Date: Thu, 13 Dec 2007 14:19:27 +0100 From: Maxime Henrion <mux@FreeBSD.org> To: glebius@FreeBSD.org Cc: net@FreeBSD.org Subject: Deadlock in the routing code Message-ID: <20071213131927.GB71713@elvis.mu.org>
next in thread | raw e-mail | index | archive | help
Hi,
We've been experiencing frequent deadlocks within the routing code
with our gateway servers that are running routed. I finally got
sufficient information to precisely pinpoint the problem, so here
we go...
DDB was helpful in leading me to understanding:
chain 1:
thread 100004 (pid 12, swi4: clock sio) blocked on lock 0xc3a5b060 (sleep mutex) "rtentry"
thread 100084 (pid 1638, routed) blocked on lock 0xc3a5b81c (sleep mutex) "rtentry"
thread 100002 (pid 14, swi1: net) blocked on lock 0xc3a5b060 (sleep mutex) "rtentry"
thread 100084 (pid 1638, routed) blocked on lock 0xc3a5b81c (sleep mutex) "rtentry"
thread 100002 (pid 14, swi1: net) blocked on lock 0xc3a5b060 (sleep mutex) "rtentry"
thread 100084 (pid 1638, routed) blocked on lock 0xc3a5b81c (sleep mutex) "rtentry"
thread 100002 (pid 14, swi1: net) blocked on lock 0xc3a5b060 (sleep mutex) "rtentry"
[...]
And so on.
So it's pretty clear here that both thread 100004 and 100002 are
contending for obtaining the mutex at 0xc3a5b060. They cannot
however obtain it because it is held by thread 100084 which is
itself trying to lock mutex 0xc3a5b81c.
The relevant part of the stacktraces are :
Thread 100002 (swi1: net):
#3 0xc06cd6be in _mtx_lock_sleep (m=0xc3a5b060, tid=3278191616, opts=0,
file=0x0, line=0) at ../../../kern/kern_mutex.c:579
#4 0xc0758bd5 in rt_check (lrt=0x0, lrt0=0xd41e9b58, dst=0xc3d09210)
at ../../../net/route.c:1281
#5 0xc0771a26 in arpresolve (ifp=0xc38c9c00, rt0=0xc3a5b7bc, m=0xc3fd0700,
dst=0xc3d09210, desten=0xd41e9b78 "") at ../../../netinet/if_ether.c:404
#6 0xc074a8f7 in ether_output (ifp=0xc38c9c00, m=0xc3fd0700, dst=0xc3d09210,
rt0=0x0) at ../../../net/if_ethersubr.c:177
#7 0xc07800e8 in ip_output (m=0xc3fd0700, opt=0xc38c9c00, ro=0xd41e9bd0,
flags=1, imo=0x0, inp=0x0) at ../../../netinet/ip_output.c:780
#8 0xc077f5a8 in ip_forward (m=0xc3fd0700, srcrt=0)
at ../../../netinet/ip_input.c:1923
#9 0xc077e0c7 in ip_input (m=0xc3fd0700) at ../../../netinet/ip_input.c:694
#10 0xc075367b in netisr_processqueue (ni=0xc0a73798)
at ../../../net/netisr.c:236
#11 0xc075387a in swi_net (dummy=0x0) at ../../../net/netisr.c:349
Thread 100004 (swi4: clock sio):
#3 0xc06cd6be in _mtx_lock_sleep (m=0xc3a5b060, tid=3278190848, opts=0,
file=0x0, line=0) at ../../../kern/kern_mutex.c:579
#4 0xc0771350 in arptimer (unused=0x0) at ../../../netinet/if_ether.c:142
#5 0xc06e40cb in softclock (dummy=0x0) at ../../../kern/kern_timeout.c:290
#6 0xc06bfca9 in ithread_execute_handlers (p=0xc3652860, ie=0xc3695c00)
at ../../../kern/kern_intr.c:682
#7 0xc06bfdc9 in ithread_loop (arg=0xc362b8d0)
Thread 100084 (routed):
#3 0xc06cd6be in _mtx_lock_sleep (m=0xc3a5b81c, tid=3284877696, opts=0,
file=0x0, line=0) at ../../../kern/kern_mutex.c:579
#4 0xc075852f in rt_setgate (rt=0xc3a5b7bc, dst=0xc3d09200, gate=0xc5f8d46c)
at ../../../net/route.c:1032
#5 0xc07598cf in route_output (m=0xc38c5900, so=0xc3a572c8)
at ../../../net/rtsock.c:506
#6 0xc0756ea8 in raw_usend (so=0x0, flags=0, m=0x0, nam=0x0, control=0x0,
td=0xc3cb4180) at ../../../net/raw_usrreq.c:263
#7 0xc0759167 in rts_send (so=0xc3a572c8, flags=0, m=0xc38c5900, nam=0x0,
control=0x0, td=0xc3cb4180) at ../../../net/rtsock.c:269
#8 0xc0713a57 in sosend (so=0xc3a572c8, addr=0x0, uio=0xd6646cbc,
top=0xc38c5900, control=0x0, flags=0, td=0xc3cb4180)
at ../../../kern/uipc_socket.c:836
#9 0xc0701f4a in soo_write (fp=0x0, uio=0xd6646cbc, active_cred=0xc3650780,
flags=0, td=0xc3cb4180) at ../../../kern/sys_socket.c:118
#10 0xc06fc1aa in dofilewrite (td=0xc3cb4180, fd=3, fp=0xc3a7f480,
auio=0xd6646cbc, offset=Unhandled dwarf expression opcode 0x93
) at file.h:253
#11 0xc06fc04b in kern_writev (td=0xc3cb4180, fd=3, auio=0xd6646cbc)
at ../../../kern/sys_generic.c:402
#12 0xc06fbf71 in write (td=0xc3cb4180, uap=0x0)
at ../../../kern/sys_generic.c:326
So, I think that the crux of the problem is in the rt_setgate()
function. At line 1025, the struct rtentry we are dealing with is
unlock to avoid LORs according to a comment. And then we call
rtalloc1() which returns us the locked struct rtentry for the gateway
address. Then we try to re-lock our own rtentry, still holding the
gateway route.
I've checked in ddb that the gateway route returned by rtalloc1()
in rt_setgate() is indeed the route that both swi1 and swi4 are
trying to obtain. I don't know however, why the routed process
running in rt_setgate() can't re-acquire the rtentry it was called
with. Presumably it's being hold by one of the two other threads
involved in this deadlock.
I'm still investigating and as soon as I know more about this, I'll
post more details.
Maxime
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20071213131927.GB71713>