Re: panic: sleeping thread owns a non-sleepable lock

On 8/12/07, Kris Kennaway <kris_at_obsecurity.org> wrote:
> On Sun, Aug 12, 2007 at 02:22:35AM +0800, Rong-en Fan wrote:
> > I'm running 7.0-CURRENT as of  yesterday, and it's very easy
> > to make it panic:
> >
> > Sleeping thread (tid 100065, pid 1066) owns a non-sleepable lock
> > sched_switch(c50a1600,0,1,1c7a7e4,4217e5,...) at sched_switch+0x190
> > mi_switch(1,0) at mi_switch+0x13f
> > sleepq_switch(c50a1600,0,c078a4e2,21b,c07e3820,...) at sleepq_switch+0x87
> > sleepq_wait(c07e3820,0,c0770b7e,3,0,...) at sleepq_wait+0x36
> > _sx_xlock_hard(c07e3820,c50a1600,0,0,0,...) at _sx_xlock_hard+0x21d
> > fr_checknatout(f9c7a8d0,f9c7a8cc,64,c57ad900,c4de7400,...) at
> > fr_checknatout+0x29d
> > fr_check(c8cc4644,14,c4de7400,1,f9c7a9b4,...) at fr_check+0x9b1
> > fr_check_wrapper(0,f9c7a9b4,c4de7400,2,c54dab28,...) at fr_check_wrapper+0x3f
> > pfil_run_hooks(c08057c0,f9c7aa4c,c4de7400,2,c54dab28,...) at pfil_run_hooks+0x74
> > ip_output(c8cc4600,0,f9c7aa10,0,0,...) at ip_output+0x913
> > tcp_output(cae322d0,cb277200,0,0,0,...) at tcp_output+0x1106
> > tcp_usr_send(c51e7318,0,cb277200,0,0,...) at tcp_usr_send+0x240
> > kern_sendfile(c50a1600,f9c7acfc,0,0,0,...) at kern_sendfile+0x1037
> > sendfile(c50a1600,f9c7acfc,20,16,f9c7ad2c,...) at sendfile+0xa8
> > syscall(f9c7ad38) at syscall+0x315
> > Xint0x80_syscall() at Xint0x80_syscall+0x20
> > --- syscall (393, FreeBSD ELF32, sendfile), eip = 0x28290bff, esp =
> > 0xbfbfc6ac, ebp = 0xbfbfe718 ---
>
> What is the lock it holds, and where is it acquired?

Hope this if enough, if not please tell me what commands I need
to issue in ddb ;-)

Sleeping thread (tid 100025, pid 26) owns a non-sleepable lock
sched_switch(c4d00e00,0,1,1ede764,23150ee,...) at sched_switch+0x190
mi_switch(1,0) at mi_switch+0x13f
sleepq_switch(c4d00e00,0,c078a4e2,21b,c07e3820,...) at sleepq_switch+0x87
sleepq_wait(c07e3820,0,c0770b7e,3,0,...) at sleepq_wait+0x36
_sx_xlock_hard(c07e3820,c4d00e00,0,0,0,...) at _sx_xlock_hard+0x21d
fr_checknatout(f5ede850,f5ede84c,64,c400,0,...) at fr_checknatout+0x29d
fr_check(c5733344,14,c4de7400,1,f5ede934,...) at fr_check+0x9b1
fr_check_wrapper(0,f5ede934,c4de7400,2,c584e498,...) at fr_check_wrapper+0x3f
pfil_run_hooks(c08057c0,f5ede9cc,c4de7400,2,c584e498,...) at pfil_run_hooks+0x74
ip_output(c5733300,0,f5ede990,0,0,...) at ip_output+0x913
tcp_output(c55bb000,b9ba2480,b9ba2a28,f5edead4,c065f1ef,...) at
tcp_output+0x1106
tcp_do_segment(c55bb000,34,5a8,4b1e708c,b0ee,...) at tcp_do_segment+0x1ba7
tcp_input(c8597200,14,c4de7400,1,0,...) at tcp_input+0x935
ip_input(c8597200,c8597200,800,c4de7400,800,...) at ip_input+0x6cf
netisr_dispatch(2,c8597200,10,3,0,...) at netisr_dispatch+0x57
ether_demux(c4de7400,c8597200,3,0,3,...) at ether_demux+0x1a3
ether_input(c4de7400,c8597200,c4d00e00,0,1,...) at ether_input+0x313
em_handle_rxtx(c4da2800,1,c4dd8880,c4dd889c,c07811ce,...) at
em_handle_rxtx+0x41c
taskqueue_run(c4dd8880,c4dd889c,c07811ce,0,f5edecf4,...) at taskqueue_run+0x174
taskqueue_thread_loop(c4da2aec,f5eded38,0,0,0,...) at taskqueue_thread_loop+0xb5
fork_exit(c05c3e06,c4da2aec,f5eded38) at fork_exit+0x99
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf5eded70, ebp = 0 ---
panic: sleeping thread
cpuid = 1
KDB: stack backtrace:
db_trace_self_wrapper(c0789bc6,f9d5baa0,c05973a0,c07a12bc,1,...) at
db_trace_self_wrapper+0x26
kdb_backtrace(c07a12bc,1,c078a9b5,f9d5baac,1,...) at kdb_backtrace+0x29
panic(c078a9b5,ffffffff,1a,cb,c51fea00,...) at panic+0x10f
propagate_priority(c51fea00,c5091050,c078a956,2d8,f9d5baec,...) at
propagate_priority+0x114
turnstile_wait(c5091050,c4d00e00,0,c584e498,c5531c60,...) at
turnstile_wait+0x2e9
_mtx_lock_sleep(c584e528,c51fea00,0,0,0,...) at _mtx_lock_sleep+0xde
tcp_usr_rcvd(c5531c60,0,f9d5bc60,0,0,...) at tcp_usr_rcvd+0x53
soreceive_generic(c5531c60,0,f9d5bc60,0,0,...) at soreceive_generic+0xef4
soreceive(c5531c60,0,f9d5bc60,0,0,...) at soreceive+0x38
soo_read(cd936828,f9d5bc60,cdce6500,0,c51fea00,...) at soo_read+0x3b
dofileread(f9d5bc60,ffffffff,ffffffff,0,cd936828,...) at dofileread+0x90
kern_readv(c51fea00,3,f9d5bc60,2822affc,0,...) at kern_readv+0x52
read(c51fea00,f9d5bcfc,c,0,ffffffff,...) at read+0x4f
syscall(f9d5bd38) at syscall+0x315
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (3, FreeBSD ELF32, read), eip = 0x2818c64f, esp =
0xbfbfb20c, ebp = 0xbfbfb358 ---
KDB: enter: panic
[thread pid 18996 tid 100158 ]
Stopped at kdb_enter+0x332: leave
db> show allchain
chain 1:
 thread 100158 (pid 18996, rsync) blocked on lock 0xc584e528 (sleep mutex) "inp"
 thread 100025 (pid 26, em0 taskq) inhibited
db > show sleepchain
thread 100158 (pid 18996, rsync) inhibited
db> show lock 0xc584e528
 class: sleep mutex
 name: inp
 type: tcpinp
 flags: {DEF, RECURSE, DUPOK}
 state: {OWNED, CONTESTED}
 owner: 0xc4d00e00 (tid 100025, pid 26, "em0 taskq")
db>

The rsync thread is in another jail which has public ip.

Regards,
Rong-En Fan

> kris
>