From owner-freebsd-current@FreeBSD.ORG Fri Jan 18 07:40:13 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 26D4716A468 for ; Fri, 18 Jan 2008 07:40:13 +0000 (UTC) (envelope-from swhetzel@gmail.com) Received: from fg-out-1718.google.com (fg-out-1718.google.com [72.14.220.154]) by mx1.freebsd.org (Postfix) with ESMTP id 6BC2B13C46A for ; Fri, 18 Jan 2008 07:40:12 +0000 (UTC) (envelope-from swhetzel@gmail.com) Received: by fg-out-1718.google.com with SMTP id 16so1086292fgg.35 for ; Thu, 17 Jan 2008 23:40:11 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:to:subject:cc:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:references; bh=+H5bs5g7zWOb+mqy/+2gLrNwSIOTqVccBwZ8EqUrTFg=; b=honubedcaR+pLhNMoBBoQRWEAHwGlh/wiPtqJ12PloIFTnd9KOglzm+MVoD20geHv9WGDERRE/SdVH5ZCuCEAe0Xix97qxoP+TxIv9dKY0ycmIJSsJgjBNjY9WIz1jJ8g/srPWH/8Uki5s2CCR0UXKBj5RvzGWtU4++OA13FhTk= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:to:subject:cc:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:references; b=DtR/ruwuDIzirugvTl/8JF05AEZ8yoh3HgggBo0nCBzelMo2rHeIvIEcCtld3QBc254yAYy0FqReWmHsMTtEwu4WJRskSIyHei40ghbklsChHzmQR/mfpJAskzWlAftF/olj9AYZ7+bRJ+bMgs7PrCGOJt4U280tiW6xFee+GIQ= Received: by 10.86.90.2 with SMTP id n2mr2787104fgb.66.1200642011402; Thu, 17 Jan 2008 23:40:11 -0800 (PST) Received: by 10.86.70.11 with HTTP; Thu, 17 Jan 2008 23:40:11 -0800 (PST) Message-ID: <790a9fff0801172340p664b48c0m9a3b961ab2e7918f@mail.gmail.com> Date: Fri, 18 Jan 2008 01:40:11 -0600 From: "Scot Hetzel" To: "Pawel Jakub Dawidek" In-Reply-To: <790a9fff0801172312o18d46a65x3be9c8f752f7845d@mail.gmail.com> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: <790a9fff0801150552l542a4238ofc12efe5fdb45fc2@mail.gmail.com> <20080115143924.GB57756@deviant.kiev.zoral.com.ua> <790a9fff0801152301l5d50461aw3a253608506368e2@mail.gmail.com> <790a9fff0801161624g459857b8y6217e579337f2f0e@mail.gmail.com> <790a9fff0801161810j5a9953c4j5d2f3f10b3a1baf@mail.gmail.com> <20080117114023.GF8820@garage.freebsd.pl> <790a9fff0801172312o18d46a65x3be9c8f752f7845d@mail.gmail.com> Cc: freebsd-current@freebsd.org Subject: Re: panic: System call lstat returning with 1 locks held 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: Fri, 18 Jan 2008 07:40:13 -0000 Previous message sent prematurely. On 1/18/08, Scot Hetzel wrote: > On 1/17/08, Pawel Jakub Dawidek wrote: > > On Wed, Jan 16, 2008 at 08:10:03PM -0600, Scot Hetzel wrote: > > > The local CVS repository is on a ZFS filesystem. Is anyone seeing > > > this problem on a UFS filesystem? > > > > WITNESS won't work on ZFS' lock by default. Please add: > > > > CFLAGS+=-DDEBUG > > > > to sys/modules/zfs/Makefile and recompile zfs kernel module. DEBUG > > define tells ZFS not to add NOWITNESS flag at lock initialization time. > > > > I rebuilt the zfs module as suggested. > > When I reboot, I am now seeing 4 different lock order reversals related to ZFS: > > 1. This lock order reversal occurs most often: > > lock order reversal: > 1st 0xffffff0001b95838 dr->dt.di.dr_mtx (dr->dt.di.dr_mtx) @ > /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1866 > 2nd 0xffffff00017531c0 db->db_mtx (db->db_mtx) @ > /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1888 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > witness_checkorder() at witness_checkorder+0x606 > _sx_xlock() at _sx_xlock+0x52 > dbuf_sync_list() at dbuf_sync_list+0x215 > dbuf_sync_list() at dbuf_sync_list+0x194 > dnode_sync() at dnode_sync+0x385 > dmu_objset_sync() at dmu_objset_sync+0x116 > dsl_pool_sync() at dsl_pool_sync+0x153 > spa_sync() at spa_sync+0x39e > txg_sync_thread() at txg_sync_thread+0x17d > fork_exit() at fork_exit+0x12a > fork_trampoline() at fork_trampoline+0xe > --- trap 0, rip = 0, rsp = 0xffffffffd72a3d30, rbp = 0 --- > > 2. This lock order reversal is similar to the one above: > > lock order reversal: > 1st 0xffffff0001b00d38 dr->dt.di.dr_mtx (dr->dt.di.dr_mtx) @ > /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1866 > 2nd 0xffffff0001a27760 db->db_mtx (db->db_mtx) @ > /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1837 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > witness_checkorder() at witness_checkorder+0x606 > _sx_xlock() at _sx_xlock+0x52 > dbuf_sync_list() at dbuf_sync_list+0xaf > dbuf_sync_list() at dbuf_sync_list+0x194 > dnode_sync() at dnode_sync+0x385 > dmu_objset_sync() at dmu_objset_sync+0x116 > dsl_pool_sync() at dsl_pool_sync+0x72 > spa_sync() at spa_sync+0x39e > txg_sync_thread() at txg_sync_thread+0x17d > fork_exit() at fork_exit+0x12a > fork_trampoline() at fork_trampoline+0xe > --- trap 0, rip = 0, rsp = 0xffffffffd72a3d30, rbp = 0 --- > 3. lock order reversal related to the write syscall lock order reversal: 1st 0xffffff00269f6500 dn->dn_mtx (dn->dn_mtx) @ /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dnode.c:874 2nd 0xffffff0026338d38 dr->dt.di.dr_mtx (dr->dt.di.dr_mtx) @ /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dnode.c:875 KDB: Stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a witness_check_order() at witness_check_order+0x606 _sx_lock() at _sx_lock+0x52 dnode_new_blkid() at dnode_new_blkid+0x15b dbuf_dirty() at dbuf_dirty+0x7dc dmu_write_uio() at dmu_write_uio+0x167 zfs_freebsd_write() at zfs_freebsd_write+0x9b4 VOP_WRITE_APV() at VOP_WRITE_APV+0x131 vn_write() at vn_write+0x24f dofilewrite() at dofilewrite+0x85 kern_writev() at kern_writev+0x60 write() at write+0x54 syscall() at syscall+0x1ce Xfast_syscall() at Xfast_syscall+0xab --- syscall (4, FreeBSD ELF64, write), rip = 0x8009f623c, rsp = 0x7729d0, rbp = 0x772a18 --- 4. lock order reversal related to the lstat syscall lock order reversal: 1st 0xffffff0001578058 zfsvfs->z_um_lock (zfsvfs->z_um_lock) @ /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/zfs_vnops.c:2949 2nd 0xffffff001725cd0 tx->tx_sync_lock (tx->tx_sync_lock) @ /usr/src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/txg.c:414 KDB: Stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a witness_check_order() at witness_check_order+0x606 _sx_lock() at _sx_lock+0x52 txg_wait_open() at txg_wait_open+0x34 dmu_tx_assign() at dmu_tx_assign+0x2a5 zfs_inactive() at zfs_inactive+0x21f zfs_freebsd_inactive() at zfs_freebsd_inactive+0x18 VOP_INACTIVE_APV() at VOP_INACTIVE_APV+0xb5 vinactive() at vinactive+0x90 vput() at vput+0x24d namei() at namei+0x29a kern_lstat() at kern_lstat+0x5e lstat() at lstat+0x2a syscall() at syscall+0x1ce Xfast_syscall() at Xfast_syscall+0xab --- syscall (190, FreeBSD ELF64, lstat), rip = 0x8009e87ec, rsp = 0x72f1d0, rbp = 0x72f2a8 --- The panic didn't occur after lock order reversal 4, instead it occured after the system had displayed lock order reversal 2. hp010# /usr/local/etc/cvsup/update.sh & hp010# tail -f /var/log/cvsup.log : : : : : Edit CVSROOT-ports/modules,v : : Edit ports/audio/sonata/pkg-plist,v panic: System call lstat returning with 1 locks held cpuid = 0 KDB: enter: panic [ thread pid 996 tid 10011 ] stopped at kdb_enter+0x3d: movq $0,0x4ad188(%rip) db> show lockedvnods Locked vnodes db> Scot