Date: Fri, 05 Feb 2010 12:49:59 +0100 From: Harald Schmalzbauer <h.schmalzbauer@omnilan.de> To: freebsd-stable <freebsd-stable@freebsd.org> Subject: Re: Reboot Loop: ffs_snapshot/bufwait LORs [Was: Re: 8.0-RELEASE hangs with lighttpd, unionfs related? Some traces included] Message-ID: <4B6C05E7.2040503@omnilan.de> In-Reply-To: <4B6C038A.9020500@omnilan.de> References: <4B6C01AB.5030500@omnilan.de> <4B6C038A.9020500@omnilan.de>
next in thread | previous in thread | raw e-mail | index | archive | help
This is an OpenPGP/MIME signed message (RFC 2440 and 3156) --------------enig6F2DD4F11A48E75DF85E15AF Content-Type: text/plain; charset=ISO-8859-15; format=flowed Content-Transfer-Encoding: quoted-printable Harald Schmalzbauer schrieb am 05.02.2010 12:39 (localtime): > Harald Schmalzbauer schrieb am 05.02.2010 12:31 (localtime): =2E.. >=20 > Additional LORs while regular machine operation (background fsck) which= =20 > leads to reboot! > I have access over the serail console, but the machine is unresponsive = > after that. So I'm now in a endelss reboot loop with the debug kernel..= =2E >=20 > lock order reversal: > 1st 0xffffff0001b899d0 ufs (ufs) @ /usr/src/sys/ufs/ffs/ffs_snapshot.c= :423 > 2nd 0xffffff802970fc28 bufwait (bufwait) @=20 > /usr/src/sys/kern/vfs_bio.c:2559 > 3rd 0xffffff00018b4448 ufs (ufs) @ /usr/src/sys/ufs/ffs/ffs_snapshot.c= :544 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > _witness_debugger() at _witness_debugger+0x49 > witness_checkorder() at witness_checkorder+0x7ea > __lockmgr_args() at __lockmgr_args+0xcbd > ffs_lock() at ffs_lock+0x8c > VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b > _vn_lock() at _vn_lock+0x50 > ffs_snapshot() at ffs_snapshot+0x1b70 > ffs_mount() at ffs_mount+0x651 > vfs_donmount() at vfs_donmount+0xcd4 > nmount() at nmount+0x74 > syscall() at syscall+0x1af > Xfast_syscall() at Xfast_syscall+0xe1 > --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D = > 0x7fffffffe988, rbp =3D 0x800a028e- > KDB: enter: witness_checkorder > [thread pid 947 tid 100073 ] > Stopped at kdb_enter+0x3d: movq $0,0x4c04dc(%rip) > db> lock order reversal: > 1st 0xffffff00018b4470 vnode interlock (vnode interlock) @=20 > /usr/src/sys/ufs/ffs/ffs_snapshot.c:523 > 2nd 0xffffff8000422028 uhci2 (uhci2) @=20 > /usr/src/sys/dev/usb/controller/uhci.c:1551 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > _witness_debugger() at _witness_debugger+0x49 > witness_checkorder() at witness_checkorder+0x7ea > _mtx_lock_flags() at _mtx_lock_flags+0x68 > uhci_do_poll() at uhci_do_poll+0x2e > usbd_transfer_poll() at usbd_transfer_poll+0x18d > ukbd_do_poll() at ukbd_do_poll+0x63 > ukbd_get_key() at ukbd_get_key+0xa8 > ukbd_read_char() at ukbd_read_char+0xaa > scgetc() at scgetc+0x5b > sc_cngetc() at sc_cngetc+0xf2 > cncheckc() at cncheckc+0x65 > cngetc() at cngetc+0x1c > db_readline() at db_readline+0x79 > db_read_line() at db_read_line+0x15 > db_command_loop() at db_command_loop+0x38 > db_trap() at db_trap+0x87 > kdb_trap() at kdb_trap+0x82 > trap() at trap+0x18f > calltrap() at calltrap+0x8 > --- trap 0x3, rip =3D 0xffffffff80381141, rsp =3D 0xffffff803e959000, r= bp =3D=20 > 0xffffff803e959020 --- > kdb_enter() at kdb_enter+0x3d > witness_checkorder() at witness_checkorder+0x7ea > __lockmgr_args() at __lockmgr_args+0xcbd > ffs_lock() at ffs_lock+0x8c > VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b > _vn_lock() at _vn_lock+0x50 > ffs_snapshot() at ffs_snapshot+0x1b70 > ffs_mount() at ffs_mount+0x651 > vfs_donmount() at vfs_donmount+0xcd4 > nmount() at nmount+0x74 > syscall() at syscall+0x1af > Xfast_syscall() at Xfast_syscall+0xe1 > --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D = > 0x7fffffffe988, rbp =3D 0x800a028e- > lock order reversal: > 1st 0xffffff00018b4470 vnode interlock (vnode interlock) @=20 > /usr/src/sys/ufs/ffs/ffs_snapshot.c:523 > 2nd 0xffffff0001747890 USB device mutex (USB device mutex) @=20 > /usr/src/sys/dev/usb/usb_device.c:1410 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > _witness_debugger() at _witness_debugger+0x49 > witness_checkorder() at witness_checkorder+0x7ea > _mtx_lock_flags() at _mtx_lock_flags+0x68 > usbd_clear_stall_proc() at usbd_clear_stall_proc+0x49 > usbd_transfer_poll() at usbd_transfer_poll+0x1c0 > ukbd_do_poll() at ukbd_do_poll+0x63 > ukbd_get_key() at ukbd_get_key+0xa8 > ukbd_read_char() at ukbd_read_char+0xaa > scgetc() at scgetc+0x5b > sc_cngetc() at sc_cngetc+0xf2 > cncheckc() at cncheckc+0x65 > cngetc() at cngetc+0x1c > db_readline() at db_readline+0x79 > db_read_line() at db_read_line+0x15 > db_command_loop() at db_command_loop+0x38 > db_trap() at db_trap+0x87 > kdb_trap() at kdb_trap+0x82 > trap() at trap+0x18f > calltrap() at calltrap+0x8 > --- trap 0x3, rip =3D 0xffffffff80381141, rsp =3D 0xffffff803e959000, r= bp =3D=20 > 0xffffff803e959020 --- > kdb_enter() at kdb_enter+0x3d > witness_checkorder() at witness_checkorder+0x7ea > __lockmgr_args() at __lockmgr_args+0xcbd > ffs_lock() at ffs_lock+0x8c > VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b > _vn_lock() at _vn_lock+0x50 > ffs_snapshot() at ffs_snapshot+0x1b70 > ffs_mount() at ffs_mount+0x651 > vfs_donmount() at vfs_donmount+0xcd4 > nmount() at nmount+0x74 > syscall() at syscall+0x1af > Xfast_syscall() at Xfast_syscall+0xe1 > --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D = > 0x7fffffffe988, rbp =3D 0x800a028e- > lock order reversal: (Giant after non-sleepable) > 1st 0xffffff00018b4470 vnode interlock (vnode interlock) @=20 > /usr/src/sys/ufs/ffs/ffs_snapshot.c:523 > 2nd 0xffffffff80820780 Giant (Giant) @=20 > /usr/src/sys/dev/usb/usb_transfer.c:1952 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > _witness_debugger() at _witness_debugger+0x49 > witness_checkorder() at witness_checkorder+0x7ea > _mtx_lock_flags() at _mtx_lock_flags+0x68 > usb_callback_proc() at usb_callback_proc+0x48 > usbd_transfer_poll() at usbd_transfer_poll+0x1e9 > ukbd_do_poll() at ukbd_do_poll+0x63 > ukbd_get_key() at ukbd_get_key+0xa8 > ukbd_read_char() at ukbd_read_char+0xaa > scgetc() at scgetc+0x5b > sc_cngetc() at sc_cngetc+0xf2 > cncheckc() at cncheckc+0x65 > cngetc() at cngetc+0x1c > db_readline() at db_readline+0x79 > db_read_line() at db_read_line+0x15 > db_command_loop() at db_command_loop+0x38 > db_trap() at db_trap+0x87 > kdb_trap() at kdb_trap+0x82 > trap() at trap+0x18f > calltrap() at calltrap+0x8 > --- trap 0x3, rip =3D 0xffffffff80381141, rsp =3D 0xffffff803e959000, r= bp =3D=20 > 0xffffff803e959020 --- > kdb_enter() at kdb_enter+0x3d > witness_checkorder() at witness_checkorder+0x7ea > __lockmgr_args() at __lockmgr_args+0xcbd > ffs_lock() at ffs_lock+0x8c > VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b > _vn_lock() at _vn_lock+0x50 > ffs_snapshot() at ffs_snapshot+0x1b70 > ffs_mount() at ffs_mount+0x651 > vfs_donmount() at vfs_donmount+0xcd4 > nmount() at nmount+0x74 > syscall() at syscall+0x1af > Xfast_syscall() at Xfast_syscall+0xe1 > --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D = > 0x7fffffffe988, rbp =3D 0x800a028e- >=20 > lock order reversal: > 1st 0xffffff802970fc28 bufwait (bufwait) @=20 > /usr/src/sys/kern/vfs_bio.c:2559 > 2nd 0xffffff00440ef6b0 snaplk (snaplk) @=20 > /usr/src/sys/ufs/ffs/ffs_snapshot.c:793 > KDB: stack backtrace: > db_trace_self_wrapper() at db_trace_self_wrapper+0x2a > _witness_debugger() at _witness_debugger+0x49 > witness_checkorder() at witness_checkorder+0x7ea > __lockmgr_args() at __lockmgr_args+0xcbd > ffs_lock() at ffs_lock+0x8c > VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b > _vn_lock() at _vn_lock+0x50 > ffs_snapshot() at ffs_snapshot+0x17d7 > ffs_mount() at ffs_mount+0x651 > vfs_donmount() at vfs_donmount+0xcd4 > nmount() at nmount+0x74 > syscall() at syscall+0x1af > Xfast_syscall() at Xfast_syscall+0xe1 > --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D = > 0x7fffffffe988, rbp =3D 0x800a028e- > KDB: enter: witness_checkorder > [thread pid 947 tid 100073 ] > Stopped at kdb_enter+0x3d: movq $0,0x4c04dc(%rip) Sorry, it was my watchdog who restarted the machine. Here's the trace I coudl get: Tracing pid 918 tid 100072 td 0xffffff0001816390 kdb_enter() at kdb_enter+0x3d witness_checkorder() at witness_checkorder+0x7ea __lockmgr_args() at __lockmgr_args+0xcbd ffs_lock() at ffs_lock+0x8c VOP_LOCK1_APV() at VOP_LOCK1_APV+0x9b _vn_lock() at _vn_lock+0x50 ffs_snapshot() at ffs_snapshot+0x1b70 ffs_mount() at ffs_mount+0x651 vfs_donmount() at vfs_donmount+0xcd4 nmount() at nmount+0x74 syscall() at syscall+0x1af Xfast_syscall() at Xfast_syscall+0xe1 --- syscall (378, FreeBSD ELF64, nmount), rip =3D 0x8007acfec, rsp =3D=20 0x7fffffffe988, rbp =3D 0x800a028e- =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D And another LOR after cont: lock order reversal: 1st 0xffffff0001e40d30 snaplk (snaplk) @ /usr/src/sys/kern/vfs_vnops.c:= 296 2nd 0xffffff00018a49d0 ufs (ufs) @=20 /usr/src/sys/ufs/ffs/ffs_snapshot.c:1587 KDB: stack backtrace: db_trace_self_wrapper() at db_trace_self_wrapper+0x2a _witness_debugger() at _witness_debugger+0x49 witness_checkorder() at witness_checkorder+0x7ea __lockmgr_args() at __lockmgr_args+0xcbd ffs_snapremove() at ffs_snapremove+0xe2 softdep_releasefile() at softdep_releasefile+0x133 ufs_inactive() at ufs_inactive+0x185 vinactive() at vinactive+0x6b vput() at vput+0x216 vn_close() at vn_close+0x10b vn_closefile() at vn_closefile+0x51 _fdrop() at _fdrop+0x20 closef() at closef+0x58 kern_close() at kern_close+0xff syscall() at syscall+0x1af Xfast_syscall() at Xfast_syscall+0xe1 --- syscall (6, FreeBSD ELF64, close), rip =3D 0x8008435ec, rsp =3D=20 0x7fffffffe988, rbp =3D 0 --- KDB: enter: witness_checkorder [thread pid 914 tid 100080 ] Stopped at kdb_enter+0x3d: movq $0,0x4c04dc(%rip) db> trace Tracing pid 914 tid 100080 td 0xffffff000186dab0 kdb_enter() at kdb_enter+0x3d witness_checkorder() at witness_checkorder+0x7ea __lockmgr_args() at __lockmgr_args+0xcbd ffs_snapremove() at ffs_snapremove+0xe2 softdep_releasefile() at softdep_releasefile+0x133 ufs_inactive() at ufs_inactive+0x185 vinactive() at vinactive+0x6b vput() at vput+0x216 vn_close() at vn_close+0x10b vn_closefile() at vn_closefile+0x51 _fdrop() at _fdrop+0x20 closef() at closef+0x58 kern_close() at kern_close+0xff syscall() at syscall+0x1af Xfast_syscall() at Xfast_syscall+0xe1 --- syscall (6, FreeBSD ELF64, close), rip =3D 0x8008435ec, rsp =3D=20 0x7fffffffe988, rbp =3D 0 --- Thanks, -Harry --------------enig6F2DD4F11A48E75DF85E15AF Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.13 (FreeBSD) iEYEARECAAYFAktsBegACgkQLDqVQ9VXb8j0awCgo5t02dQXe6B/hitFgF3k2e53 UMAAnjl+Rre9bwrI7VXrWyA0yUWcqXid =5RJL -----END PGP SIGNATURE----- --------------enig6F2DD4F11A48E75DF85E15AF--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?4B6C05E7.2040503>