Re: LOR: vfs_lookup.c:501 ffs_vnops.c:261 vfs_subr.c:2134

Hi Folks,

   I just updated this particular systems to current as of this
evening (2011-07-05 7:22pm EDT) and am still seeing this LOR.

lock order reversal:
 1st 0xfffffe003c893818 ufs (ufs) _at_ /usr/src.2011-07-05_7.22pm_EDT/sys/kern/vfs_lookup.c:501
 2nd 0xffffff9f0c7eeef8 bufwait (bufwait) _at_ /usr/src.2011-07-05_7.22pm_EDT/sys/ufs/ffs/ffs_vnops.c:261
 3rd 0xfffffe003c8689f8 ufs (ufs) _at_ /usr/src.2011-07-05_7.22pm_EDT/sys/kern/vfs_subr.c:2134
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
kdb_backtrace() at kdb_backtrace+0x37
_witness_debugger() at _witness_debugger+0x2e
witness_checkorder() at witness_checkorder+0x807
__lockmgr_args() at __lockmgr_args+0xd42
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_buf() at softdep_sync_buf+0x568
ffs_syncvnode() at ffs_syncvnode+0x293
ffs_truncate() at ffs_truncate+0x4c4
ufs_direnter() at ufs_direnter+0x6ed
ufs_makeinode() at ufs_makeinode+0x250
VOP_CREATE_APV() at VOP_CREATE_APV+0x8d
vn_open_cred() at vn_open_cred+0x46a
kern_openat() at kern_openat+0x17f
syscallenter() at syscallenter+0x1aa
syscall() at syscall+0x4c
Xfast_syscall() at Xfast_syscall+0xdd
--- syscall (5, FreeBSD ELF64, open), rip = 0x800936b9c, rsp = 0x7fffffffdac8, rbp = 0 ---

   Cross-posting to -fs for more visibility. Thoughts welcome.

-John

----- John's Original Message -----
> Hi folks,
> 
>    I'm seeing the following LOR in dmesg after my latest update this evening.
> 
> # uname -a
> FreeBSD zfscarp3p 9.0-CURRENT FreeBSD 9.0-CURRENT #0: Fri Jun 17 22:36:45 EDT 2011     root_at_zfscarp3p/usr/obj/usr/src.2011-06-17_9.36pm_EDT/sys/GENERIC amd6
> 
> WARNING: WITNESS option enabled, expect reduced performance.
> Trying to mount root from ufs:/dev/da56s1a [rw]...
> lock order reversal:
>  1st 0xfffffe003d2f9278 ufs (ufs) _at_ /usr/src.2011-06-17_9.36pm_EDT/sys/kern/vfs_lookup.c:501
>  2nd 0xffffff9f0c7f0e58 bufwait (bufwait) _at_ /usr/src.2011-06-17_9.36pm_EDT/sys/ufs/ffs/ffs_vnops.c:261
>  3rd 0xfffffe003d371278 ufs (ufs) _at_ /usr/src.2011-06-17_9.36pm_EDT/sys/kern/vfs_subr.c:2134
> KDB: stack backtrace:
> db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
> kdb_backtrace() at kdb_backtrace+0x37
> _witness_debugger() at _witness_debugger+0x2e
> witness_checkorder() at witness_checkorder+0x807
> __lockmgr_args() at __lockmgr_args+0xd42
> 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_buf() at softdep_sync_buf+0x56a
> ffs_syncvnode() at ffs_syncvnode+0x293
> ffs_truncate() at ffs_truncate+0x4c4
> ufs_direnter() at ufs_direnter+0x6ed
> ufs_makeinode() at ufs_makeinode+0x250
> VOP_CREATE_APV() at VOP_CREATE_APV+0x8d
> vn_open_cred() at vn_open_cred+0x46a
> kern_openat() at kern_openat+0x17f
> syscallenter() at syscallenter+0x1aa
> syscall() at syscall+0x4c
> Xfast_syscall() at Xfast_syscall+0xdd
> --- syscall (5, FreeBSD ELF64, open), rip = 0x800936b7c, rsp = 0x7fffffffdac8, rbp = 0 ---
> bce1: Gigabit link up!
> 
>    Only seems to happen once at boot time.
> 
> Thanks,
> John