freebsd stable - Jul 2003 - Okay, looks like I might have a *good* one here ... inode hang

neptune# ps -M vmcore.1 -N kernel.debug -axl | grep inode | wc -l
     961

and I have a vmcore to work on here !! :)

(kgdb) proc 99643
(kgdb) bt
#0  mi_switch () at machine/globals.h:119
#1  0x8014a1f9 in tsleep (ident=0x8a4ef600, priority=8, wmesg=0x80263d4a
"inode", timo=0) at /usr/src/sys/kern/kern_synch.c:479
#2  0x80141507 in acquire (lkp=0x8a4ef600, extflags=16777280, wanted=1536) at
/usr/src/sys/kern/kern_lock.c:147
#3  0x8014179c in lockmgr (lkp=0x8a4ef600, flags=16973826, interlkp=0xbde68aec,
p=0xbf57b000) at /usr/src/sys/kern/kern_lock.c:355
#4  0x80172b73 in vop_stdlock (ap=0xbfc2dd1c) at
/usr/src/sys/kern/vfs_default.c:256
#5  0x801f0955 in ufs_vnoperate (ap=0xbfc2dd1c) at
/usr/src/sys/ufs/ufs/ufs_vnops.c:2376
#6  0x8017d450 in vn_lock (vp=0xbde68a80, flags=131074, p=0xbf57b000) at
vnode_if.h:861
#7  0x80173b1c in lookup (ndp=0xbfc2dec4) at /usr/src/sys/kern/vfs_lookup.c:301
#8  0x80173824 in namei (ndp=0xbfc2dec4) at /usr/src/sys/kern/vfs_lookup.c:153
#9  0x8017c867 in vn_open (ndp=0xbfc2dec4, fmode=1, cmode=420) at
/usr/src/sys/kern/vfs_vnops.c:138
#10 0x8017899c in open (p=0xbf57b000, uap=0xbfc2df80) at
/usr/src/sys/kern/vfs_syscalls.c:1029
#11 0x8023c485 in syscall2 (frame={tf_fs = 47, tf_es = 134610991, tf_ds =
2143223855, tf_edi = 4, tf_esi = 672253248, tf_ebp = 2143284976, tf_isp =
-1077747756, tf_ebx = 672178060,
      tf_edx = 672253248, tf_ecx = 16, tf_eax = 5, tf_trapno = 12, tf_err = 2,
tf_eip = 672086720, tf_cs = 31, tf_eflags = 535, tf_esp = 2143284932, tf_ss =
47})
    at /usr/src/sys/i386/i386/trap.c:1175
#12 0x802299ab in Xint0x80_syscall ()
#13 0x2807ac6c in ?? ()
#14 0x2807abf0 in ?? ()
#15 0x804acbd in ?? ()
#16 0x8049e1e in ?? ()

(kgdb) print *(struct lock *)0x8a4ef600
$1 = {lk_interlock = {lock_data = 0}, lk_flags = 2098240, lk_sharecount = 0,
lk_waitcount = 958, lk_exclusivecount = 1, lk_prio = 8, lk_wmesg = 0x80263d4a
"inode", lk_timo = 6,
  lk_lockholder = 79367}


(kgdb) proc 79367
(kgdb) bt
#0  mi_switch () at machine/globals.h:119
#1  0x8014a1f9 in tsleep (ident=0x8a4ef300, priority=8, wmesg=0x80263d4a
"inode", timo=0) at /usr/src/sys/kern/kern_synch.c:479
#2  0x80141507 in acquire (lkp=0x8a4ef300, extflags=16777280, wanted=1536) at
/usr/src/sys/kern/kern_lock.c:147
#3  0x8014179c in lockmgr (lkp=0x8a4ef300, flags=16842754, interlkp=0xbde68dec,
p=0xbf57e5a0) at /usr/src/sys/kern/kern_lock.c:355
#4  0x80172b73 in vop_stdlock (ap=0xbf80ed44) at
/usr/src/sys/kern/vfs_default.c:256
#5  0x801f0955 in ufs_vnoperate (ap=0xbf80ed44) at
/usr/src/sys/ufs/ufs/ufs_vnops.c:2376
#6  0x8017d450 in vn_lock (vp=0xbde68d80, flags=65538, p=0xbf57e5a0) at
vnode_if.h:861
#7  0x80175d83 in vget (vp=0xbde68d80, flags=2, p=0xbf57e5a0) at
/usr/src/sys/kern/vfs_subr.c:1539
#8  0x80170c1f in vfs_cache_lookup (ap=0xbf80ee00) at
/usr/src/sys/kern/vfs_cache.c:494
#9  0x801f0955 in ufs_vnoperate (ap=0xbf80ee00) at
/usr/src/sys/ufs/ufs/ufs_vnops.c:2376
#10 0x80173d29 in lookup (ndp=0xbf80ee7c) at vnode_if.h:52
#11 0x80173824 in namei (ndp=0xbf80ee7c) at /usr/src/sys/kern/vfs_lookup.c:153
#12 0x80179ae9 in stat (p=0xbf57e5a0, uap=0xbf80ef80) at
/usr/src/sys/kern/vfs_syscalls.c:1788
#13 0x8023c485 in syscall2 (frame={tf_fs = 47, tf_es = 47, tf_ds = 2143223855,
tf_edi = 135990371, tf_esi = 135990312, tf_ebp = 2143287536, tf_isp =
-1082069036, tf_ebx = 135990371,
      tf_edx = 135983160, tf_ecx = -61, tf_eax = 188, tf_trapno = 12, tf_err =
2, tf_eip = 672125504, tf_cs = 31, tf_eflags = 534, tf_esp = 2143287492, tf_ss =
47})
    at /usr/src/sys/i386/i386/trap.c:1175
#14 0x802299ab in Xint0x80_syscall ()
#15 0x806206c in ?? ()
#16 0x8062f4d in ?? ()
#17 0x806328c in ?? ()
#18 0x805c6b6 in ?? ()
#19 0x805c8ed in ?? ()
#20 0x805cb5c in ?? ()
#21 0x805d009 in ?? ()
#22 0x805d553 in ?? ()
#23 0x804fb36 in ?? ()


not sure why 15->23 are giving ??'s, but I have no kernel modules being
used, having compiled everything into the kernel:

neptune# kldstat
Id Refs Address    Size     Name
 1    1 0x80100000 215f60   kernel
neptune#

On Tue, Jul 01, 2003, Marc G. Fournier wrote:
[...]
> and I have a vmcore to work on here !! :)
Yes, this does look promising.  Can you look at
*(struct lock *)0x8a4ef300 (the lock the second
process is trying to acquire) also?  It probably
points back to the first process, but we might as
well be sure.  It might also be interesting to see
the ndp arguments to the namei calls, but the
problem can probably be tracked down without them.

I'm actually out of town this week, so if anyone
else wants to take a stab, feel free.

On Wed, 2 Jul 2003, David Schultz wrote:
> On Tue, Jul 01, 2003, Marc G. Fournier wrote:
> [...]
> > and I have a vmcore to work on here !! :)
>
> Yes, this does look promising.  Can you look at
> *(struct lock *)0x8a4ef300 (the lock the second
> process is trying to acquire) also?
(kgdb) print *(struct lock *)0x8a4ef300
$2 = {lk_interlock = {lock_data = 0}, lk_flags = 2098240, lk_sharecount = 0,
lk_waitcount = 2, lk_exclusivecount = 1, lk_prio = 8, lk_wmesg = 0x80263d4a
"inode", lk_timo = 6,
  lk_lockholder = 75285}

> It probably points back to the first process, but we might as well be
> sure.  It might also be interesting to see the ndp arguments to the
> namei calls, but the problem can probably be tracked down without them.
How do I do this one?