From owner-freebsd-current@FreeBSD.ORG Tue Aug 9 20:33:32 2005 Return-Path: X-Original-To: freebsd-current@freebsd.org Delivered-To: freebsd-current@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6AC1F16A41F for ; Tue, 9 Aug 2005 20:33:32 +0000 (GMT) (envelope-from thierry@herbelot.com) Received: from postfix4-1.free.fr (postfix4-1.free.fr [213.228.0.62]) by mx1.FreeBSD.org (Postfix) with ESMTP id 9F9D243D58 for ; Tue, 9 Aug 2005 20:33:31 +0000 (GMT) (envelope-from thierry@herbelot.com) Received: from herbelot.dyndns.org (bne75-4-82-227-159-103.fbx.proxad.net [82.227.159.103]) by postfix4-1.free.fr (Postfix) with ESMTP id 6B1E3319E3E for ; Tue, 9 Aug 2005 22:33:30 +0200 (CEST) Received: from diversion.herbelot.nom (diversion.herbelot.nom [192.168.2.6]) by herbelot.dyndns.org (8.13.3/8.13.3) with ESMTP id j79KXMEr004592 for ; Tue, 9 Aug 2005 22:33:28 +0200 (CEST) From: Thierry Herbelot To: freebsd-current@freebsd.org Date: Tue, 9 Aug 2005 22:33:12 +0200 User-Agent: KMail/1.8.2 X-Warning: Windows can lose your files X-Op-Sys: Le FriBi de la mort qui tue X-Org: TfH&Co X-MailScanner: Found to be clean MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-15" Content-Transfer-Encoding: 8bit Content-Disposition: inline Message-Id: <200508092233.14912.thierry@herbelot.com> Subject: panic: lock (sleep mutex) vnode interlock not locked X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: thierry@herbelot.com List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 09 Aug 2005 20:33:32 -0000 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@YYY:/usr/obj/usr/src/sys/GENERIC WARNING: WITNESS option enabled, expect reduced performance. MPTable: 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 real memory = 100663296 (96 MB) avail memory = 88850432 (84 MB) .... panic: lock (sleep mutex) vnode interlock not locked @ /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 @ /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
) 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 to continue, or q 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 , 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' , f_fstypename = "ufs", '\0' , f_mntfromname = "/dev/mirror/gm0s1f", '\0' , f_mntonname = "/usr", '\0' }, 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}