panic with ZFS

From: Thierry Herbelot <thierry_at_herbelot.com>
Date: Sat, 21 Jul 2007 06:57:09 +0200
Hello,

with a recent -current -built yesterday), I just got a panic while 
rebuilding -j4 the world and portupgrading firefox.

it was during the "cleandir" phase of make buildworld :
===> gnu/usr.bin/groff/font/devascii (cleandir)
===> sbin/rcorder (cleandir)
===> lib/libpam/modules/pam_tacplus (cleandir)
===> gnu/usr.bin/groff/font/devcp1047 (cleandir)
===> sbin/reboot (cleandir)
Read from remote host cur: Operation timed out
Connection to cur closed.
machine%

the machine is pretty much memory limited (only 320 MB of RAM), with two CPUs, 
running a straight GENERIC kernel, including WITNESS and INVARIANTS.

all filesystems except / are stored in a mirrored tank (specifically, src and 
obj are in two separate zfs filesystems).

# ident /boot/kernel/kernel | grep uma_core
     $FreeBSD: src/sys/vm/uma_core.c,v 1.147 2007/05/31 22:52:14 attilio Exp $
# ident /boot/kernel/kernel | grep uipc_sockbuf
     $FreeBSD: src/sys/kern/uipc_sockbuf.c,v 1.171 2007/05/31 11:51:22 rwatson 
Exp $

	TfH

the panic message is :

panic: System call unlink returning with 1 locks held
cpuid = 0
KDB: enter: panic
[thread pid 42789 tid 100102 ]
Stopped at      kdb_enter+0x32: leave
db> where
Tracing pid 42789 tid 100102 td 0xc2ce3200
kdb_enter(c0a92bc5,0,c0ac0a31,d5457c8c,0,...) at kdb_enter+0x32
panic(c0ac0a31,c0a98f5c,1,c0a98f5c,c0b3f030,...) at panic+0x124
syscall(d5457d38) at syscall+0x46e
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (0, FreeBSD ELF32, nosys), eip = 0x28145c23, esp = 0xbfbfe75c, ebp 
= 0xbfbfe788 ---
db> show alllocks
Process 42787 (rm) thread 0xc70a0400 (100173)
exclusive sleep mutex 16 (UMA zone) r = 0 (0xc1474708) locked 
_at_ /tank/files1/src/sys/vm/uma_core.c:2257
Process 22309 (sshd) thread 0xc50b1c00 (100153)
exclusive sx so_rcv_sx r = 0 (0xc30753a4) locked 
_at_ /tank/files1/src/sys/kern/uipc_sockbuf.c:145
Process 22241 (sshd) thread 0xc36c9c00 (100145)
exclusive sx so_rcv_sx r = 0 (0xc6b523a4) locked 
_at_ /tank/files1/src/sys/kern/uipc_sockbuf.c:145
Process 22186 (sshd) thread 0xc36c8400 (100125)
exclusive sx so_rcv_sx r = 0 (0xc26ddb60) locked 
_at_ /tank/files1/src/sys/kern/uipc_sockbuf.c:145
db> ps
  pid  ppid  pgrp   uid   state   wmesg     wchan    cmd
42789 42788 39442     0  R+      CPU 0               rm
42788 42785 39442     0  S+      wait     0xc70662ac sh
42787 42786 39442     0  R+      CPU 1               rm
42786 42784 39442     0  S+      wait     0xc4186558 sh
42785 42739 39442     0  S+      select   0xc0bf42fc make
42784 41484 39442     0  S+      select   0xc0bf42fc make
42779 42589 39442     0  S+      zfs:(&zi 0xc3a44218 make
42767 42765 34732     0  S+      piperd   0xc36e418c as
42766 42765 34732     0  S+      zfs:(&zi 0xc3acbce0 cc1
42765 40226 34732     0  S+      wait     0xc36ca000 cc
42739 42734 39442     0  S+      wait     0xc3bdd2ac sh
42734 42691 39442     0  S+      select   0xc0bf42fc make
42728     0     0     0  SL      vgeom:io 0xc4df2d48 [vdev:worker ad2s2d]
42727     0     0     0  SL      vgeom:io 0xc3a18108 [vdev:worker ad0s2d]
42691 42685 39442     0  S+      wait     0xc4e67804 sh
42685 41228 39442     0  S+      select   0xc0bf42fc make
42649 42648 39442     0  S+      zfs:(&zi 0xc3b19890 rm
42648 42557 39442     0  S+      wait     0xc3420000 sh
42589 42586 39442     0  S+      wait     0xc36c7ab0 sh
42586 42585 39442     0  S+      select   0xc0bf42fc make
42585 42582 39442     0  S+      wait     0xc2ce0000 sh
42582 40683 39442     0  S+      select   0xc0bf42fc make
42557 42555 39442     0  S+      select   0xc0bf42fc make
42555 42551 39442     0  S+      wait     0xc2872804 sh
42551 42550 39442     0  S+      select   0xc0bf42fc make
42550 42543 39442     0  S+      wait     0xc2673804 sh
42543 42542 39442     0  S+      select   0xc0bf42fc make
42542 40666 39442     0  S+      wait     0xc294c000 sh
41484 41452 39442     0  S+      wait     0xc3c1dab0 sh
41452 41449 39442     0  S+      select   0xc0bf42fc make
41449 40666 39442     0  S+      wait     0xc70c3000 sh
41228 41226 39442     0  S+      wait     0xc4e672ac sh
41226 41002 39442     0  S+      select   0xc0bf42fc make
41002 40997 39442     0  S+      wait     0xc2679558 sh
40997 40996 39442     0  S+      select   0xc0bf42fc make
40996 40666 39442     0  S+      wait     0xc3b6a804 sh
40683 40678 39442     0  S+      wait     0xc54332ac sh
40678 40674 39442     0  S+      select   0xc0bf42fc make
40674 40666 39442     0  S+      wait     0xc3b69558 sh
40666 40665 39442     0  S+      select   0xc0bf42fc make
40665 39551 39442     0  S+      wait     0xc2ce0804 sh
40226 40224 34732     0  S+      wait     0xc36ca558 gmake
40224 40211 34732     0  S+      wait     0xc33d1ab0 sh
40211 39329 34732     0  S+      wait     0xc7066ab0 gmake
39551 39549 39442     0  S+      select   0xc0bf42fc make
39549 39442 39442     0  S+      wait     0xc4181804 sh
39442 22261 39442     0  S+      select   0xc0bf42fc make
39329 39326 34732     0  S+      wait     0xc2cdb2ac sh
39326 39070 34732     0  S+      wait     0xc33d1558 gmake
39070 39069 34732     0  S+      wait     0xc26cd000 gmake
39069 34732 34732     0  S+      wait     0xc2cdc000 sh
34732 34731 34732     0  Ss+     wait     0xc3420558 make
34731 22289 22289     0  S+      select   0xc0bf42fc script
22397 22318 22397  1001  S+      nanslp   0xc0ba76e4 zpool
22318 22312 22318  1001  Ss+     pause    0xc2cdc5b8 csh
22312 22309 22309  1001  S       select   0xc0bf42fc sshd
22309 22170 22309     0  Ss      sbwait   0xc30753d4 sshd
22289 22280 22289     0  S+      wait     0xc70c3804 initial thread
22280 22279 22280     0  S+      pause    0xc4920864 csh
22279 22244 22279  1001  S+      wait     0xc49202ac su
22261 22260 22261     0  S+      pause    0xc36c730c csh
22260 22245 22260  1001  S+      wait     0xc2cdc804 su
22245 22240 22245  1001  Ss+     pause    0xc36c5b10 csh
22244 22243 22244  1001  Ss+     pause    0xc36c6b10 csh
22243 22241 22241  1001  S       select   0xc0bf42fc sshd
22241 22170 22241     0  Ss      sbwait   0xc6b523d4 sshd
22240 22186 22186  1001  S       select   0xc0bf42fc sshd
22239     1 22239     0  Ss+     ttyin    0xc258f410 getty
22238     1 22238     0  Ss+     ttyin    0xc258d810 getty
22237     1 22237     0  Ss+     ttyin    0xc258b010 getty
22236     1 22236     0  Ss+     ttyin    0xc258b410 getty
22235     1 22235     0  Ss+     ttyin    0xc258b810 getty
22234     1 22234     0  Ss+     ttyin    0xc258bc10 getty
22233     1 22233     0  Ss+     ttyin    0xc258c010 getty
22232     1 22232     0  Ss+     ttyin    0xc258c410 getty
22231     1 22231     0  Ss+     ttyin    0xc258c810 getty
22188     1 22188     0  Ss      nanslp   0xc0ba76e4 cron
22186 22170 22186     0  Ss      sbwait   0xc26ddb90 sshd
22180     1 22180    25  Ss      pause    0xc417c30c sendmail
22176     1 22176     0  Ss      select   0xc0bf42fc sendmail
22170     1 22170     0  Ss      select   0xc0bf42fc sshd
22152     1 22152     0  Ss      select   0xc0bf42fc ntpd
22048     1 22048     0  Ss      select   0xc0bf42fc syslogd
21980     1 21980     0  Ss      select   0xc0bf42fc devd
21697     1 21697     0  Ss      pause    0xc4920b10 adjkerntz
  133     0     0     0  SL      zfs:(&tx 0xc2ad072c [txg_thread_enter]
  132     0     0     0  SL      zfs:(&zi 0xc3537ab8 [txg_thread_enter]
  131     0     0     0  SL      zfs:(&tx 0xc2ad071c [txg_thread_enter]
  128     0     0     0  SL      zfs:(&tq 0xc27c811c [spa_zio_intr_5]
  127     0     0     0  SL      zfs:(&tq 0xc27c811c [spa_zio_intr_5]
  126     0     0     0  SL      zfs:(&tq 0xc27c81e8 [spa_zio_issue_5]
  125     0     0     0  SL      zfs:(&tq 0xc27c81e8 [spa_zio_issue_5]
  124     0     0     0  SL      zfs:(&tq 0xc27c82b4 [spa_zio_intr_4]
  123     0     0     0  SL      zfs:(&tq 0xc27c82b4 [spa_zio_intr_4]
  122     0     0     0  SL      zfs:(&tq 0xc27c8380 [spa_zio_issue_4]
  121     0     0     0  SL      zfs:(&tq 0xc27c8380 [spa_zio_issue_4]
  120     0     0     0  SL      zfs:(&tq 0xc27c844c [spa_zio_intr_3]
  119     0     0     0  SL      zfs:(&tq 0xc27c844c [spa_zio_intr_3]
  118     0     0     0  SL      zfs:(&tq 0xc27c8518 [spa_zio_issue_3]
  117     0     0     0  SL      zfs:(&tq 0xc27c8518 [spa_zio_issue_3]
  116     0     0     0  SL      zfs:(&tq 0xc27c85e4 [spa_zio_intr_2]
  115     0     0     0  SL      zfs:(&tq 0xc27c85e4 [spa_zio_intr_2]
  114     0     0     0  SL      zfs:(&tq 0xc27c86b0 [spa_zio_issue_2]
  113     0     0     0  SL      zfs:(&tq 0xc27c86b0 [spa_zio_issue_2]
  112     0     0     0  SL      zfs:(&tq 0xc27c877c [spa_zio_intr_1]
  111     0     0     0  SL      zfs:(&tq 0xc27c877c [spa_zio_intr_1]
  110     0     0     0  SL      zfs:(&tq 0xc27c7d10 [spa_zio_issue_1]
  109     0     0     0  SL      zfs:(&tq 0xc27c7d10 [spa_zio_issue_1]
  108     0     0     0  SL      zfs:(&tq 0xc27c7ddc [spa_zio_intr_0]
  107     0     0     0  SL      zfs:(&tq 0xc27c7ddc [spa_zio_intr_0]
  106     0     0     0  SL      zfs:(&tq 0xc27c7ea8 [spa_zio_issue_0]
  105     0     0     0  SL      zfs:(&tq 0xc27c7ea8 [spa_zio_issue_0]
   77     0     0     0  SL      zfs:(&ar 0xc2788dcc [arc_reclaim_thread]
   75     0     0     0  SL      zfs:(&tq 0xc27c8050 [system_taskq]
   74     0     0     0  SL      zfs:(&tq 0xc27c8050 [system_taskq]
   46     0     0     0  SL      -        0xc0ba7514 [schedcpu]
   45     0     0     0  SL      sdflush  0xc0bfffe4 [softdepflush]
   44     0     0     0  SL      vlruwt   0xc2676558 [vnlru]
   43     0     0     0  SL      syncer   0xc0ba750c [syncer]
   42     0     0     0  SL      psleep   0xc0bf47a4 [bufdaemon]
   41     0     0     0  SL      pgzero   0xc0c00ab8 [pagezero]
   40     0     0     0  SL      psleep   0xc0c007d4 [vmdaemon]
   39     0     0     0  SL      psleep   0xc0c0079c [pagedaemon]
    9     0     0     0  SL      waiting_ 0xc0bf6508 [sctp_iterator]
   38     0     0     0  WL                          [irq5: pcm0]
   37     0     0     0  WL                          [swi0: sio]
   36     0     0     0  WL                          [irq7: ppc0]
    8     0     0     0  SL      -        0xc255a63c [fdc0]
   35     0     0     0  WL                          [irq12: psm0]
   34     0     0     0  WL                          [irq1: atkbd0]
   33     0     0     0  SL      usbevt   0xc2510210 [usb4]
   32     0     0     0  WL                          [irq18: ehci0++]
   31     0     0     0  SL      usbevt   0xc2548210 [usb3]
   30     0     0     0  WL                          [irq17: ohci2]
   29     0     0     0  SL      usbevt   0xc254f210 [usb2]
   28     0     0     0  WL                          [irq16: ohci1]
   27     0     0     0  SL      usbevt   0xc2544210 [usb1]
   26     0     0     0  SL      usbtsk   0xc0ba4df4 [usbtask-dr]
   25     0     0     0  SL      usbtsk   0xc0ba4de0 [usbtask-hc]
   24     0     0     0  SL      usbevt   0xc2525210 [usb0]
   23     0     0     0  WL                          [irq19: dc0 uhci0+]
   22     0     0     0  WL                          [irq15: ata1]
   21     0     0     0  WL                          [irq14: ata0]
   20     0     0     0  WL                          [swi5: +]
   19     0     0     0  WL                          [swi2: cambio]
    7     0     0     0  SL      ccb_scan 0xc0b75ff4 [xpt_thrd]
    6     0     0     0  SL      -        0xc2447d00 [kqueue taskq]
   18     0     0     0  WL                          [swi6: task queue]
   17     0     0     0  WL                          [swi6: Giant taskq]
    5     0     0     0  SL      -        0xc2470080 [thread taskq]
   16     0     0     0  SL      -        0xc0ba7514 [yarrow]
    4     0     0     0  SL      -        0xc0ba558c [g_down]
    3     0     0     0  SL      -        0xc0ba5588 [g_up]
    2     0     0     0  SL      -        0xc0ba5580 [g_event]
   15     0     0     0  WL                          [swi3: vm]
   14     0     0     0  RL                          [swi4: clock sio]
   13     0     0     0  WL                          [swi1: net]
   12     0     0     0  RL                          [idle: cpu0]
   11     0     0     0  RL                          [idle: cpu1]
    1     0     1     0  SLs     wait     0xc2449ab0 [init]
   10     0     0     0  SL      audit_wo 0xc0bffa54 [audit]
    0     0     0     0  WLs                         [swapper]
db>     
Received on Sat Jul 21 2007 - 02:57:22 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:15 UTC