Re: spin lock sched lock held for > 5 seconds

John Baldwin wrote:
> On 01-Aug-2003 Lars Eggert wrote:
> 
>>Hi,
>>
>>got the following panic overnight running with all debugging options on
>>(WITNESS, MUTEX_DEBUG, DIAGNOSTIC, INVARIANTS; WITNESS_SKIPSPIN off):
>>
>>panic: spin lock sched lock held by 0xc658e130 for > 5 seconds
>>cpuid = 0; lapic.id = 00000000
>>Stack backtrace:
>>backtrace(c031d030,0,c031c4c5,df0dab8c,100) at backtrace+0x17
>>panic(c031c4c5,c031c62e,c658e130,c036f160,18b) at panic+0x13d
>>_mtx_lock_spin(c036f160,2,c031a229,18b,c21b2ab0) at _mtx_lock_spin+0x83
>>_mtx_lock_spin_flags(c036f160,2,c031a229,18b,df0dac0c) at
>>_mtx_lock_spin_flags+0xb9
>>statclock(df0dac00,df0dac44,c02d8a9c,0,c2198d00) at statclock+0x39
>>rtcintr(0) at rtcintr+0x4f
>>Xfastunpend8(df0dacb8,c02d1f05,8,608,c0372e60) at Xfastunpend8+0x1c
>>call_fast_unpend(8,608,c0372e60,ffc00034,0) at call_fast_unpend+0xd
>>i386_unpend(c036f160,c21b0790,df0dacd0,c01b1ae0,df0dacec) at
>>i386_unpend+0x8d
>>cpu_unpend(df0dacec,c01a2534,c036f160,1,c031c2e2) at cpu_unpend+0x2d
>>critical_exit(c036f160,1,c031c2e2,1bc,1) at critical_exit+0x2d
>>_mtx_unlock_spin_flags(c036f160,0,c031ac9f,7c,c21b2ab0) at
>>_mtx_unlock_spin_flags+0xbb
>>idle_proc(0,df0dad48,c031ab89,312,c21b2ab0) at idle_proc+0xb0
>>fork_exit(c0199972,0,df0dad48) at fork_exit+0xc3
>>fork_trampoline() at fork_trampoline+0x1a
>>--- trap 0x1, eip = 0, esp = 0xdf0dad7c, ebp = 0 ---
>>Debugger("panic")
>>timeout stopping cpus
>>Stopped at      Debugger+0x4f:  xchgl   %ebx,in_Debugger.0
>>db>
>>
>>The machine is still in ddb, let me know if I can provide additional info.
> 
> Try updating to a more recent current.  I recently added some extra
> debugging here that will attempt to better show who owns the lock and
> where it was acquired.

Same panic string, but a different call chain:

spin lock sched lock held by 0xc21b2d10 for > 5 seconds
exclusive spin mutex sched lock r = 0 (0xc036efc0) locked _at_ 
/usr/src/sys/kern/kern_mutex.c:512
panic: spin lock held too long
cpuid = 3; lapic.id = 03000000
Stack backtrace:
backtrace(c031ce60,3000000,c031c305,df0d0c30,100) at backtrace+0x17
panic(c031c305,c21b2d10,c21b2d10,c036efc0,bc) at panic+0x13d
_mtx_lock_spin(c036efc0,2,c031a037,bc,c21b2720) at _mtx_lock_spin+0xb4
_mtx_lock_spin_flags(c036efc0,2,c031a037,bc,c21b2720) at 
_mtx_lock_spin_flags+0xb9
hardclock_process(df0d0ca0,df0d0ce4,c02d7062,0,c0390018) at 
hardclock_process+0x3c
forwarded_hardclock(0) at forwarded_hardclock+0x11
Xhardclock(df0d0d10,c01998d7,c036f000,2,c031aaad) at Xhardclock+0x52
cpu_idle(c036f000,2,c031aaad,5f,c21b2720) at cpu_idle+0x8
idle_proc(0,df0d0d48,c031a997,30e,0) at idle_proc+0x45
fork_exit(c0199892,0,df0d0d48) at fork_exit+0xc3
fork_trampoline() at fork_trampoline+0x8
--- trap 0x1, eip = 0, esp = 0xdf0d0d7c, ebp = 0 ---
Debugger("panic")
timeout stopping cpus
Stopped at      Debugger+0x4f:  xchgl   %ebx,in_Debugger.0
db>

Machine is still in ddb, in case you'd like me to poke around some more.

Lars
-- 
Lars Eggert <larse_at_isi.edu>           USC Information Sciences Institute