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) @=20 /usr/src/sys/kern/vfs_bio.c:2559 2nd 0xffffff000498b000 dirhash (dirhash) @=20 /usr/src/sys/ufs/ufs/ufs_dirhash.c:2 85 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a =3D=20 db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c =3D _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af =3D witness_checkorder+0x66f _sx_xlock() at 0xffffffff8056b6d4 =3D _sx_xlock+0x34 ufsdirhash_acquire() at 0xffffffff8076f833 =3D ufsdirhash_acquire+0x33 ufsdirhash_add() at 0xffffffff8076fd99 =3D ufsdirhash_add+0x19 ufs_direnter() at 0xffffffff80772498 =3D ufs_direnter+0x848 ufs_mkdir() at 0xffffffff807783d6 =3D ufs_mkdir+0x5e6 VOP_MKDIR_APV() at 0xffffffff808650d4 =3D VOP_MKDIR_APV+0x34 kern_mkdirat() at 0xffffffff805eb740 =3D kern_mkdirat+0x270 syscall() at 0xffffffff8081ec5e =3D syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 =3D Xfast_syscall+0xe1 --- syscall (136, FreeBSD ELF64, mkdir), rip =3D 0x80072c53c, rsp =3D=20 0x7fffffffec88 , rbp =3D 0x7fffffffef66 --- KDB: enter: witness_checkorder [thread pid 1255 tid 100076 ] Stopped at 0xffffffff8059083d =3D kdb_enter+0x3d: movq =20 $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) @=20 /usr/src/sys/kern/vfs_subr.c:2083 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a =3D=20 db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c =3D _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af =3D witness_checkorder+0x66f __lockmgr_args() at 0xffffffff80552054 =3D __lockmgr_args+0xd04 vop_stdlock() at 0xffffffff805d9239 =3D vop_stdlock+0x39 VOP_LOCK1_APV() at 0xffffffff80864f56 =3D VOP_LOCK1_APV+0x46 _vn_lock() at 0xffffffff805f3cc7 =3D _vn_lock+0x47 vget() at 0xffffffff805e8856 =3D vget+0x56 devfs_allocv() at 0xffffffff804fa993 =3D devfs_allocv+0x103 devfs_root() at 0xffffffff804f9268 =3D devfs_root+0x48 dounmount() at 0xffffffff805e3369 =3D dounmount+0x419 vfs_unmountall() at 0xffffffff805e82a2 =3D vfs_unmountall+0x42 boot() at 0xffffffff80564bd3 =3D boot+0x683 reboot() at 0xffffffff80564ef8 =3D reboot+0x68 syscall() at 0xffffffff8081ec5e =3D syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 =3D Xfast_syscall+0xe1 --- syscall (55, FreeBSD ELF64, reboot), rip =3D 0x80078f83c, rsp =3D=20 0x7fffffffece8 , rbp =3D 0 --- KDB: enter: witness_checkorder [thread pid 35 tid 100073 ] Stopped at 0xffffffff8059083d =3D kdb_enter+0x3d: movq =20 $0,0x6508a0(%rip ) db> lock order reversal: 1st 0xffffff0004831da8 vnode interlock (vnode interlock) @=20 /usr/src/sys/fs/devf s/devfs_vnops.c:349 2nd 0xffffff8000248858 firewire (firewire) @=20 /usr/src/sys/dev/firewire/fwohci.c :2227 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff801dab0a =3D=20 db_trace_self_wrapper+0x2a _witness_debugger() at 0xffffffff805a144c =3D _witness_debugger+0x2c witness_checkorder() at 0xffffffff805a24af =3D witness_checkorder+0x66f _mtx_lock_flags() at 0xffffffff80557b52 =3D _mtx_lock_flags+0x32 fwohci_poll() at 0xffffffff8035feb1 =3D fwohci_poll+0x31 dcons_cngetc() at 0xffffffff80303d69 =3D dcons_cngetc+0x59 cncheckc() at 0xffffffff8052d425 =3D cncheckc+0x65 cngetc() at 0xffffffff8052d44c =3D cngetc+0x1c db_readline() at 0xffffffff801d9ef7 =3D db_readline+0x77 db_read_line() at 0xffffffff801da975 =3D db_read_line+0x15 db_command_loop() at 0xffffffff801d8ad8 =3D db_command_loop+0x38 db_trap() at 0xffffffff801daa49 =3D db_trap+0x89 kdb_trap() at 0xffffffff80590665 =3D kdb_trap+0x95 trap() at 0xffffffff8081f200 =3D trap+0x170 calltrap() at 0xffffffff808067d3 =3D calltrap+0x8 --- trap 0x3, rip =3D 0xffffffff8059083d, rsp =3D 0xffffff80405d9710, rbp= =3D=20 0xffffff 80405d9730 --- kdb_enter() at 0xffffffff8059083d =3D kdb_enter+0x3d witness_checkorder() at 0xffffffff805a24af =3D witness_checkorder+0x66f __lockmgr_args() at 0xffffffff80552054 =3D __lockmgr_args+0xd04 vop_stdlock() at 0xffffffff805d9239 =3D vop_stdlock+0x39 VOP_LOCK1_APV() at 0xffffffff80864f56 =3D VOP_LOCK1_APV+0x46 _vn_lock() at 0xffffffff805f3cc7 =3D _vn_lock+0x47 vget() at 0xffffffff805e8856 =3D vget+0x56 devfs_allocv() at 0xffffffff804fa993 =3D devfs_allocv+0x103 devfs_root() at 0xffffffff804f9268 =3D devfs_root+0x48 dounmount() at 0xffffffff805e3369 =3D dounmount+0x419 vfs_unmountall() at 0xffffffff805e82a2 =3D vfs_unmountall+0x42 boot() at 0xffffffff80564bd3 =3D boot+0x683 reboot() at 0xffffffff80564ef8 =3D reboot+0x68 syscall() at 0xffffffff8081ec5e =3D syscall+0x19e Xfast_syscall() at 0xffffffff80806ab1 =3D Xfast_syscall+0xe1 --- syscall (55, FreeBSD ELF64, reboot), rip =3D 0x80078f83c, rsp =3D=20 0x7fffffffece8 , rbp =3D 0 ---
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?8CD953BFE2324E5-1B10-A8CE>