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

2008/1/25, Yar Tikhiy <yar_at_comp.chem.msu.su>:
> On Thu, Jan 24, 2008 at 04:07:43PM +0100, Attilio Rao wrote:
> > 2008/1/24, Yar Tikhiy <yar_at_comp.chem.msu.su>:
> > > On Thu, Jan 24, 2008 at 02:18:56PM +0100, Attilio Rao wrote:
> > > > 2008/1/24, Yar Tikhiy <yar_at_freebsd.org>:
> > > > > On Tue, Jan 15, 2008 at 04:39:24PM +0200, Kostik Belousov wrote:
> > > > > >
> > > > > > 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 think I'm seeing the same panic on UFS.  It's rather nasty: I
> > > > > cannot rebuild CURRENT natively due to it so I have to build it
> > > > > under 6-STABLE.  My favourite way to trigger the panic reliably is
> > > > > running `make install' in a simple port directory, e.g., portmaster,
> > > > > but my system also panics during daily scripts run and, as already
> > > > > said, if trying to build world.
> > > >
> > > > Yar,
> > > > as it seems reproducible for you, can you please add this patch to the tree:
> > > > http://www.freebsd.org/~attilio/debug_tdlocks.diff
> > > >
> > > > compile your kernel with:
> > > > options KTR
> > > > options KTR_COMPILE=(KTR_SPARE2)
> > > > options KTR_MASK=(KTR_SPARE2)
> > > > options KTR_ENTRIES=32768
> > > >
> > > > and once kernel panics, at ddb prompts do:
> > > > > show ktr
> > >
> > > Thank you for your instant response!
> > >
> > > The patched kernel is already being built, but I've got the following
> > > question in the meanwhile: Should I have updated my kernel to get your
> > > latest changes to kern_lock.c?  Now my local copy of kern_lock.c is at
> > > rev. 1.119, i.e., 1 revision behind today's change.
> >
> > As long as this patch still applies, it should not any meaningful difference.
> >
> > Thanks a lot for your effort of testing and reporting bugs!
>
> I don't deserve these kind words because I disinformed you seriously.
>
> My panic appears to be related not to UFS, but to NTFS.  Namely I
> have an NTFS volume mounted read-only at /ntfs.  I have no idea why
> the ports framework touches the /ntfs sub-tree, but not mounting
> it in the first place makes the panic go away.  (I still wonder why
> my system would also panic during buildworld, which should not touch
> my /ntfs at all...  Now I'll try to do a buildworld w/o /ntfs mounted.)

Well, this is still to be fixed :)

> At the same time, dismounting the NTFS volume leads to an instant
> panic of a similar kind:
>
>         panic: System call unmount returning with 5 locks held
>
> More debug output is attached.
>
> So at least UFS doesn't seem affected by the panic.  Excuse me for
> my having provided wrong info.
>
> --
> Yar
>
> panic: System call unmount returning with 5 locks held
> cpuid = 0
> KDB: enter: panic
> [thread pid 985 tid 100085 ]
> Stopped at      kdb_enter+0x3a: movl    $0,kdb_why
> db> show lockedvn
> Locked vnodes
> db> sh ktr
> 678 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 677 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 676 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 675 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 674 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 673 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 672 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 671 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 670 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 669 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 668 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 667 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 666 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 665 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 664 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 663 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 662 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 661 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> 660 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of -1 td_locks
> 659 (0xc37dd000:cpu0): _lockmgr: 0xc37dd000 bumping of 1 td_locks
> db> where
> Tracing pid 985 tid 100085 td 0xc37dd000
> kdb_enter(c0b0c893,c0b0c893,c0b3ce37,d639cc8c,0,...) at kdb_enter+0x3a
> panic(c0b3ce37,c0b2b59e,5,c0b2b59e,c0bbef10,...) at panic+0x12c
> syscall(d639cd38) at syscall+0x46e
> Xint0x80_syscall() at Xint0x80_syscall+0x20
> --- syscall (0, FreeBSD ELF32, nosys), eip = 0x280c4bbb, esp = 0xbfbfe59c, ebp = 0xbfbfe658 ---

Do you see any call to lockmgr_disown() in this ktr trace?
Can you past relevant lines of it, otherwise?

Thanks,
Attilio


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