From owner-freebsd-current@FreeBSD.ORG Sat Nov 29 19:03:53 2008 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 27A281065670 for ; Sat, 29 Nov 2008 19:03:53 +0000 (UTC) (envelope-from rmtodd@ichotolot.servalan.com) Received: from mx1.synetsystems.com (mx1.synetsystems.com [76.10.206.14]) by mx1.freebsd.org (Postfix) with ESMTP id C47438FC12 for ; Sat, 29 Nov 2008 19:03:52 +0000 (UTC) (envelope-from rmtodd@ichotolot.servalan.com) Received: by mx1.synetsystems.com (Postfix, from userid 66) id C3803C97; Sat, 29 Nov 2008 13:45:15 -0500 (EST) Received: from localhost ([127.0.0.1]:30532 helo=ichotolot.servalan.com) by servalan.servalan.com with esmtp (Exim 4.69 (FreeBSD)) (envelope-from ) id 1L6UMh-000PiT-3S for freebsd-current@freebsd.org; Sat, 29 Nov 2008 12:16:23 -0600 To: freebsd-current@freebsd.org Date: Sat, 29 Nov 2008 12:16:23 -0600 From: Richard Todd Message-Id: <20081129184515.C3803C97@mx1.synetsystems.com> Subject: Panic upon unmounting zfs snapshot: "vput: negative ref cnt" X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 29 Nov 2008 19:03:53 -0000 I'm running -CURRENT as of this Thursday, and discovered the following panic upon doing the fairly straightforward steps of making a snapshot, mounting it, doing some activity reading from the snapshot, and unmounting it -- the exact sequence of commands was something like zfs snapshot u1@foosnap mount -r -t zfs u1@foosnap /mnt ls -lR /mnt umount /mnt Got a crash dump, gdb info follows. Note that the offending vp seems to be the vnode for the mount point that the snapshot was mounted on. Script started on Sat Nov 29 02:17:46 2008 You have mail. blo-rakane# kgdb kernel.debug /var/crash/vmcore.10 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: vput: negative ref count 0x84f70c90: tag ufs, type VDIR usecount 0, writecount 0, refcount 0 mountedhere 0 flags (VI_FREE) VI_LOCKed lock type ufs: EXCL by thread 0x84792b40 (pid 26659) ino 8070, on dev da1s1a panic: vput: negative ref cnt cpuid = 0 KDB: stack backtrace: db_trace_self_wrapper(80c23a8c,a7c78bd8,808367f9,80c5728f,0,...) at db_trace_self_wrapper+0x26 kdb_backtrace(80c5728f,0,80c2e3ed,a7c78be4,0,...) at kdb_backtrace+0x29 panic(80c2e3ed,80bdfde4,80c2e3d4,886,a7c78c14,...) at panic+0x119 vput(84f70c90,0,80c2cf23,53c,0,...) at vput+0x12b dounmount(83e12000,8000000,84792b40,482,5e402c08,...) at dounmount+0x6e0 unmount(84792b40,a7c78cf8,8,84792b40,80d07bb0,...) at unmount+0x2e0 syscall(a7c78d38) at syscall+0x2b4 Xint0x80_syscall() at Xint0x80_syscall+0x20 --- syscall (22, FreeBSD ELF32, unmount), eip = 0x200d220f, esp = 0x7fbfe02c, ebp = 0x7fbfe0f8 --- Uptime: 5h3m41s Physical memory: 621 MB Dumping 221 MB: 206 190 174 158 142 126 110 94 78 62 46 30 14 Reading symbols from /boot/kernel/geom_mirror.ko...done. Loaded symbols for /boot/kernel/geom_mirror.ko Reading symbols from /boot/kernel/zfs.ko...done. Loaded symbols for /boot/kernel/zfs.ko Reading symbols from /boot/kernel/opensolaris.ko...done. Loaded symbols for /boot/kernel/opensolaris.ko Reading symbols from /boot/kernel/linux.ko...done. Loaded symbols for /boot/kernel/linux.ko Reading symbols from /boot/kernel/green_saver.ko...done. Loaded symbols for /boot/kernel/green_saver.ko #0 doadump () at pcpu.h:246 246 __asm __volatile("movl %%fs:0,%0" : "=r" (td)); (kgdb) bt #0 doadump () at pcpu.h:246 #1 0x8083655e in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:420 #2 0x80836832 in panic (fmt=Variable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:576 #3 0x808c0ebb in vput (vp=0x84f70c90) at /usr/src/sys/kern/vfs_subr.c:2199 #4 0x808b9160 in dounmount (mp=0x83e12000, flags=134217728, td=0x84792b40) at /usr/src/sys/kern/vfs_mount.c:1343 #5 0x808b9480 in unmount (td=0x84792b40, uap=0xa7c78cf8) at /usr/src/sys/kern/vfs_mount.c:1182 #6 0x80b6b214 in syscall (frame=0xa7c78d38) at /usr/src/sys/i386/i386/trap.c:1076 #7 0x80b4ff10 in Xint0x80_syscall () at /usr/src/sys/i386/i386/exception.s:261 #8 0x00000033 in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) fr 3 #3 0x808c0ebb in vput (vp=0x84f70c90) at /usr/src/sys/kern/vfs_subr.c:2199 2199 panic("vput: negative ref cnt"); (kgdb) p *vp $1 = {v_type = VDIR, v_tag = 0x80c1a42c "ufs", v_op = 0x80d2c6e0, v_data = 0x84e427f8, v_mount = 0x83e12c80, v_nmntvnodes = { tqe_next = 0x885de324, tqe_prev = 0x84f6f768}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist = {le_next = 0x0, le_prev = 0x83c9f2a4}, v_hash = 8070, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0x84f58440, tqh_last = 0x84f58450}, v_dd = 0x83cfda78, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = { lo_name = 0x80c1a42c "ufs", lo_flags = 91947009, lo_data = 0, lo_witness = 0x0}, lk_lock = 2222533440, lk_timo = 16, lk_pri = 80}, v_interlock = {lock_object = {lo_name = 0x80c26a32 "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 2222533440}, v_vnlock = 0x84f70ce8, v_holdcnt = 0, v_usecount = 0, v_iflag = 256, v_vflag = 0, v_writecount = 0, v_freelist = { tqe_next = 0x0, tqe_prev = 0x84b242b8}, v_bufobj = {bo_mtx = { lock_object = {lo_name = 0x80c2e32a "bufobj interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0x84f70d4c}, bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0x84f70d5c}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_ops = 0x80d17100, bo_bsize = 16384, bo_object = 0x0, bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0x84f70c90, __bo_vnode = 0x84f70c90}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0} (kgdb) l 2194 2195 if (vp->v_usecount != 1) { 2196 #ifdef DIAGNOSTIC 2197 vprint("vput: negative ref count", vp); 2198 #endif 2199 panic("vput: negative ref cnt"); 2200 } 2201 /* 2202 * We want to hold the vnode until the inactive finishes to 2203 * prevent vgone() races. We drop the use count here and the (kgdb) p vp->v_usecount $2 = 0 (kgdb) fr 4 #4 0x808b9160 in dounmount (mp=0x83e12000, flags=134217728, td=0x84792b40) at /usr/src/sys/kern/vfs_mount.c:1343 1343 vput(coveredvp); (kgdb) p coveredvp $3 = (struct vnode *) 0x84f70c90 (kgdb) p coveredvp[0] $4 = {v_type = VDIR, v_tag = 0x80c1a42c "ufs", v_op = 0x80d2c6e0, v_data = 0x84e427f8, v_mount = 0x83e12c80, v_nmntvnodes = { tqe_next = 0x885de324, tqe_prev = 0x84f6f768}, v_un = {vu_mount = 0x0, vu_socket = 0x0, vu_cdev = 0x0, vu_fifoinfo = 0x0, vu_yield = 0}, v_hashlist = {le_next = 0x0, le_prev = 0x83c9f2a4}, v_hash = 8070, v_cache_src = {lh_first = 0x0}, v_cache_dst = {tqh_first = 0x84f58440, tqh_last = 0x84f58450}, v_dd = 0x83cfda78, v_cstart = 0, v_lasta = 0, v_lastw = 0, v_clen = 0, v_lock = {lock_object = { lo_name = 0x80c1a42c "ufs", lo_flags = 91947009, lo_data = 0, lo_witness = 0x0}, lk_lock = 2222533440, lk_timo = 16, lk_pri = 80}, v_interlock = {lock_object = {lo_name = 0x80c26a32 "vnode interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 2222533440}, v_vnlock = 0x84f70ce8, v_holdcnt = 0, v_usecount = 0, v_iflag = 256, v_vflag = 0, v_writecount = 0, v_freelist = { tqe_next = 0x0, tqe_prev = 0x84b242b8}, v_bufobj = {bo_mtx = { lock_object = {lo_name = 0x80c2e32a "bufobj interlock", lo_flags = 16973824, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, bo_clean = {bv_hd = {tqh_first = 0x0, tqh_last = 0x84f70d4c}, bv_root = 0x0, bv_cnt = 0}, bo_dirty = {bv_hd = {tqh_first = 0x0, tqh_last = 0x84f70d5c}, bv_root = 0x0, bv_cnt = 0}, bo_numoutput = 0, bo_flag = 0, bo_ops = 0x80d17100, bo_bsize = 16384, bo_object = 0x0, bo_synclist = {le_next = 0x0, le_prev = 0x0}, bo_private = 0x84f70c90, __bo_vnode = 0x84f70c90}, v_pollinfo = 0x0, v_label = 0x0, v_lockf = 0x0} (kgdb) l 1338 mtx_lock(&mountlist_mtx); 1339 TAILQ_REMOVE(&mountlist, mp, mnt_list); 1340 mtx_unlock(&mountlist_mtx); 1341 if (coveredvp != NULL) { 1342 coveredvp->v_mountedhere = NULL; 1343 vput(coveredvp); 1344 } 1345 vfs_event_signal(NULL, VQ_UNMOUNT, 0); 1346 vfs_mount_destroy(mp); 1347 return (0); (kgdb) q blo-rakane# exit exit Script done on Sat Nov 29 02:19:59 2008