From owner-freebsd-current@FreeBSD.ORG Tue Jul 14 13:36:44 2009 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 C3CD1106566B for ; Tue, 14 Jul 2009 13:36:44 +0000 (UTC) (envelope-from 000.fbsd@quip.cz) Received: from elsa.codelab.cz (elsa.codelab.cz [94.124.105.4]) by mx1.freebsd.org (Postfix) with ESMTP id 680578FC15 for ; Tue, 14 Jul 2009 13:36:44 +0000 (UTC) (envelope-from 000.fbsd@quip.cz) Received: from localhost (localhost.codelab.cz [127.0.0.1]) by elsa.codelab.cz (Postfix) with ESMTP id 335FE19E023; Tue, 14 Jul 2009 15:36:41 +0200 (CEST) Received: from [192.168.1.2] (r5bb235.net.upc.cz [86.49.61.235]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by elsa.codelab.cz (Postfix) with ESMTPSA id 9178519E019; Tue, 14 Jul 2009 15:36:38 +0200 (CEST) Message-ID: <4A5C89E7.503@quip.cz> Date: Tue, 14 Jul 2009 15:36:39 +0200 From: Miroslav Lachman <000.fbsd@quip.cz> User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.7.12) Gecko/20050915 X-Accept-Language: cz, cs, en, en-us MIME-Version: 1.0 To: Nick Barkas References: <549859.9626.qm@web25007.mail.ukl.yahoo.com> <4A379AEE.7080101@freebsd.org> In-Reply-To: <4A379AEE.7080101@freebsd.org> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit Cc: "freebsd-current@freebsd.org" Subject: Re: LOR:vfs_bio.c and ufs_dirhash.c 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: Tue, 14 Jul 2009 13:36:45 -0000 Nick Barkas wrote: [snip] >> Jun 15 17:46:53 ibb kernel: lock order reversal: >> Jun 15 17:46:53 ibb kernel: 1st 0xd9537bb0 bufwait (bufwait) @ >> /usr/src/sys/kern/vfs_bio.c:2558 >> Jun 15 17:46:53 ibb kernel: 2nd 0xc5efd000 dirhash (dirhash) @ >> /usr/src/sys/ufs/ufs/ufs_dirhash.c:285 >> Jun 15 17:46:53 ibb kernel: KDB: stack backtrace: >> Jun 15 17:46:53 ibb kernel: >> db_trace_self_wrapper(c0c5e1c8,e813a87c,c08b15d5,c08a250b,c0c6100b,...) >> at db_trace_self_wrapper+0x26 >> Jun 15 17:46:53 ibb kernel: >> kdb_backtrace(c08a250b,c0c6100b,c552acf0,c5530c00,e813a8d8,...) at >> kdb_backtrace+0x29 >> Jun 15 17:46:53 ibb kernel: >> _witness_debugger(c0c6100b,c5efd000,c0c810bd,c5530c00,c0c80d56,...) at >> _witness_debugger+0x25 >> Jun 15 17:46:53 ibb kernel: >> witness_checkorder(c5efd000,9,c0c80d56,11d,0,...) at >> witness_checkorder+0x839 >> Jun 15 17:46:53 ibb kernel: >> _sx_xlock(c5efd000,0,c0c80d56,11d,c6015c3c,...) at _sx_xlock+0x85 >> Jun 15 17:46:53 ibb kernel: >> ufsdirhash_acquire(d9537b50,da6db800,200,da6db81c,e813a9a8,...) at >> ufsdirhash_acquire+0x35 >> Jun 15 17:46:53 ibb kernel: >> ufsdirhash_add(c6015c3c,e813aa20,81c,e813a994,e813a998,...) at >> ufsdirhash_add+0x13 >> Jun 15 17:46:53 ibb kernel: >> ufs_direnter(c5ff596c,c6139218,e813aa20,e813ac04,d956c200,...) at >> ufs_direnter+0x729 >> Jun 15 17:46:53 ibb kernel: ufs_mkdir(e813ac28,ead,0,0,e813ab70,...) >> at ufs_mkdir+0x897 >> Jun 15 17:46:53 ibb kernel: >> VOP_MKDIR_APV(c0d5eec0,e813ac28,e813ac04,e813ab70,0,...) at >> VOP_MKDIR_APV+0xa5 >> Jun 15 17:46:53 ibb kernel: >> kern_mkdirat(c5cda480,ffffff9c,28528f80,0,1ed,...) at kern_mkdirat+0x268 >> Jun 15 17:46:53 ibb kernel: >> kern_mkdir(c5cda480,28528f80,0,1ed,e813ad2c,...) at kern_mkdir+0x2e >> Jun 15 17:46:53 ibb kernel: >> mkdir(c5cda480,e813acf8,8,c0c5e284,c0d3f240,...) at mkdir+0x29 >> Jun 15 17:46:53 ibb kernel: syscall(e813ad38) at syscall+0x2a3 >> Jun 15 17:46:53 ibb kernel: Xint0x80_syscall() at Xint0x80_syscall+0x20 >> Jun 15 17:46:53 ibb kernel: --- syscall (136, FreeBSD ELF32, mkdir), >> eip = 0x283063c3, esp = 0xbf4f9d1c, ebp = 0xbf4f9d48 --- >> >> Mail me, if I can help with anything else... > > > This is known, and shouldn't be anything to worry about because it will > not result in a deadlock. See the comment added in r187474: > > + * WITNESS reports a lock order reversal between the "bufwait" lock > + * and the "dirhash" lock. However, this specific reversal will not > + * cause a deadlock. To get a deadlock, one would have to lock a > + * buffer followed by the dirhash while a second thread locked a > + * buffer while holding the dirhash lock. The second order can happen > + * under a shared or exclusive vnode lock for the associated directory > + * in lookup(). The first order, however, can only happen under an > + * exclusive vnode lock (e.g. unlink(), rename(), etc.). Thus, for > + * a thread to be doing a "bufwait" -> "dirhash" order, it has to hold > + * an exclusive vnode lock. That exclusive vnode lock will prevent > + * any other threads from doing a "dirhash" -> "bufwait" order. > > See also http://sources.zabbadoz.net/freebsd/lor/261.html but note that > you are seeing different line numbers in vfs_bio.c and ufs_dirhash.c > because those files have been changed since this page was first created > back in September. I don't know how to identify the uniqueness of the LOR. I installed 8.0-BETA1 amd64 with GENERIC kernel on new server for testing (Xeon E5520 QuadCore + 12GB RAM) and got following LORs in heavy IO operation (portsnap extract) Both LORs appeared at the same time (in var/log/messages) lock order reversal: 1st 0xffffff80f93fccc0 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:2558 2nd 0xffffff000a2fa000 dirhash (dirhash) @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:285 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a _witness_debugger() at _witness_debugger+0x2e witness_checkorder() at witness_checkorder+0x81e _sx_xlock() at _sx_xlock+0x55 ufsdirhash_acquire() at ufsdirhash_acquire+0x33 ufsdirhash_add() at ufsdirhash_add+0x19 ufs_direnter() at ufs_direnter+0x88b ufs_makeinode() at ufs_makeinode+0x2a7 VOP_CREATE_APV() at VOP_CREATE_APV+0x8d vn_open_cred() at vn_open_cred+0x468 kern_openat() at kern_openat+0x179 syscall() at syscall+0x1af Xfast_syscall() at Xfast_syscall+0xd0 --- syscall (5, FreeBSD ELF64, open), rip = 0x800e32d5c, rsp = 0x7fffffffe5d8, rbp = 0x1a4 --- lock order reversal: 1st 0xffffff02a21f7620 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2083 2nd 0xffffff80f93fccc0 bufwait (bufwait) @ /usr/src/sys/ufs/ffs/ffs_softdep.c:6170 3rd 0xffffff02a18ef620 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2083 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a _witness_debugger() at _witness_debugger+0x2e witness_checkorder() at witness_checkorder+0x81e __lockmgr_args() at __lockmgr_args+0xcf3 ffs_lock() at ffs_lock+0x8c VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b _vn_lock() at _vn_lock+0x47 vget() at vget+0x7b vfs_hash_get() at vfs_hash_get+0xd5 ffs_vgetf() at ffs_vgetf+0x48 softdep_sync_metadata() at softdep_sync_metadata+0x475 ffs_syncvnode() at ffs_syncvnode+0x210 ffs_fsync() at ffs_fsync+0x43 ufs_direnter() at ufs_direnter+0x315 ufs_makeinode() at ufs_makeinode+0x2a7 VOP_CREATE_APV() at VOP_CREATE_APV+0x8d vn_open_cred() at vn_open_cred+0x468 kern_openat() at kern_openat+0x179 syscall() at syscall+0x1af Xfast_syscall() at Xfast_syscall+0xd0 --- syscall (5, FreeBSD ELF64, open), rip = 0x800e32d5c, rsp = 0x7fffffffe5d8, rbp = 0x1a4 ---