Re: panic: System call lstat returning with 1 locks held

2008/1/17, Scot Hetzel <swhetzel_at_gmail.com>:
> On 1/16/08, Scot Hetzel <swhetzel_at_gmail.com> wrote:
>  > On 1/15/08, Kostik Belousov <kostikbel_at_gmail.com> wrote:
>  > > On Tue, Jan 15, 2008 at 07:52:12AM -0600, Scot Hetzel wrote:
>  > > > When I boot a Jan 13th or Jan 15th kernel, and then run
>  > > > /usr/local/etc/cvsup/update.sh to update the local CVS repository, I
>  > > > get the following panic:
>  > > >
>  > > > panic: System call lstat returning with 1 locks held
>  > > > cpuid = 0
>  > > > KDB: enter: panic
>  > > > [thread ; pid 1240 tid 10031]
>  > > > stopped at kdb_enter+0x3d: movq $0,0x41b048(%rip)
>  > > > db> show alllocks
>  > > > db> show locks
>  > > > db> bt
>  > > > tracing pid 1240 tid 10031 td 0xffffff001c1ad360
>  > > > kdb_enter() at kdb_enter+0x3d
>  > > > panic() at panic+0x176
>  > > > syscalls() at syscalls+0x66d
>  > > > Xfast_syscalls() at Xfast_syscalls+0xab
>  > > > --- syscall (0, FreeBSD ELF64, nosys), rip = 0x8009e87ec, rsp=
>  > > > 0x72ec50, rbp = 0x72ed28 ---
>  > > >
>  > > I think this could be related to the recent vn_lock()/VOP_LOCK() KPI changes.
>  > > Please, add DEBUG_VFS_LOCKS to the kernel config, and do the
>  > >         show lockedvnods
>  > > from the ddb prompt when the panic occurs. The witness does not track
>  > > the lockmgr locks.
>  > >
>  > I added DEBUG_VFS_LOCKS to the kernel config file, rebuilt and
>  > installed the kernel.  After rebooting the system, I started the cvsup
>  > update for my local mirror, when the panic occured I received a
>  > similar panic to the one above.  When I used 'show lockedvnods' the
>  > only thing that was displayed was 'Locked vnodes' and that was it.
>  >
>  > I'm going to try a binary search to see if I can narrow the problem down.
>  >
>  > Scot
>  >
>
> I found the point where the problem occurs.  If I update /usr/src/sys
>  to Jan 08 23:45 UTC 2008, then I don't get the lstat panic.  But when
>  I update to Jan 08 23:49 UTC 2008, the panic returns.
>
>  These are the files that change between these times:
>
>  dev/usb/ehci.c:
>      $FreeBSD: src/sys/dev/usb/ehci.c,v 1.57 2008/01/08 23:48:30 attilio Exp $
>
>  dev/usb/if_udav.c:
>      $FreeBSD: src/sys/dev/usb/if_udav.c,v 1.34 2008/01/08 23:48:30
>  attilio Exp $
>
>  fs/hpfs/hpfs_subr.h:
>      $FreeBSD: src/sys/fs/hpfs/hpfs_subr.h,v 1.4 2008/01/08 23:48:31
>  attilio Exp $
>
>  fs/ntfs/ntfs_subr.c:
>      $FreeBSD: src/sys/fs/ntfs/ntfs_subr.c,v 1.43 2008/01/08 23:48:31
>  attilio Exp $
>
>  kern/kern_lock.c:
>      $FreeBSD: src/sys/kern/kern_lock.c,v 1.117 2008/01/08 23:48:31
>  attilio Exp $
>
>  sys/buf.h:
>      $FreeBSD: src/sys/sys/buf.h,v 1.197 2008/01/08 23:48:31 attilio Exp $
>
>  sys/lockmgr.h:
>      $FreeBSD: src/sys/sys/lockmgr.h,v 1.56 2008/01/08 23:48:31 attilio Exp $

At least now I know why the problem has became visible just after these commits.
This is because before ntfs lockmgr were just working with the kernel
as owner; consequently td_locks could not be bumped and the problem
was hiding.
I think, also, the problem is not linked to vnodes, so having vnodes
debugging should not produce any difference. NTFS uses a lot of
lockmgr for tracking its internal stuffs.
More analysis to come.

Attilio


-- 
Peace can only be achieved by understanding - A. Einstein