several lock order reversals in VFS suddenly.

Mon Aug 18 09:35:54 UTC 2008

Hey guys, I just updated to -current to play with usb2 and noticed
a few lock order reversals, any ideas?

lock order reversal: (sleepable after non-sleepable)
 1st 0xc388b01c struct mount mtx (struct mount mtx) @ /vol/share/src/sys/kern/vfs_subr.c:346 2nd 0xc388b000 vfslock (vfslock) @ /vol/share/src/sys/kern/vfs_subr.c:373
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c3258b08,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26kdb_backtrace(4,c0b8bf99,c0e080f0,c3476388,c3258b60,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c388b000,c0b9949e,c3476388,c0b99a43,...) at _witness_debugger+0x25witness_checkorder(c388b000,1,c0b99a43,175,c0b8bf99,...) at witness_checkorder+0x7c9
__lockmgr_args(c388b000,200100,c388b01c,0,0,...) at __lockmgr_args+0x230
vfs_busy(c388b000,200,0,c34c3d20,1,...) at vfs_busy+0x1bc
vfs_mount_alloc(0,c0c5e100,c0b997e9,c34c3d20,c084ffe0,...) at vfs_mount_alloc+0x78
vfs_mountroot(c0ccda70,4,c0b87e4d,267,0,...) at vfs_mountroot+0x26c
start_init(0,c3258d38,c0b8987e,322,c34c1d0c,...) at start_init+0x6f
fork_exit(c07984e0,0,c3258d38) at fork_exit+0xb8
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xc3258d70, ebp = 0 ---

lock order reversal: (sleepable after non-sleepable)
 1st 0xc389228c vnode interlock (vnode interlock) @ /vol/share/src/sys/fs/devfs/devfs_vnops.c:286 2nd 0xc3892270 devfs (devfs) @ /vol/share/src/sys/kern/vfs_subr.c:2044
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c3258a2c,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26kdb_backtrace(4,c0b8bf99,c0e07438,c34764c0,c3258a84,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c3892270,c0b83670,c34764c0,c0b99a43,...) at _witness_debugger+0x25witness_checkorder(c3892270,9,c0b99a43,7fc,c0bb295e,...) at witness_checkorder+0x7c9
__lockmgr_args(c3892270,80100,c389228c,0,0,...) at __lockmgr_args+0x790
vop_stdlock(c3258b88,c0b83832,c0b86ad6,80100,c3892218,...) at vop_stdlock+0x62
VOP_LOCK1_APV(c0c5e1e0,c3258b88,c0c9c380,c3892218,80100,...) at VOP_LOCK1_APV+0xa5
_vn_lock(c3892218,80100,c0b99a43,7fc,8,...) at _vn_lock+0x5e
vget(c3892218,80100,c34c3d20,11f,c0b837c9,...) at vget+0xc9
devfs_allocv(c3891700,c388b000,c3258c20,c34c3d20,c0e07438,...) at devfs_allocv+0x11a
devfs_root(c388b000,80000,c0e33c34,c34c3d20,4,...) at devfs_root+0x51
set_rootvnode(c0e33c20,0,c0b9939a,5f4,c084ffe0,...) at set_rootvnode+0x2d
vfs_mountroot(c0ccda70,4,c0b87e4d,267,0,...) at vfs_mountroot+0x34c
start_init(0,c3258d38,c0b8987e,322,c34c1d0c,...) at start_init+0x6f
fork_exit(c07984e0,0,c3258d38) at fork_exit+0xb8
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xc3258d70, ebp = 0 ---

lock order reversal: (sleepable after non-sleepable)
 1st 0xc3766e10 vnode interlock (vnode interlock) @ /vol/share/src/sys/kern/vfs_hash.c:79
 2nd 0xc3766df4 ufs (ufs) @ /vol/share/src/sys/kern/vfs_subr.c:2044
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c3258908,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26
kdb_backtrace(4,c0b8bf99,c0e070c8,c34765f8,c3258960,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c3766df4,c0b873de,c34765f8,c0b99a43,...) at _witness_debugger+0x25
witness_checkorder(c3766df4,9,c0b99a43,7fc,80246,...) at witness_checkorder+0x7c9
__lockmgr_args(c3766df4,80100,c3766e10,0,0,...) at __lockmgr_args+0x790
ffs_lock(c3258a6c,c0b99020,c0b86ad6,80100,c3766d9c,...) at ffs_lock+0x8a
VOP_LOCK1_APV(c0c842a0,c3258a6c,c0c9c380,c3766d9c,80100,...) at VOP_LOCK1_APV+0xa5
_vn_lock(c3766d9c,80100,c0b99a43,7fc,4,...) at _vn_lock+0x5e
vget(c3766d9c,80100,c34c3d20,50,0,...) at vget+0xc9
vfs_hash_get(c388ad20,2,80000,c34c3d20,c3258b64,...) at vfs_hash_get+0xe6
ffs_vget(c388ad20,2,80000,c3258b64,c0b9939a,...) at ffs_vget+0x49
ufs_root(c388ad20,80000,c0e33c34,c34c3d20,4,...) at ufs_root+0x28
set_rootvnode(c389228c,0,c0b9939a,613,c0b86ad8,...) at set_rootvnode+0x2d
vfs_mountroot_try(c0b9999f,c0b86ad8,c0b997ea,1,c084ffe0,...) at vfs_mountroot_try+0x2cd
vfs_mountroot(c0ccda70,4,c0b87e4d,267,0,...) at vfs_mountroot+0x40e
start_init(0,c3258d38,c0b8987e,322,c34c1d0c,...) at start_init+0x6f
fork_exit(c07984e0,0,c3258d38) at fork_exit+0xb8
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xc3258d70, ebp = 0 ---

lock order reversal: (sleepable after non-sleepable)
 1st 0xc3766e44 bufobj interlock (bufobj interlock) @ /vol/share/src/sys/kern/vfs_bio.c:2429
 2nd 0xc31147d0 bufwait (bufwait) @ /vol/share/src/sys/kern/vfs_bio.c:2443
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c3258728,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26
kdb_backtrace(4,c0b8bf99,c0e073e0,c34737a8,c3258780,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c31147d0,c0b98339,c34737a8,c0b978e2,...) at _witness_debugger+0x25
witness_checkorder(c31147d0,9,c0b978e2,98b,c32587a4,...) at witness_checkorder+0x7c9
__lockmgr_args(c31147d0,81900,c3766e44,c0b98295,50,...) at __lockmgr_args+0x790
getblk(c3766d9c,0,0,800,0,...) at getblk+0x153
breadn(c3766d9c,0,0,800,0,...) at breadn+0x44
bread(c3766d9c,0,0,800,0,...) at bread+0x4c
ffs_blkatoff(c3766d9c,0,0,0,c32589a4,...) at ffs_blkatoff+0xd1
ufs_lookup(c32589e8,c3766d9c,c3258b38,c3766d9c,c3258a08,...) at ufs_lookup+0x2e6
VOP_CACHEDLOOKUP_APV(c0c842a0,c32589e8,c3258b38,c3258b24,c348c300,...) at VOP_CACHEDLOOKUP_APV+0xa5
vfs_cache_lookup(c3258a68,c3258a68,500000c,80000,c3766d9c,...) at vfs_cache_lookup+0xd0
VOP_LOOKUP_APV(c0c842a0,c3258a68,c0b99142,1b0,c3258b24,...) at VOP_LOOKUP_APV+0xa5
lookup(c3258b0c,c0b99142,d8,c0,c348c42c,...) at lookup+0x57e
namei(c3258b0c,c3258b24,c081003c,c0e073e0,c0b997e5,...) at namei+0x44b
kern_unlinkat(c34c3d20,ffffff9c,c0b997e5,1,c3258c5c,...) at kern_unlinkat+0x46
kern_unlink(c34c3d20,c0b997e5,1,62f,0,...) at kern_unlink+0x27
vfs_mountroot_try(c0b9999f,c0b86ad8,c0b997ea,1,c084ffe0,...) at vfs_mountroot_try+0x482
vfs_mountroot(c0ccda70,4,c0b87e4d,267,0,...) at vfs_mountroot+0x40e
start_init(0,c3258d38,c0b8987e,322,c34c1d0c,...) at start_init+0x6f
fork_exit(c07984e0,0,c3258d38) at fork_exit+0xb8
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xc3258d70, ebp = 0 ---

lock order reversal: (sleepable after non-sleepable)
 1st 0xc3766aec vnode interlock (vnode interlock) @ /vol/share/src/sys/ufs/ufs/ufs_dirhash.c:167
 2nd 0xc383d400 dirhash (dirhash) @ /vol/share/src/sys/ufs/ufs/ufs_dirhash.c:178
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c33ac7c4,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26
kdb_backtrace(4,c0b8bf99,c0e07120,c3476660,c33ac81c,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c383d400,c0bb1011,c3476660,c0bb0ca4,...) at _witness_debugger+0x25
witness_checkorder(c383d400,1,c0bb0ca4,b2,c33ac840,...) at witness_checkorder+0x7c9
__lockmgr_args(c383d400,200100,c3766aec,0,0,...) at __lockmgr_args+0x230
ufsdirhash_build(c38a3d90,c00,0,c3755230,c0b98a05,...) at ufsdirhash_build+0x1d8
ufs_lookup(c33ac9f8,c3766a78,c33acbb0,c3766a78,c33aca18,...) at ufs_lookup+0xf0
VOP_CACHEDLOOKUP_APV(c0c842a0,c33ac9f8,c33acbb0,c33acb9c,c348c300,...) at VOP_CACHEDLOOKUP_APV+0xa5
vfs_cache_lookup(c33aca78,c33aca78,c33acb84,80000,c3766a78,...) at vfs_cache_lookup+0xd0
VOP_LOOKUP_APV(c0c842a0,c33aca78,c0b99142,1b0,c33acb9c,...) at VOP_LOOKUP_APV+0xa5
lookup(c33acb84,c0b99142,d8,c0,c38b002c,...) at lookup+0x57e
namei(c33acb84,38f,3,0,c33acc4b,...) at namei+0x44b
kern_statat(c3755230,200,ffffff9c,80c5707,0,...) at kern_statat+0x64
kern_lstat(c3755230,80c5707,0,c33acc18,c37552d4,...) at kern_lstat+0x36
lstat(c3755230,c33accf8,8,c33acd38,c0c62970,...) at lstat+0x2f
syscall(c33acd38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (190, FreeBSD ELF32, lstat), eip = 0x808a4bb, esp = 0xbfbfe42c, ebp = 0xbfbfe4b8 ---

lock order reversal:
 1st 0xc39a13c4 user map (user map) @ /vol/share/src/sys/vm/vm_map.c:2208
 2nd 0xc3ae76a0 ufs (ufs) @ /vol/share/src/sys/vm/vm_object.c:1050
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,c33c8a3c,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26
kdb_backtrace(4,c0b8bf99,c0e07120,c34765f8,c33c8a94,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c3ae76a0,c0b873de,c34765f8,c0bb34f3,...) at _witness_debugger+0x25
witness_checkorder(c3ae76a0,9,c0bb34f3,41a,4,...) at witness_checkorder+0x7c9
__lockmgr_args(c3ae76a0,80400,c3ae76bc,0,0,...) at __lockmgr_args+0x790
ffs_lock(c33c8ba0,0,9f,80400,c3ae7648,...) at ffs_lock+0x8a
VOP_LOCK1_APV(c0c84460,c33c8ba0,c0c9c380,c3ae7648,80400,...) at VOP_LOCK1_APV+0xa5
_vn_lock(c3ae7648,80400,c0bb34f3,41a,28191000,...) at _vn_lock+0x5e
vm_object_sync(c3b015d0,0,0,10000000,1,...) at vm_object_sync+0x186
vm_map_sync(c39a1380,28191000,28191000,1,0,...) at vm_map_sync+0x281
msync(c38c68c0,c33c8cf8,c,c33c8d38,c0c61db8,...) at msync+0x6c
syscall(c33c8d38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (65, FreeBSD ELF32, msync), eip = 0x280cda4b, esp = 0xbfbfe6dc, ebp = 0xbfbfe6f8 ---

lock order reversal: (sleepable after non-sleepable)
 1st 0xc0e3f8c4 Softdep Lock (Softdep Lock) @ /vol/share/src/sys/ufs/ffs/ffs_softdep.c:5470
 2nd 0xc31db940 bufwait (bufwait) @ /vol/share/src/sys/ufs/ffs/ffs_softdep.c:6123
KDB: stack backtrace:
db_trace_self_wrapper(c0b906e9,d6462990,c08101f5,4,c0b8bf99,...) at db_trace_self_wrapper+0x26
kdb_backtrace(4,c0b8bf99,c0e063b8,c34737a8,d64629e8,...) at kdb_backtrace+0x29
_witness_debugger(c0b92fe5,c31db940,c0b98339,c34737a8,c0baf14f,...) at _witness_debugger+0x25
witness_checkorder(c31db940,9,c0baf14f,17eb,c3513000,...) at witness_checkorder+0x7c9
__lockmgr_args(c31db940,80900,c0e3f8c4,0,0,...) at __lockmgr_args+0x790
getdirtybuf(c0e3f8c4,4,c0baf14f,1582,d6462b0c,...) at getdirtybuf+0xc3
flush_deplist(d6462b10,0,c0baf14f,155e,64eb,...) at flush_deplist+0x59
flush_inodedep_deps(c0e3f8c4,0,c0baf14f,145f,d6462b50,...) at flush_inodedep_deps+0xbc
softdep_sync_metadata(c4aa0430,0,c0bb0987,131,0,...) at softdep_sync_metadata+0x55
ffs_syncvnode(c4aa0430,1,d6462c5c,d6462c38,c0ae82a5,...) at ffs_syncvnode+0x3e2
ffs_fsync(d6462c5c,d6462cf8,0,d6462c5c,d6462c80,...) at ffs_fsync+0x1c
VOP_FSYNC_APV(c0c84460,d6462c5c,c0b9aaf4,d90,0,...) at VOP_FSYNC_APV+0xa5
fsync(c3bb2af0,d6462cf8,4,c0b71985,c0c62088,...) at fsync+0x1ae
syscall(d6462d38) at syscall+0x2a3
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (95, FreeBSD ELF32, fsync), eip = 0x283c7807, esp = 0xbfbfae3c, ebp = 0xbfbfc7d8 ---

-- 
- Alfred Perlstein