panic: lock (sleep mutex) vnode interlock not locked

From: Thierry Herbelot <thierry_at_herbelot.com>
Date: Tue, 9 Aug 2005 22:33:12 +0200
Hello,

I'm seeing the above panic on two machines (SMP BP6 and a notebook) with 
recent -Current (certainly "heisenbug" : the same kernel runs happily on the 
notebook).
The panic log on the SMP machine follows.

	TfH

#ident /usr/src/sys/kern/vfs_subr.c
/usr/src/sys/kern/vfs_subr.c:
     $FreeBSD: src/sys/kern/vfs_subr.c,v 1.638 2005/08/06 01:42:03 ssouhlal 
Exp $

FreeBSD 7.0-CURRENT #758: Tue Aug  9 20:18:36 CEST 2005
    XX_at_YYY:/usr/obj/usr/src/sys/GENERIC
WARNING: WITNESS option enabled, expect reduced performance.
MPTable: <OEM00000 PROD00000000>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Pentium II/Pentium II Xeon/Celeron (334.09-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x665  Stepping = 5
  
Features=0x183fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR>
real memory  = 100663296 (96 MB)
avail memory = 88850432 (84 MB)
....
panic: lock (sleep mutex) vnode interlock not locked 
_at_ /usr/src/sys/kern/vfs_subr.c:2117
cpuid = 1
KDB: enter: panic
[thread pid 49 tid 100039 ]
Stopped at      kdb_enter+0x2b: nop
db> where
Tracing pid 49 tid 100039 td 0xc12a4900
kdb_enter(c0859e9d) at kdb_enter+0x2b
panic(c085de0d,c08753f9,c085d79a,c0862e0e,845) at panic+0x127
witness_unlock(c1850d3c,8,c0862e0e,845) at witness_unlock+0xbc
_mtx_unlock_flags(c1850d3c,0,c0862e0e,845,c1850cc0) at _mtx_unlock_flags+0x5b
vdropl(c1850cc0,7,c12a4900,c09076c0,c1850cc0) at vdropl+0x5e
vlrureclaim(c1471800,c12a4900,c12a3830,c068412c,c12a3830) at vlrureclaim+0x1fd
vnlru_proc(0,c7228d38,0,c068412c,0) at vnlru_proc+0x18b
fork_exit(c068412c,0,c7228d38) at fork_exit+0xa0
fork_trampoline() at fork_trampoline+0x8


# kgdb kernel.debug /files3/tmp/vmcore.161
[GDB will not be able to debug user-mode threads: /usr/lib/libthread_db.so: 
Undefined symbol "ps_pglobal_lookup"]
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-marcel-freebsd".

Unread portion of the kernel message buffer:
panic: lock (sleep mutex) vnode interlock not locked 
_at_ /usr/src/sys/kern/vfs_subr.c:2117
cpuid = 1
KDB: enter: panic
Dumping 95 MB (2 chunks)
  chunk 0: 1MB (159 pages) ... ok
  chunk 1: 95MB (24320 pages) 80 64 48 32 16

#0  doadump () at pcpu.h:165
165             __asm __volatile("movl %%fs:0,%0" : "=r" (td));
(kgdb) where
#0  doadump () at pcpu.h:165
#1  0xc0469303 in db_fncall (dummy1=0, dummy2=0, dummy3=-1067144389,
    dummy4=0xc7228aa8 "Ü\212\"Ç") at /usr/src/sys/ddb/db_command.c:489
#2  0xc0469108 in db_command (last_cmdp=0xc09089a4, cmd_table=0x0, 
aux_cmd_tablep=0xc08859f4,
    aux_cmd_tablep_end=0xc0885a10) at /usr/src/sys/ddb/db_command.c:349
#3  0xc04691d0 in db_command_loop () at /usr/src/sys/ddb/db_command.c:455
#4  0xc046ad71 in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:221
#5  0xc064add4 in kdb_trap (type=3, code=0, tf=0xc7228bec) 
at /usr/src/sys/kern/subr_kdb.c:473
#6  0xc07f1400 in trap (frame=
      {tf_fs = -954073080, tf_es = -1067188184, tf_ds = -1065025496, tf_edi = 
-1064968691, tf_esi = 1, tf_ebp = -954037204, tf_isp = -954037224, tf_ebx = 
-954037160, tf_edx = 0, tf_ecx = -1056755712, tf_eax = 18, tf_trapno = 3, 
tf_err = 0, tf_eip = -1067144389, tf_cs = 32, tf_eflags = 642, tf_esp = 
-954037172, tf_ss = -1067241705}) at /usr/src/sys/i386/i386/trap.c:601
#7  0xc07deeaa in calltrap () at /usr/src/sys/i386/i386/exception.s:139
#8  0xc7220008 in ?? ()
#9  0xc0640028 in do_wait (td=0xc0859e9d, umtx=0x100, id=-1054193408, 
timeout=0xc12a4900)
    at /usr/src/sys/kern/kern_umtx.c:153
#10 0xc0632f17 in panic (fmt=0x282 <Address 0x282 out of bounds>)
    at /usr/src/sys/kern/kern_shutdown.c:537
#11 0xc0654e74 in witness_unlock (lock=0xc1850d3c, flags=8,
    file=0xc0862e0e "/usr/src/sys/kern/vfs_subr.c", line=2117)
    at /usr/src/sys/kern/subr_witness.c:1133
#12 0xc062b073 in _mtx_unlock_flags (m=0xc1850d3c, opts=0,
    file=0xc0862e0e "/usr/src/sys/kern/vfs_subr.c", line=2117)
    at /usr/src/sys/kern/kern_mutex.c:297
#13 0xc0686732 in vdropl (vp=0xc1850cc0) at /usr/src/sys/kern/vfs_subr.c:2117
---Type <return> to continue, or q <return> to quit---
#14 0xc0683f51 in vlrureclaim (mp=0xc1471800) 
at /usr/src/sys/kern/vfs_subr.c:593
#15 0xc06842b7 in vnlru_proc () at /usr/src/sys/kern/vfs_subr.c:693
#16 0xc061fb88 in fork_exit (callout=0xc068412c <vnlru_proc>, arg=0x0, 
frame=0xc7228d38)     at /usr/src/sys/kern/kern_fork.c:789
#17 0xc07def0c in fork_trampoline () at /usr/src/sys/i386/i386/exception.s:208
(kgdb) frame 13
#13 0xc0686732 in vdropl (vp=0xc1850cc0) at /usr/src/sys/kern/vfs_subr.c:2117
2117            VI_UNLOCK(vp);
(kgdb) list
2112                            vdestroy(vp);
2113                            return;
2114                    } else
2115                            vfree(vp);
2116            }
2117            VI_UNLOCK(vp);
2118    }
2119
2120    /*
2121     * Call VOP_INACTIVE on the vnode and manage the DOINGINACT and 
OWEINACT
(kgdb) print *vp
$1 = {v_type = VBAD, v_tag = 0xc0832156 "none", v_op = 0x0, v_data = 0x0, 
v_mount = 0x0,   v_nmntvnodes = {tqe_next = 0x0, tqe_prev = 0xc1ae2014}, v_un 
= {vu_mount = 0x0,    vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0}, 
v_hashlist = {le_next = 0x0,    le_prev = 0xc1bfaac0}, v_hash = 100144, 
v_cache_src = {lh_first = 0x0}, v_cache_dst = {    tqh_first = 0x0, tqh_last 
= 0xc1850cf0}, v_dd = 0x0, v_cstart = 0, v_lasta = 0,  v_lastw = 0, v_clen = 
0, v_lock = {lk_interlock = 0xc09236a0, lk_flags = 64,    lk_sharecount = 0, 
lk_waitcount = 0, lk_exclusivecount = 0, lk_prio = 80,    lk_wmesg = 
0xc0860eac "ufs", lk_timo = 51, lk_lockholder = 0xffffffff, lk_newlock = 
0x0},  v_interlock = {mtx_object = {lo_class = 0xc08bf024, lo_name = 
0xc085d79a "vnode interlock",      lo_type = 0xc085d79a "vnode interlock", 
lo_flags = 131072, lo_list = {        tqe_next = 0xc1c84b1c, tqe_prev = 
0xc185d5dc}, lo_witness = 0xc0934990}, mtx_lock = 4,    mtx_recurse = 0}, 
v_vnlock = 0xc1850d18, v_holdcnt = 0, v_usecount = 0, v_iflag = 128,
  v_vflag = 0, v_writecount = 0, v_freelist = {tqe_next = 0xc186b000, tqe_prev 
= 0xc0971ff0},  v_bufobj = {bo_mtx = 0xc1850d3c, bo_clean = {bv_hd = 
{tqh_first = 0x0,        tqh_last = 0xc1850d84}, bv_root = 0x0, bv_cnt = 0}, 
bo_dirty = {bv_hd = {        tqh_first = 0x0, tqh_last = 0xc1850d94}, bv_root 
= 0x0, bv_cnt = 0}, bo_numoutput = 0,    bo_flag = 0, bo_ops = 0xc08c5f04, 
bo_bsize = 16384, bo_object = 0x0, bo_synclist = {      le_next = 0x0, 
le_prev = 0x0}, bo_private = 0xc1850cc0, __bo_vnode = 0xc1850cc0},
  v_pollinfo = 0x0, v_label = 0x0}
(kgdb)
(kgdb) frame 15
#15 0xc06842b7 in vnlru_proc () at /usr/src/sys/kern/vfs_subr.c:693
693                             done += vlrureclaim(mp);
(kgdb) print *mp
$3 = {mnt_list = {tqe_next = 0xc1428c00, tqe_prev = 0xc1472000}, mnt_op = 
0xc08f8d40, mnt_vfc = 0xc08f8d80, mnt_vnodecovered = 0xc1478220, mnt_syncer = 
0xc14d1aa0,  mnt_nvnodelist = {tqh_first = 0xc186b000, tqh_last = 
0xc1ae2014}, mnt_lock = {    lk_interlock = 0xc0922c5c, lk_flags = 16777216, 
lk_sharecount = 1, lk_waitcount = 0,    lk_exclusivecount = 0, lk_prio = 80, 
lk_wmesg = 0xc08628dc "vfslock", lk_timo = 0,    lk_lockholder = 0xffffffff, 
lk_newlock = 0x0}, mnt_mtx = {mtx_object = {      lo_class = 0xc08bf024, 
lo_name = 0xc08628cb "struct mount mtx",      lo_type = 0xc08628cb "struct 
mount mtx", lo_flags = 196608, lo_list = {        tqe_next = 0xc146c358, 
tqe_prev = 0xc1528e80}, lo_witness = 0xc09333d8}, mtx_lock = 4,    
mtx_recurse = 0}, mnt_writeopcount = 1, mnt_flag = 2101248, mnt_opt = 
0xc144b110,  mnt_optnew = 0x0, mnt_kern_flag = 536870912, mnt_maxsymlinklen = 
120, mnt_stat = {    f_version = 537068824, f_type = 2, f_flags = 2101248, 
f_bsize = 2048, f_iosize = 16384,    f_blocks = 2076367, f_bfree = 932529, 
f_bavail = 766420, f_files = 541694,    f_ffree = 374237, f_syncwrites = 0, 
f_asyncwrites = 0, f_syncreads = 0, f_asyncreads = 0,    f_spare = {0, 0, 0, 
0, 0, 0, 0, 0, 0, 0}, f_namemax = 255, f_owner = 0, f_fsid = {val = 
{        1111831628, -1056705871}}, f_charspare = '\0' <repeats 79 times>,
    f_fstypename = "ufs", '\0' <repeats 12 times>,    f_mntfromname = 
"/dev/mirror/gm0s1f", '\0' <repeats 69 times>,    f_mntonname = "/usr", '\0' 
<repeats 83 times>}, mnt_cred = 0xc14a0280,  mnt_data = 0xc146c300, mnt_time 
= 0, mnt_iosize_max = 131072, mnt_export = 0x0,  mnt_mntlabel = 0x0, 
mnt_fslabel = 0x0, mnt_nvnodelistsize = 3047, mnt_hashseed = 1139488015}
Received on Tue Aug 09 2005 - 18:33:32 UTC

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