Date: Mon, 07 Feb 2011 19:12:22 -0500 From: dieterbsd@engineer.com To: freebsd-hackers@freebsd.org Subject: witness Re: Why does printf(9) hang network? Message-ID: <8CD953BFE2324E5-1B10-A8CE@web-mmc-m02.sysops.aol.com>
next in thread | raw e-mail | index | archive | help
I received a suggestion to try witness, so I build a kernel with WITNESS, WITNESS_KDB, KDB, DDB, KDB_TRACE, and DDB_NUMSYM. This is my first attempt to use witness, so if I got something wrong let me know. Didn't quite make it all the way up to a multiuser prompt: Starting syslogd. Starting rpcbind. lock order reversal: 1st 0xffffff8029549320 bufwait (bufwait) @ /usr/src/sys/kern/vfs_bio.c:2559 2nd 0xffffff000498b000 dirhash (dirhash) @ /usr/src/sys/ufs/ufs/ufs_dirhash.c:2 85 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a = db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c = _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af = witness_checkorder+0x66f _sx_xlock() at 0xffffffff8056b6d4 = _sx_xlock+0x34 ufsdirhash_acquire() at 0xffffffff8076f833 = ufsdirhash_acquire+0x33 ufsdirhash_add() at 0xffffffff8076fd99 = ufsdirhash_add+0x19 ufs_direnter() at 0xffffffff80772498 = ufs_direnter+0x848 ufs_mkdir() at 0xffffffff807783d6 = ufs_mkdir+0x5e6 VOP_MKDIR_APV() at 0xffffffff808650d4 = VOP_MKDIR_APV+0x34 kern_mkdirat() at 0xffffffff805eb740 = kern_mkdirat+0x270 syscall() at 0xffffffff8081ec5e = syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 = Xfast_syscall+0xe1 --- syscall (136, FreeBSD ELF64, mkdir), rip = 0x80072c53c, rsp = 0x7fffffffec88 , rbp = 0x7fffffffef66 --- KDB: enter: witness_checkorder [thread pid 1255 tid 100076 ] Stopped at 0xffffffff8059083d = kdb_enter+0x3d: movq $0,0x6508a0(%rip ) db> Managed to reboot to single user mode, changed /boot/kernel back to my production kernel, and got another lock order reversal rebooting: # sync # reboot Waiting (max 60 seconds) for system process `vnlru' to stop...done Waiting (max 60 seconds) for system process `bufdaemon' to stop...done Waiting (max 60 seconds) for system process `syncer' to stop... Syncing disks, vnodes remaining...0 done All buffers synced. lock order reversal: 1st 0xffffff0004831448 ufs (ufs) @ /usr/src/sys/kern/vfs_mount.c:1200 2nd 0xffffff0004831d80 devfs (devfs) @ /usr/src/sys/kern/vfs_subr.c:2083 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a = db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c = _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af = witness_checkorder+0x66f __lockmgr_args() at 0xffffffff80552054 = __lockmgr_args+0xd04 vop_stdlock() at 0xffffffff805d9239 = vop_stdlock+0x39 VOP_LOCK1_APV() at 0xffffffff80864f56 = VOP_LOCK1_APV+0x46 _vn_lock() at 0xffffffff805f3cc7 = _vn_lock+0x47 vget() at 0xffffffff805e8856 = vget+0x56 devfs_allocv() at 0xffffffff804fa993 = devfs_allocv+0x103 devfs_root() at 0xffffffff804f9268 = devfs_root+0x48 dounmount() at 0xffffffff805e3369 = dounmount+0x419 vfs_unmountall() at 0xffffffff805e82a2 = vfs_unmountall+0x42 boot() at 0xffffffff80564bd3 = boot+0x683 reboot() at 0xffffffff80564ef8 = reboot+0x68 syscall() at 0xffffffff8081ec5e = syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 = Xfast_syscall+0xe1 --- syscall (55, FreeBSD ELF64, reboot), rip = 0x80078f83c, rsp = 0x7fffffffece8 , rbp = 0 --- KDB: enter: witness_checkorder [thread pid 35 tid 100073 ] Stopped at 0xffffffff8059083d = kdb_enter+0x3d: movq $0,0x6508a0(%rip ) db> lock order reversal: 1st 0xffffff0004831da8 vnode interlock (vnode interlock) @ /usr/src/sys/fs/devf s/devfs_vnops.c:349 2nd 0xffffff8000248858 firewire (firewire) @ /usr/src/sys/dev/firewire/fwohci.c :2227 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a = db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c = _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af = witness_checkorder+0x66f _mtx_lock_flags() at 0xffffffff80557b52 = _mtx_lock_flags+0x32 fwohci_poll() at 0xffffffff8035feb1 = fwohci_poll+0x31 dcons_cngetc() at 0xffffffff80303d69 = dcons_cngetc+0x59 cncheckc() at 0xffffffff8052d425 = cncheckc+0x65 cngetc() at 0xffffffff8052d44c = cngetc+0x1c db_readline() at 0xffffffff801d9ef7 = db_readline+0x77 db_read_line() at 0xffffffff801da975 = db_read_line+0x15 db_command_loop() at 0xffffffff801d8ad8 = db_command_loop+0x38 db_trap() at 0xffffffff801daa49 = db_trap+0x89 kdb_trap() at 0xffffffff80590665 = kdb_trap+0x95 trap() at 0xffffffff8081f200 = trap+0x170 calltrap() at 0xffffffff808067d3 = calltrap+0x8 --- trap 0x3, rip = 0xffffffff8059083d, rsp = 0xffffff80405d9710, rbp = 0xffffff 80405d9730 --- kdb_enter() at 0xffffffff8059083d = kdb_enter+0x3d witness_checkorder() at 0xffffffff805a24af = witness_checkorder+0x66f __lockmgr_args() at 0xffffffff80552054 = __lockmgr_args+0xd04 vop_stdlock() at 0xffffffff805d9239 = vop_stdlock+0x39 VOP_LOCK1_APV() at 0xffffffff80864f56 = VOP_LOCK1_APV+0x46 _vn_lock() at 0xffffffff805f3cc7 = _vn_lock+0x47 vget() at 0xffffffff805e8856 = vget+0x56 devfs_allocv() at 0xffffffff804fa993 = devfs_allocv+0x103 devfs_root() at 0xffffffff804f9268 = devfs_root+0x48 dounmount() at 0xffffffff805e3369 = dounmount+0x419 vfs_unmountall() at 0xffffffff805e82a2 = vfs_unmountall+0x42 boot() at 0xffffffff80564bd3 = boot+0x683 reboot() at 0xffffffff80564ef8 = reboot+0x68 syscall() at 0xffffffff8081ec5e = syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 = Xfast_syscall+0xe1 --- syscall (55, FreeBSD ELF64, reboot), rip = 0x80078f83c, rsp = 0x7fffffffece8 , rbp = 0 ---
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?8CD953BFE2324E5-1B10-A8CE>