lock order reversal in 10-alpha2

Shane Ambler FreeBSD at ShaneWare.Biz
Fri Sep 27 03:57:50 UTC 2013


After booting from a 10-alpha2 disk I am seeing "lock order reversal" 
messages show up from time to time. Current logs have 35 entries.

The machine normally is running 9.1 from zfs root and I have setup a 
separate disk (eSATA case connected through backplane port to onboard 
SATA port) that I have installed 10-alpha amd64 onto a ufs partition to 
test port building with. I started by building 10 alpha1 and installing 
onto the new disk. I have since done svn up (last revision is 255868) 
then rebuilt and installed kernel and world while running 10 and still 
see these messages.

I mentioned the existing 9.1 on zfs which I am not importing while 
running 10 from ufs as I noticed zfs mentioned in one of the entries.

Initially I built with an empty src.conf but the last build I used the 
following -

WITH_BSD_GREP=yes
WITH_CLANG_EXTRAS=yes
WITH_CTF=yes
WITHOUT_LIB32=yes
WITH_LLDB=yes

Hardware is ASUS P8H61-M LE/USB3 corei5 8GB RAM nvidia GT520

I can provide full copy of log/messages or dmesg if required.

A few samples --

messages:Sep 26 02:01:27 leader kernel: lock order reversal:
messages-Sep 26 02:01:27 leader kernel: 1st 0xfffffe01eebd07f8 bufwait 
(bufwait) @ /usr/src/sys/kern/vfs_bio.c:3059
messages-Sep 26 02:01:27 leader kernel: 2nd 0xfffff800122f8200 dirhash 
(dirhash) @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:284
messages-Sep 26 02:01:27 leader kernel: KDB: stack backtrace:
messages-Sep 26 02:01:27 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe0238a8f270
messages-Sep 26 02:01:27 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe0238a8f320
messages-Sep 26 02:01:27 leader kernel: witness_checkorder() at 
witness_checkorder+0xd23/frame 0xfffffe0238a8f3b0
messages-Sep 26 02:01:27 leader kernel: _sx_xlock() at 
_sx_xlock+0x75/frame 0xfffffe0238a8f3f0
messages-Sep 26 02:01:27 leader kernel: ufsdirhash_add() at 
ufsdirhash_add+0x3b/frame 0xfffffe0238a8f430
messages-Sep 26 02:01:27 leader kernel: ufs_direnter() at 
ufs_direnter+0x688/frame 0xfffffe0238a8f4f0
messages-Sep 26 02:01:27 leader kernel: ufs_makeinode() at 
ufs_makeinode+0x573/frame 0xfffffe0238a8f6b0
messages-Sep 26 02:01:27 leader kernel: VOP_CREATE_APV() at 
VOP_CREATE_APV+0xea/frame 0xfffffe0238a8f6e0
messages-Sep 26 02:01:27 leader kernel: vn_open_cred() at 
vn_open_cred+0x300/frame 0xfffffe0238a8f830
messages-Sep 26 02:01:27 leader kernel: kern_openat() at 
kern_openat+0x261/frame 0xfffffe0238a8f9a0
messages-Sep 26 02:01:27 leader kernel: amd64_syscall() at 
amd64_syscall+0x265/frame 0xfffffe0238a8fab0
messages-Sep 26 02:01:27 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe0238a8fab0
messages-Sep 26 02:01:27 leader kernel: --- syscall (5, FreeBSD ELF64, 
sys_open), rip = 0x80185baca, rsp = 0x7fffffffd168, rbp = 0x7fffffffd1a0 ---

messages.0:Sep 23 10:08:11 leader kernel: lock order reversal:
messages.0-Sep 23 10:08:11 leader kernel: 1st 0xfffff801ba2e65f0 ufs 
(ufs) @ /usr/src/sys/kern/vfs_syscalls.c:3435
messages.0-Sep 23 10:08:11 leader kernel: 2nd 0xfffffe01ef93c1c0 bufwait 
(bufwait) @ /usr/src/sys/ufs/ffs/ffs_vnops.c:262
messages.0-Sep 23 10:08:11 leader kernel: 3rd 0xfffff801ba2e6240 ufs 
(ufs) @ /usr/src/sys/kern/vfs_subr.c:2099
messages.0-Sep 23 10:08:11 leader kernel: KDB: stack backtrace:
messages.0-Sep 23 10:08:11 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe02397c2300
messages.0-Sep 23 10:08:11 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe02397c23b0
messages.0-Sep 23 10:08:11 leader kernel: witness_checkorder() at 
witness_checkorder+0xd23/frame 0xfffffe02397c2440
messages.0-Sep 23 10:08:11 leader kernel: __lockmgr_args() at 
__lockmgr_args+0x6f2/frame 0xfffffe02397c2570
messages.0-Sep 23 10:08:11 leader kernel: ffs_lock() at 
ffs_lock+0x84/frame 0xfffffe02397c25c0
messages.0-Sep 23 10:08:11 leader kernel: VOP_LOCK1_APV() at 
VOP_LOCK1_APV+0xf5/frame 0xfffffe02397c25f0
messages.0-Sep 23 10:08:11 leader kernel: _vn_lock() at 
_vn_lock+0xab/frame 0xfffffe02397c2660
messages.0-Sep 23 10:08:11 leader kernel: vget() at vget+0x70/frame 
0xfffffe02397c26b0
messages.0-Sep 23 10:08:11 leader kernel: vfs_hash_get() at 
vfs_hash_get+0xf5/frame 0xfffffe02397c2700
messages.0-Sep 23 10:08:11 leader kernel: ffs_vgetf() at 
ffs_vgetf+0x41/frame 0xfffffe02397c2790
messages.0-Sep 23 10:08:11 leader kernel: softdep_sync_buf() at 
softdep_sync_buf+0x8fa/frame 0xfffffe02397c2840
messages.0-Sep 23 10:08:11 leader kernel: ffs_syncvnode() at 
ffs_syncvnode+0x258/frame 0xfffffe02397c28c0
messages.0-Sep 23 10:08:11 leader kernel: ffs_fsync() at 
ffs_fsync+0x20/frame 0xfffffe02397c28f0
messages.0-Sep 23 10:08:11 leader kernel: VOP_FSYNC_APV() at 
VOP_FSYNC_APV+0xf0/frame 0xfffffe02397c2920
messages.0-Sep 23 10:08:11 leader kernel: sys_fsync() at 
sys_fsync+0x156/frame 0xfffffe02397c29a0
messages.0-Sep 23 10:08:11 leader kernel: amd64_syscall() at 
amd64_syscall+0x265/frame 0xfffffe02397c2ab0
messages.0-Sep 23 10:08:11 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe02397c2ab0
messages.0-Sep 23 10:08:11 leader kernel: --- syscall (95, FreeBSD 
ELF64, sys_fsync), rip = 0x8029a41fa, rsp = 0x7fffffffcf28, rbp = 
0x7fffffffcf40 ---

messages.0:Sep 23 10:08:11 leader kernel: lock order reversal:
messages.0-Sep 23 10:08:11 leader kernel: 1st 0xfffff801ba2e65f0 ufs 
(ufs) @ /usr/src/sys/kern/vfs_syscalls.c:3435
messages.0-Sep 23 10:08:11 leader kernel: 2nd 0xfffffe01ef93c1c0 bufwait 
(bufwait) @ /usr/src/sys/ufs/ffs/ffs_vnops.c:262
messages.0-Sep 23 10:08:11 leader kernel: 3rd 0xfffff801ba2e6240 ufs 
(ufs) @ /usr/src/sys/kern/vfs_subr.c:2099
messages.0-Sep 23 10:08:11 leader kernel: KDB: stack backtrace:
messages.0-Sep 23 10:08:11 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe02397c2300
messages.0-Sep 23 10:08:11 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe02397c23b0
messages.0-Sep 23 10:08:11 leader kernel: witness_checkorder() at 
witness_checkorder+0xd23/frame 0xfffffe02397c2440
messages.0-Sep 23 10:08:11 leader kernel: __lockmgr_args() at 
__lockmgr_args+0x6f2/frame 0xfffffe02397c2570
messages.0-Sep 23 10:08:11 leader kernel: ffs_lock() at 
ffs_lock+0x84/frame 0xfffffe02397c25c0
messages.0-Sep 23 10:08:11 leader kernel: VOP_LOCK1_APV() at 
VOP_LOCK1_APV+0xf5/frame 0xfffffe02397c25f0
messages.0-Sep 23 10:08:11 leader kernel: _vn_lock() at 
_vn_lock+0xab/frame 0xfffffe02397c2660
messages.0-Sep 23 10:08:11 leader kernel: vget() at vget+0x70/frame 
0xfffffe02397c26b0
messages.0-Sep 23 10:08:11 leader kernel: vfs_hash_get() at 
vfs_hash_get+0xf5/frame 0xfffffe02397c2700
messages.0-Sep 23 10:08:11 leader kernel: ffs_vgetf() at 
ffs_vgetf+0x41/frame 0xfffffe02397c2790
messages.0-Sep 23 10:08:11 leader kernel: softdep_sync_buf() at 
softdep_sync_buf+0x8fa/frame 0xfffffe02397c2840
messages.0-Sep 23 10:08:11 leader kernel: ffs_syncvnode() at 
ffs_syncvnode+0x258/frame 0xfffffe02397c28c0
messages.0-Sep 23 10:08:11 leader kernel: ffs_fsync() at 
ffs_fsync+0x20/frame 0xfffffe02397c28f0
messages.0-Sep 23 10:08:11 leader kernel: VOP_FSYNC_APV() at 
VOP_FSYNC_APV+0xf0/frame 0xfffffe02397c2920
messages.0-Sep 23 10:08:11 leader kernel: sys_fsync() at 
sys_fsync+0x156/frame 0xfffffe02397c29a0
messages.0-Sep 23 10:08:11 leader kernel: amd64_syscall() at 
amd64_syscall+0x265/frame 0xfffffe02397c2ab0
messages.0-Sep 23 10:08:11 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe02397c2ab0
messages.0-Sep 23 10:08:11 leader kernel: --- syscall (95, FreeBSD 
ELF64, sys_fsync), rip = 0x8029a41fa, rsp = 0x7fffffffcf28, rbp = 
0x7fffffffcf40 ---

messages.0:Sep 23 10:36:02 leader kernel: lock order reversal:
messages.0-Sep 23 10:36:02 leader kernel: 1st 0xfffff801ba9be240 zfs 
(zfs) @ /usr/src/sys/kern/vfs_mount.c:1237
messages.0-Sep 23 10:36:02 leader kernel: 2nd 0xfffff801babab7c8 syncer 
(syncer) @ /usr/src/sys/kern/vfs_subr.c:2210
messages.0-Sep 23 10:36:02 leader kernel: KDB: stack backtrace:
messages.0-Sep 23 10:36:02 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe02397ef460
messages.0-Sep 23 10:36:02 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe02397ef510
messages.0-Sep 23 10:36:02 leader kernel: witness_checkorder() at 
witness_checkorder+0xd23/frame 0xfffffe02397ef5a0
messages.0-Sep 23 10:36:02 leader kernel: __lockmgr_args() at 
__lockmgr_args+0x6f2/frame 0xfffffe02397ef6d0
messages.0-Sep 23 10:36:02 leader kernel: vop_stdlock() at 
vop_stdlock+0x3c/frame 0xfffffe02397ef6f0
messages.0-Sep 23 10:36:02 leader kernel: VOP_LOCK1_APV() at 
VOP_LOCK1_APV+0xf5/frame 0xfffffe02397ef720
messages.0-Sep 23 10:36:02 leader kernel: _vn_lock() at 
_vn_lock+0xab/frame 0xfffffe02397ef790
messages.0-Sep 23 10:36:02 leader kernel: vputx() at vputx+0x208/frame 
0xfffffe02397ef7f0
messages.0-Sep 23 10:36:02 leader kernel: dounmount() at 
dounmount+0x327/frame 0xfffffe02397ef870
messages.0-Sep 23 10:36:02 leader kernel: sys_unmount() at 
sys_unmount+0x356/frame 0xfffffe02397ef9a0
messages.0-Sep 23 10:36:02 leader kernel: amd64_syscall() at 
amd64_syscall+0x265/frame 0xfffffe02397efab0
messages.0-Sep 23 10:36:02 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe02397efab0
messages.0-Sep 23 10:36:02 leader kernel: --- syscall (22, FreeBSD 
ELF64, sys_unmount), rip = 0x80191f24a, rsp = 0x7fffffffc3d8, rbp = 
0x7fffffffc860 ---


More information about the freebsd-stable mailing list