Re: nullfs: panic: vrele: negative ref cnt

From: pluknet <pluknet_at_gmail.com>
Date: Mon, 9 Mar 2009 21:58:22 +0300
2009/3/9 Paul B. Mahol <onemda_at_gmail.com>:
> Hi,
> here is part of textdump:
>
> db:1:lockinfo> show locks
> db:1:locks>  show alllocks
> Process 722 (sh) thread 0xc4134000 (100065)
> db:1:alllocks>  show lockedvnods
> Locked vnodes
> db:0:kdb.enter.panic>  show pcpu
> cpuid        = 1
> curthread    = 0xc4134000: pid 722 "sh"
> curpcb       = 0xc3ba8d90
> fpcurthread  = 0xc4134000: pid 722 "sh"
> idlethread   = 0xc3d08d80: pid 10 "idle: cpu1"
> APIC ID      = 1
> currentldt   = 0x50
> spin locks held:
> db:0:kdb.enter.panic>  bt
> Tracing pid 722 tid 100065 td 0xc4134000
> kdb_enter(c0610bfe,c0610bfe,c061db9e,c3ba8aa8,1,...) at kdb_enter+0x3a
> panic(c061db9e,0,c061cee6,88e,4,...) at panic+0x136
> vrele(c4326d9c,0,c433fb5f,82,c060f3c7,...) at vrele+0x111
> null_nodeget(c3fd4780,c4326d9c,c3ba8bf4,0,c3ba8be4,...) at null_nodeget+0xa0
> null_bypass(c3ba8be0,c3f35a78,c3ba8c28) at null_bypass+0x141
> VOP_VPTOCNP_APV(c4340240,c3ba8be0,c061bf01,387,c3cecc00,...) at
> VOP_VPTOCNP_APV+0xb3
> vn_vptocnp(c3ba8c4c,c061bf01,3af,c3ba8c3c,c3f35a78,...) at vn_vptocnp+0xd9
> vn_fullpath1(c3cecc00,c3ba8c5c,3fc,315,c3cecc00,...) at vn_fullpath1+0x29a
> kern___getcwd(c4134000,bfbfe884,0,400,c3ba8d2c,...) at kern___getcwd+0xd0
> __getcwd(c4134000,c3ba8cf8,8,c0617c09,c0640290,...) at __getcwd+0x29
> syscall(c3ba8d38) at syscall+0x261
> Xint0x80_syscall() at Xint0x80_syscall+0x20
> --- syscall (326, FreeBSD ELF32, __getcwd), eip = 0x2814edfb, esp =
> 0xbfbfe6cc, ebp = 0xbfbfe788 ---
>
>
> panic: vrele: negative ref cnt
> cpuid = 1
> KDB: enter: panic
> shared lockmgr ufs (ufs) r = 0 (0xc43c36a0) locked _at_
> /usr/src/sys/kern/vfs_default.c:790
> shared lockmgr ufs (ufs) r = 0 (0xc43c36a0) locked _at_
> /usr/src/sys/kern/vfs_default.c:790
>
> 0xc43c3648: tag ufs, type VDIR
>    usecount 1, writecount 0, refcount 1 mountedhere 0
>    flags ()
>    lock type ufs: SHARED (count 1)
>        ino 3583142, on dev ad0s1h
>
> 0xc43c3430: tag null, type VDIR
>    usecount 4, writecount 0, refcount 5 mountedhere 0
>    flags ()
>    lock type ufs: SHARED (count 1)
>        vp=0xc43c3430, lowervp=0xc43c3648
>
>
> How to reproduce it:
>
> # mount_nullfs /usr/local/src /usr/src
> # cd /sys
> # whereis something
>
>
> It appears panic have been introduced after r189488
>

[marcus_at_ cc'ed]

Futher debugging shows:

Script started on Mon Mar  9 21:43:17 2009
c8-vb# kgdb /boot/kernel/kernel /var/crash/vmcore.1

GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-marcel-freebsd"...

Unread portion of the kernel message buffer:
, FreeBSD ELF32, __getcwd), eip = 0x28154b2b, esp = 0xbfbfe71c, ebp =
0xbfbfe7d8 ---
null_hashget: 0xc4451560 is not locked but should be
KDB: enter: lock violation
panic: mutex Giant not owned at /usr/src/sys/kern/tty_ttydisc.c:1127
cpuid = 0
Uptime: 43m7s
Physical memory: 1015 MB
Dumping 51 MB: 36 20 4

Reading symbols from /boot/kernel/if_em.ko...Reading symbols from
/boot/kernel/if_em.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/if_em.ko
Reading symbols from /boot/kernel/nfsclient.ko...Reading symbols from
/boot/kernel/nfsclient.ko.symbols...done.
done.
Loaded symbols for /boot/kernel/nfsclient.ko
#0  doadump () at pcpu.h:246
246	pcpu.h: No such file or directory.
	in pcpu.h
(kgdb) bt
#0  doadump () at pcpu.h:246
#1  0xc05c458e in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:420
#2  0xc05c4862 in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:576
#3  0xc05b4c77 in _mtx_assert (m=0xc08b6170, what=4,
    file=0xc0829baf "/usr/src/sys/kern/tty_ttydisc.c", line=1127)
    at /usr/src/sys/kern/kern_mutex.c:639
#4  0xc06197dd in ttydisc_getc (tp=0xc3dbf000, buf=0xe66bc7c0, len=128)
    at /usr/src/sys/kern/tty_ttydisc.c:1127
#5  0xc050daf4 in sctty_outwakeup (tp=0xc3dbf000)
    at /usr/src/sys/dev/syscons/syscons.c:323
#6  0xc050e05c in scgetc (sc=0xc0a73000, flags=3)
    at /usr/src/sys/dev/syscons/syscons.c:3281
#7  0xc050e680 in sc_cngetc (cd=0xc0863d20)
    at /usr/src/sys/dev/syscons/syscons.c:1607
#8  0xc058cd68 in cncheckc () at /usr/src/sys/kern/kern_cons.c:377
#9  0xc058cda6 in cngetc () at /usr/src/sys/kern/kern_cons.c:355
#10 0xc0480435 in db_readline (lstart=0xc08a0100 "", lsize=120)
    at /usr/src/sys/ddb/db_input.c:326
#11 0xc0480e0a in db_read_line () at /usr/src/sys/ddb/db_lex.c:56
#12 0xc047f0b6 in db_command_loop () at /usr/src/sys/ddb/db_command.c:496
#13 0xc0480f2d in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:229
#14 0xc05f1d86 in kdb_trap (type=3, code=0, tf=0xe66bca34)
    at /usr/src/sys/kern/subr_kdb.c:534
#15 0xc07bc856 in trap (frame=0xe66bca34) at /usr/src/sys/i386/i386/trap.c:678
---Type <return> to continue, or q <return> to quit---
#16 0xc07a15bb in calltrap () at /usr/src/sys/i386/i386/exception.s:165
#17 0xc05f1f0a in kdb_enter (why=0xc082deeb "vfslock",
    msg=0xc082dedc "lock violation") at cpufunc.h:71
#18 0xc064a541 in vfs_badlock (msg=0xc082df39 "is not locked but should be",
    str=0xc08173c4 "null_hashget", vp=0xc4451560)
    at /usr/src/sys/kern/vfs_subr.c:3699
#19 0xc064ddf2 in assert_vop_locked (vp=0xc4451560,
    str=0xc08173c4 "null_hashget") at /usr/src/sys/kern/vfs_subr.c:3723
#20 0xc055c5df in null_nodeget (mp=0xc40152cc, lowervp=0xc4451560,
    vpp=0xe66bcbf0) at /usr/src/sys/fs/nullfs/null_subr.c:110
#21 0xc055d75a in null_bypass (ap=0xe66bcbdc)
    at /usr/src/sys/fs/nullfs/null_vnops.c:325
#22 0xc07c86a3 in VOP_VPTOCNP_APV (vop=0xc08688a0, a=0xe66bcbdc)
    at vnode_if.c:2871
#23 0xc063a749 in vn_vptocnp (vp=0xe66bcc24, bp=0xe66bcc28,
    buf=0xc3e15c00 'p' <repeats 200 times>..., buflen=0xe66bcc48)
    at vnode_if.h:1541
#24 0xc063aaca in vn_fullpath1 (td=Variable "td" is not available.
) at /usr/src/sys/kern/vfs_cache.c:1001
#25 0xc063ae60 in kern___getcwd (td=0xc4435000,
    buf=0xbfbfe8d4 <Address 0xbfbfe8d4 out of bounds>, bufseg=UIO_USERSPACE,
    buflen=1024) at /usr/src/sys/kern/vfs_cache.c:795
#26 0xc063b009 in __getcwd (td=0xc4435000, uap=0xe66bccf8)
    at /usr/src/sys/kern/vfs_cache.c:769
#27 0xc07bbfd4 in syscall (frame=0xe66bcd38)
---Type <return> to continue, or q <return> to quit---
    at /usr/src/sys/i386/i386/trap.c:1066
#28 0xc07a1620 in Xint0x80_syscall ()
    at /usr/src/sys/i386/i386/exception.s:261
#29 0x00000033 in ?? ()
Previous frame inner to this frame (corrupt stack?)
(kgdb) c8-vb#

c8-vb# ^Dexit

Script done on Mon Mar  9 21:43:35 2009


-- 
wbr,
pluknet
Received on Mon Mar 09 2009 - 17:58:24 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:43 UTC