panic: spin lock held too long (RELENG_8 from today)

[Andriy Gapon]

on 07/07/2011 08:55 Mike Tancsa said the following:
> I did a buildworld on this box to bring it up to RELENG_8 for the BIND
> fixes.  Unfortunately, the formerly solid box (April 13th kernel)
> panic'd tonight with
> 
> Unread portion of the kernel message buffer:
> spin lock 0xc0b1d200 (sched lock 1) held by 0xc5dac8a0 (tid 100107) too long
> panic: spin lock held too long
> cpuid = 0
> Uptime: 13h30m4s
> Physical memory: 2035 MB
> 
> 
> Its a somewhat busy box taking in mail as well as backups for a few
> servers over nfs.  At the time, it would have been getting about 250Mb/s
> inbound on its gigabit interface.  Full core.txt file at
> 
> http://www.tancsa.com/core-jul8-2011.txt

I thought that this was supposed to contain output of 'thread apply all bt' in
kgdb.  Anyway, I think that stacktrace for tid 100107 may have some useful
information.

> #0  doadump () at pcpu.h:231
> 231     pcpu.h: No such file or directory.
>         in pcpu.h
> (kgdb) #0  doadump () at pcpu.h:231
> #1  0xc06fd6d3 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:429
> #2  0xc06fd937 in panic (fmt=Variable "fmt" is not available.
> ) at /usr/src/sys/kern/kern_shutdown.c:602
> #3  0xc06ed95f in _mtx_lock_spin_failed (m=0x0)
>     at /usr/src/sys/kern/kern_mutex.c:490
> #4  0xc06ed9e5 in _mtx_lock_spin (m=0xc0b1d200, tid=3312388992, opts=0,
>     file=0x0, line=0) at /usr/src/sys/kern/kern_mutex.c:526
> #5  0xc0720254 in sched_add (td=0xc5dac5c0, flags=0)
>     at /usr/src/sys/kern/sched_ule.c:1119
> #6  0xc07203f9 in sched_wakeup (td=0xc5dac5c0)
>     at /usr/src/sys/kern/sched_ule.c:1950
> #7  0xc07061f8 in setrunnable (td=0xc5dac5c0)
>     at /usr/src/sys/kern/kern_synch.c:499
> #8  0xc07362af in sleepq_resume_thread (sq=0xca0da300, td=0xc5dac5c0,
> pri=Variable "pri" is not available.
> )
>     at /usr/src/sys/kern/subr_sleepqueue.c:751
> #9  0xc0736e18 in sleepq_signal (wchan=0xc5fafe50, flags=1, pri=0, queue=0)
>     at /usr/src/sys/kern/subr_sleepqueue.c:825
> #10 0xc06b6764 in cv_signal (cvp=0xc5fafe50)
>     at /usr/src/sys/kern/kern_condvar.c:422
> #11 0xc08eaa0d in xprt_assignthread (xprt=Variable "xprt" is not available.
> ) at /usr/src/sys/rpc/svc.c:342
> #12 0xc08ec502 in xprt_active (xprt=0xc95d9600) at
> /usr/src/sys/rpc/svc.c:378
> #13 0xc08ee051 in svc_vc_soupcall (so=0xc6372ce0, arg=0xc95d9600,
> waitflag=1)
>     at /usr/src/sys/rpc/svc_vc.c:747
> #14 0xc075bbb1 in sowakeup (so=0xc6372ce0, sb=0xc6372d34)
>     at /usr/src/sys/kern/uipc_sockbuf.c:191
> #15 0xc08447bc in tcp_do_segment (m=0xcaa8d200, th=0xca6aa824,
> so=0xc6372ce0,
>     tp=0xc63b4d20, drop_hdrlen=52, tlen=1448, iptos=0 '\0', ti_locked=2)
>     at /usr/src/sys/netinet/tcp_input.c:1775
> #16 0xc0847930 in tcp_input (m=0xcaa8d200, off0=20)
>     at /usr/src/sys/netinet/tcp_input.c:1329
> #17 0xc07ddaf7 in ip_input (m=0xcaa8d200)
>     at /usr/src/sys/netinet/ip_input.c:787
> #18 0xc07b8859 in netisr_dispatch_src (proto=1, source=0, m=0xcaa8d200)
>     at /usr/src/sys/net/netisr.c:859
> #19 0xc07b8af0 in netisr_dispatch (proto=1, m=0xcaa8d200)
>     at /usr/src/sys/net/netisr.c:946
> #20 0xc07ae5e1 in ether_demux (ifp=0xc56ed800, m=0xcaa8d200)
>     at /usr/src/sys/net/if_ethersubr.c:894
> #21 0xc07aeb5f in ether_input (ifp=0xc56ed800, m=0xcaa8d200)
>     at /usr/src/sys/net/if_ethersubr.c:753
> #22 0xc09977b2 in nfe_int_task (arg=0xc56ff000, pending=1)
>     at /usr/src/sys/dev/nfe/if_nfe.c:2187
> #23 0xc07387ca in taskqueue_run_locked (queue=0xc5702440)
>     at /usr/src/sys/kern/subr_taskqueue.c:248
> #24 0xc073895c in taskqueue_thread_loop (arg=0xc56ff130)
>     at /usr/src/sys/kern/subr_taskqueue.c:385
> #25 0xc06d1027 in fork_exit (callout=0xc07388a0 <taskqueue_thread_loop>,
>     arg=0xc56ff130, frame=0xc538ed28) at /usr/src/sys/kern/kern_fork.c:861
> #26 0xc09a5c24 in fork_trampoline () at
> /usr/src/sys/i386/i386/exception.s:275
> (kgdb)
> 


-- 
Andriy Gapon