Re: panic: spin lock held too long (while rebooting)

From: Thierry Herbelot <thierry_at_herbelot.com>
Date: Sat, 21 Jan 2006 07:05:10 +0100
Le Wednesday 4 January 2006 14:38, John Baldwin a écrit :
> On Wednesday 04 January 2006 02:06 am, Thierry Herbelot wrote:

[SNIP previous similar panic]
>
> Next time you get this, can you use 'show threads' to figure out the tid
> for the thread whose pointer is in the printf (0xc16de480 in this case) and
> then do a trace of that thread?

Hello,

Here is a more detailed crash session :

is this (zomb)  problematic ? (in ps) :
    8 c182e228    0     1     0 0002204 zomb[INACTIVE] g_mirror gm0s1

I keep the machine in DDB, if there are more detailed commands to investigate 
the panic (the machine is an SMP BP6, runs a GENERIC current kernel, and 
stores its local files in two g_mirror partitions).

The problematic spinlock is held by 0xc16de340 which is cpustop_handler.

	TfH

PS : printout of the crash :

# reboot
Waiting (max 60 seconds) for system process `vnlru' to stop...done
Waiting (max 60 seconds) for system process `bufdaemon' to stop...done
Waiting (max 60 seconds) for system process `syncer' to stop...
Syncing disks, vnodes remaining...3 2 2 2 0 0 done
All buffers synced.
Uptime: 39m52s
GEOM_MIRROR: Device files1: provider mirror/files1 destroyed.
GEOM_MIRROR: Device files1 destroyed.
GEOM_MIRROR: Device gm0s1: provider mirror/gm0s1 destroyed.
GEOM_MIRROR: Device gm0s1 destroyed.
Rebooting...
cpu_reset: Stopping other CPUs
spin lock sched lock held by 0xc16de340 for > 5 seconds
panic: spin lock held too long
cpuid = 0
KDB: enter: panic
[thread pid 18874 tid 100079 ]
Stopped at      kdb_enter+0x2b: nop

db> trace
Tracing pid 18874 tid 100079 td 0xc197c1a0
kdb_enter(c0882824) at kdb_enter+0x2b
panic(c0881c7e,c094e970,c16de340,c0881c55,c0881daf) at panic+0x127
_mtx_lock_spin(c094e970,c197c1a0,2,c087e5ea,cb) at _mtx_lock_spin+0xa8
_mtx_lock_spin_flags(c094e970,2,c087e5ea,cb) at _mtx_lock_spin_flags+0xaa
hardclock_cpu(0,c09cef20,0,c7644ba0,c0808371) at hardclock_cpu+0x25
hardclock(0,c081810e) at hardclock+0x13
lapic_handle_timer(8,28,c16b0028,c16ba00c,0) at lapic_handle_timer+0x71
Xtimerint() at Xtimerint+0x1e
--- interrupt, eip = 0xc081810e, esp = 0xc7644be8, ebp = 0xc7644c0c ---
DELAY(f4240) at DELAY+0x92
cpu_reset(f4240,c0882a0b,c7644c64,c065418b,0) at cpu_reset+0xc8
shutdown_reset(0,0,c16ba00c,0,c0882848) at shutdown_reset+0x1c
boot(0,c094e988,0,c0882848,a1) at boot+0x553
reboot(c197c1a0,c7644d04,c197c1a0,0,2) at reboot+0x32
syscall(3b,3b,3b,0,2) at syscall+0x27e
Xint0x80_syscall() at Xint0x80_syscall+0x1f
--- syscall (55, FreeBSD ELF32, reboot), eip = 0x280add0f, esp = 0xbfbfedcc, 
ebp = 0xbfbfee18 ---

db> ps
  pid   proc     uid  ppid  pgrp  flag   stat  wmesg    wchan  cmd
18874 c1be0450    0     1 18874 0004002 [CPU 0] reboot
   41 c18a5ac8    0     0     0 0000204 [SLPQ - 0xc72cfd04][SLP] schedcpu
   40 c18a5cf0    0     0     0 0000204 [SLPQ - 0xc09a2dec][SLP] nfsiod 3
   39 c18aa000    0     0     0 0000204 [SLPQ - 0xc09a2de8][SLP] nfsiod 2
   38 c17a8cf0    0     0     0 0000204 [SLPQ - 0xc09a2de4][SLP] nfsiod 1
   37 c182b000    0     0     0 0000204 [SLPQ - 0xc09a2de0][SLP] nfsiod 0
   36 c182b228    0     0     0 0000204 [SLPQ ktsusp 0xc182b2ac][SLP] vnlru
   35 c182b450    0     0     0 0000204 [SLPQ ktsusp 0xc182b4d4][SLP] syncer
   34 c182b678    0     0     0 0000204 [SLPQ ktsusp 0xc182b6fc][SLP] 
bufdaemon
   33 c182b8a0    0     0     0 000020c [SLPQ pgzero 0xc09b0d10][SLP] pagezero
   32 c182bac8    0     0     0 0000204 [SLPQ psleep 0xc09a8c3c][SLP] vmdaemon
   31 c182bcf0    0     0     0 0000204 [SLPQ psleep 0xc09a8bfc][SLP] 
pagedaemon
   30 c182e450    0     0     0 0000204 [IWAIT] irq5: pcm1
    7 c16f5678    0     0     0 0000204 [SLPQ - 0xc16cbe3c][SLP] fdc0
   29 c16f58a0    0     0     0 0000204 [IWAIT] swi0: sio
   28 c16f5ac8    0     0     0 0000204 [IWAIT] irq7: ppc0
   27 c16f5cf0    0     0     0 0000204 [IWAIT] irq1: atkbd0
   26 c17a8000    0     0     0 0000204 [IWAIT] irq17: atapci1
   25 c17a8228    0     0     0 0000204 [IWAIT] irq18: pcm0++
   24 c17a8450    0     0     0 0000204 [SLPQ usbtsk 0xc094c744][SLP] usbtask
   23 c17a8678    0     0     0 0000204 [SLPQ usbevt 0xc17b1210][SLP] usb0
   22 c17a88a0    0     0     0 0000204 [IWAIT] irq19: dc0 uhci0
   21 c17a8ac8    0     0     0 0000204 [IWAIT] irq15: ata1
   20 c16e2228    0     0     0 0000204 [IWAIT] irq14: ata0
   19 c16e2450    0     0     0 0000204 [IWAIT] swi6: task queue
    6 c16e2678    0     0     0 0000204 [SLPQ - 0xc1792400][SLP] kqueue taskq
   18 c16e28a0    0     0     0 0000204 [IWAIT] swi2: cambio
   17 c16e2ac8    0     0     0 0000204 [IWAIT] swi5: +
    5 c16e2cf0    0     0     0 0000204 [SLPQ - 0xc16dc500][SLP] thread taskq
   16 c16f5000    0     0     0 0000204 [IWAIT] swi6: Giant taskq
   15 c16f5228    0     0     0 0000204 [SLPQ - 0xc094a3a0][SLP] yarrow
    4 c16f5450    0     0     0 0000204 [SLPQ - 0xc094cebc][SLP] g_down
    3 c16dd000    0     0     0 0000204 [SLPQ - 0xc094ceb8][SLP] g_up
    2 c16dd228    0     0     0 0000204 [RUNQ] g_event
   14 c16dd450    0     0     0 0000204 [IWAIT] swi1: net
   13 c16dd678    0     0     0 0000204 [IWAIT] swi3: vm
   12 c16dd8a0    0     0     0 000020c [LOCK  Giant c1824480] swi4: clock sio
   11 c16ddac8    0     0     0 000020c [Can run] idle: cpu0
   10 c16ddcf0    0     0     0 000020c [Can run] idle: cpu1
    1 c16e2000    0     0     1 0004200 [CPU 1] init
    0 c094cfc0    0     0     0 0000200 [IWAIT] swapper
    8 c182e228    0     1     0 0002204 zomb[INACTIVE] g_mirror gm0s1


db> show threads
  100079 (0xc197c1a0)  kdb_enter(c0882824) at kdb_enter+0x2b
  100047 (0xc18a9680)  sched_switch(c18a9680,0,1) at sched_switch+0x183
  100048 (0xc18a94e0)  sched_switch(c18a94e0,0,1) at sched_switch+0x183
  100049 (0xc18a9340)  sched_switch(c18a9340,0,1) at sched_switch+0x183
  100027 (0xc16e3d00)  sched_switch(c16e3d00,0,1) at sched_switch+0x183
  100028 (0xc16e3b60)  sched_switch(c16e3b60,0,1) at sched_switch+0x183
  100029 (0xc16e39c0)  sched_switch(c16e39c0,0,1) at sched_switch+0x183
  100030 (0xc16e3820)  sched_switch(c16e3820,0,1) at sched_switch+0x183
  100031 (0xc16e3680)  sched_switch(c16e3680,0,1) at sched_switch+0x183
  100032 (0xc16e34e0)  sched_switch(c16e34e0,0,1) at sched_switch+0x183
  100033 (0xc182d000)  sched_switch(c182d000,0,1) at sched_switch+0x183
  100034 (0xc182cd00)  sched_switch(c182cd00,0,1) at sched_switch+0x183
  100037 (0xc182c820)  fork_trampoline() at fork_trampoline
  100017 (0xc16df680)  sched_switch(c16df680,0,1) at sched_switch+0x183
  100018 (0xc16df4e0)  sched_switch(c16df4e0,0,1) at sched_switch+0x183
  100019 (0xc16df340)  fork_trampoline() at fork_trampoline
  100020 (0xc16df1a0)  fork_trampoline() at fork_trampoline
  100021 (0xc17a9820)  fork_trampoline() at fork_trampoline
  100022 (0xc17a9680)  sched_switch(c17a9680,0,1) at sched_switch+0x183
  100023 (0xc17a94e0)  sched_switch(c17a94e0,0,1) at sched_switch+0x183
  100024 (0xc17a9340)  sched_switch(c17a9340,0,1) at sched_switch+0x183
  100025 (0xc17a91a0)  fork_trampoline() at fork_trampoline
  100026 (0xc17a9000)  sched_switch(c17a9000,0,1) at sched_switch+0x183
  100008 (0xc16de1a0)  sched_switch(c16de1a0,0,1) at sched_switch+0x183
  100009 (0xc16de000)  sched_switch(c16de000,0,1) at sched_switch+0x183
  100010 (0xc16e3340)  sched_switch(c16e3340,0,1) at sched_switch+0x183
  100011 (0xc16e31a0)  fork_trampoline() at fork_trampoline
  100012 (0xc16e3000)  fork_trampoline() at fork_trampoline
  100013 (0xc16dfd00)  sched_switch(c16dfd00,0,1) at sched_switch+0x183
  100014 (0xc16dfb60)  fork_trampoline() at fork_trampoline
  100015 (0xc16df9c0)  sched_switch(c16df9c0,0,1) at sched_switch+0x183
  100016 (0xc16df820)  sched_switch(c16df820,0,1) at sched_switch+0x183
  100000 (0xc16df000)  sched_switch(c16df000,0,1) at sched_switch+0x183
  100001 (0xc16ded00)  sched_switch(c16ded00,0,1) at sched_switch+0x183
  100002 (0xc16deb60)  fork_trampoline() at fork_trampoline
  100003 (0xc16de9c0)  fork_trampoline() at fork_trampoline
  100004 (0xc16de820)  sched_switch(c16de820,0,1) at sched_switch+0x183
  100005 (0xc16de680)  sched_switch(c16de680,c16de1a0,6) at sched_switch+0x183
  100006 (0xc16de4e0)  sched_switch(c16de4e0,0,1) at sched_switch+0x183
  100007 (0xc16de340)  cpustop_handler(c6cccba8,c08149f1,c6cccb4c,c0678738,0) 
at cpustop_handler+0x31
       0 (0xc094d200)  sched_switch(c094d200,0,1) at sched_switch+0x183
Received on Sat Jan 21 2006 - 05:05:25 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:51 UTC