Re: LOR:vfs_bio.c and ufs_dirhash.c

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) _at_ 
>> /usr/src/sys/kern/vfs_bio.c:2558
>> Jun 15 17:46:53 ibb kernel: 2nd 0xc5efd000 dirhash (dirhash) _at_ 
>> /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) _at_ 
/usr/src/sys/kern/vfs_bio.c:2558
  2nd 0xffffff000a2fa000 dirhash (dirhash) _at_ 
/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) _at_ /usr/src/sys/kern/vfs_subr.c:2083
  2nd 0xffffff80f93fccc0 bufwait (bufwait) _at_ 
/usr/src/sys/ufs/ffs/ffs_softdep.c:6170
  3rd 0xffffff02a18ef620 ufs (ufs) _at_ /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 ---