FW: lock order reversals w/ backtrace

Hans Petter Selasky hans.petter.selasky at bitfrost.no
Sat Jan 25 15:54:20 UTC 2014


FYI - can anyone comment?

--HPS
 
 
-----Original message-----
> From:Thomas Hoffmann <trh411 at gmail.com <mailto:trh411 at gmail.com> >
> Sent: Saturday 25th January 2014 15:55
> To: freebsd-current <freebsd-current at freebsd.org <mailto:freebsd-current at freebsd.org> >
> Cc: Hans Petter Selasky <hans.petter.selasky at bitfrost.no <mailto:hans.petter.selasky at bitfrost.no> >
> Subject: Re: lock order reversals w/ backtrace
> 
> On Fri, Jan 24, 2014 at 11:47 PM, Thomas Hoffmann <trh411 at gmail.com <mailto:trh411 at gmail.com> > wrote:
> 
> > On Fri, Jan 24, 2014 at 9:52 AM, Thomas Hoffmann <trh411 at gmail.com <mailto:trh411 at gmail.com> > wrote:
> >
> >> On Thu, Jan 23, 2014 at 11:49 AM, Hans Petter Selasky <
> >> hans.petter.selasky at bitfrost.no <mailto:hans.petter.selasky at bitfrost.no> > wrote:
> >>
> >>>  Hi,
> >>>
> >>> Can you see if you can snap some keywords of the backtraces, like usb_xxx usbdx_xxx cam scsi or something like that.
> >>>
> >>> Else I believe there are some sysctl options to prevent the final reboot somehow so that you can write down the messages.
> >>>
> >>>
> >>> --HPS
> >>>
> >>>
> >>> -----Original message-----
> >>> > From:Thomas Hoffmann <trh411 at gmail.com <mailto:trh411 at gmail.com> >
> >>> > Sent: Thursday 23rd January 2014 17:15
> >>>
> >>> > To: freebsd-current <freebsd-current at freebsd.org <mailto:freebsd-current at freebsd.org> >
> >>> > Subject: lock order reversals w/ backtrace
> >>> >
> >>> > A few days ago I started running 11.0-CURRENT at r260971 for the first time.
> >>>
> >>>
> >>> >
> >>> > The last couple of times I shutdown my system I noticed 2 or 3 short "lock
> >>> > order reversal" messages with accompanying backtraces scroll by. Do these
> >>> > messages represent a problem that I should report or can I ignore them as
> >>>
> >>>
> >>> > debug in nature? If I should report them, how or where do these messages
> >>> > get logged? I can find no reference to them in syslog or anywhere else upon
> >>> > my subsequent reboot.
> >>> >
> >>> > I also had a couple of these messages pop up the other day while
> >>>
> >>>
> >>> > mounting/umounting USB thumb drives. I did not think anything of them at
> >>> > the time as the mounts/umounts completed successfully.
> >>> >
> >>> > Please advise. Thanks.
> >>> >
> >>> > -Tom
> >>>
> >>>  I managed to snap a photo of my screen during shutdown.
> >> Here is the full text of the first of two lock order reversals I got last
> >> night during system shutdown, both of which are zfs-related to (it
> >> appears?) unmounts. A few lines got chopped as they were out-of-frame when
> >> I took the photo:
> >>
> >> shutting down local daemons:
> >> lock order reversal:
> >>   1st 0xfffff801194f67c8 zfs (zfs) @ /usr/src/sys/kern/vfs_mount.c:1237
> >>   2nd 0xfffff801194f6420 syncer (syncer) @
> >> /usr/src/sys/kern/vfs_subr.c:22[..chopped...]
> >> KDB: stack backtrace:
> >> db_trace_self_wrapper() at db_trace_delf_wrapper+0x2b/frame
> >> 0xfffffe01ac78[...chopped...]
> >> kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe01ac784650
> >> witness_checkorder() at witness_checkorder+0xd23/frame 0xfffffe01ac7846e0
> >> __lockmgr_args() __lockmgr_args+0x878/frame 0xfffffe01ac784810
> >> vop_stdlock() at vop_stdlock+0x3c/frame 0xfffffe01ac784830
> >> VOP_LOCK1_APV() at VOP_LOCK1_APV+0xf5/frame 0xfffffe01ac784860
> >> _vn_lock() at _vn_lock+0xab/frame 0xfffffe01ac7848d0
> >> vputx() at vputx+0x240/frame 0xfffffe01ac784930
> >> dounmount at dounmount+0x327/frame 0xfffffe01ac7849b0
> >> sys_unmount() at sys_unmount+0x356/frame 0xfffffe01ac784ac0
> >> amd64_syscall() at amd64_syscall+0x265/frame 0xfffffe01ac784bf0
> >> Xfast_syscall() at Xfast_syscall+0xfb/frame 0xfffffe01ac784bf0
> >> --- syscall (22, FreeBSD ELF64, sys_unmount, rip = 0x80191c72a,
> >> rsp[...chopped...]
> >>
> >> I have a zpool on an external USB HDD that I export at shutdown via
> >> rc.shutdown.local. Don't know if that is contributing to this or not. When
> >> I get a chance to bring down the system I will manually export it before
> >> shutdown to see if that makes any difference.
> >>
> >
> > Was able to capture the full text of the lock order reversal I've been
> > experiencing at shutdown. Turns out to be associated with the export of one
> > of my zpools that is hosted on an external USB HDD. Normally I export the
> > zpool from rc.shutdown.local, but tonight I exported it manually before I
> > shutdown and got the following.
> >
> > lock order reversal:
> > : 1st 0xfffff8011952b5f0 zfs (zfs) @ /usr/src/sys/kern/vfs_mount.c:1237
> > : 2nd 0xfffff8011952b068 syncer (syncer) @
> > /usr/src/sys/kern/vfs_subr.c:2212
> > KDB: stack backtrace:
> > db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame
> > 0xfffffe01add6e5a0
> > kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe01add6e650
> > witness_checkorder() at witness_checkorder+0xd23/frame 0xfffffe01add6e6e0
> > __lockmgr_args() at __lockmgr_args+0x878/frame 0xfffffe01add6e810
> > vop_stdlock() at vop_stdlock+0x3c/frame 0xfffffe01add6e830
> > VOP_LOCK1_APV() at VOP_LOCK1_APV+0xf5/frame 0xfffffe01add6e860
> > _vn_lock() at _vn_lock+0xab/frame 0xfffffe01add6e8d0
> > vputx() at vputx+0x240/frame 0xfffffe01add6e930
> > dounmount() at dounmount+0x327/frame 0xfffffe01add6e9b0
> > sys_unmount() at sys_unmount+0x356/frame 0xfffffe01add6eae0
> > amd64_syscall() at amd64_syscall+0x265/frame 0xfffffe01add6ebf0
> > Xfast_syscall() at Xfast_syscall+0xfb/frame 0xfffffe01add6ebf0
> > --- syscall (22, FreeBSD ELF64, sys_unmount), rip = 0x80191c72a, rsp =
> > 0x7fffffffc4c8, rbp = 0x7fffffffc960 ---
> >
> > When imported and mounted, the zpool reports no errors and I have not
> > experienced any anomalies reading or writing to the zpool. Should I be
> > concerned?
> >
> > Hmm, seems like I'm the only one interested in this.
> 
> I think I have resolved the problem with the zpool on the external USB HDD.
> I copied off the data, destroyed the datasets and zpool, recreated the
> zpool and datasets and restored the data. I have executed several exports
> on the zpool and have received no "lock order reversal" messages.
> 
> I am still getting lock order reversal messages for my bootpool and zroot
> zpools at shutdown. Recreating bootpool would be relatively easy, but if
> I'm going to recreate zroot, I might as well do a reinistall, am I am not
> prepared to do at this time. So I'm still in search of an alternative way
> to resolve this issue. My zpools all show "no known data errors", scrub
> cleanly, zpool upgrade reports that all zpools support all features, and
> I've not experienced any other issues related to my zpools.
> 
> Based on the above lock order reversal data, the error is in this block of
> code (, specifically /usr/src/sys/kern/vfs_mount.c:1237)
> 
>  if ((coveredvp = mp->mnt_vnodecovered) != NULL) {
>                 mnt_gen_r = mp->mnt_gen;
>                 VI_LOCK(coveredvp);
>                 vholdl(coveredvp);
>                 vn_lock(coveredvp, LK_EXCLUSIVE | LK_INTERLOCK | LK_RETRY);
>    /* LINE 1237 */
>                 vdrop(coveredvp);
>                 /*
>                  * Check for mp being unmounted while waiting for the
>                  * covered vnode lock.
>                  */
>                 if (coveredvp->v_mountedhere != mp ||
>                     coveredvp->v_mountedhere->mnt_gen != mnt_gen_r) {
>                         VOP_UNLOCK(coveredvp, 0);
>                         return (EBUSY);
>                 }
> }
> 
> 
> -Tom
> _______________________________________________
> freebsd-current at freebsd.org <mailto:freebsd-current at freebsd.org>  mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-current <http://lists.freebsd.org/mailman/listinfo/freebsd-current> 
> To unsubscribe, send any mail to "freebsd-current-unsubscribe at freebsd.org <mailto:freebsd-current-unsubscribe at freebsd.org> "
> 



More information about the freebsd-fs mailing list