Re: nullfs: panic: vrele: negative ref cnt

On 3/9/09, Paul B. Mahol <onemda_at_gmail.com> wrote:
> On 3/9/09, John Baldwin <jhb_at_freebsd.org> wrote:
>> On Monday 09 March 2009 9:15:22 am Paul B. Mahol wrote:
>>> Hi,
>>> here is part of textdump:
>>>
>>> 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
>>
>> Try this.  null_bypass() can't handle VOP_VPTOCNP because VPTOCNP doesn't
>> return a vnode that is locked and VREF'd, but just a vnode that is
>> vhold()'d.
>> This patch attempts to give nullfs a VOP_VPTONCP() method which remaps
>> the
>> directory vnode properly on return by locking the directory vnode while
>> invoking null_nodeget().
>
> It livelocks active vty into [ufs] state. Will try with WITNESS kernel
> soon.

db:1:lockinfo> show locks
db:1:locks>  show alllocks
Process 819 (sh) thread 0xc4112900 (100048)
db:1:alllocks>  show lockedvnods
Locked vnodes
db:0:kdb.enter.panic>  show pcpu
cpuid        = 1
curthread    = 0xc4112900: pid 819 "sh"
curpcb       = 0xc3b65d90
fpcurthread  = 0xc4112900: pid 819 "sh"
idlethread   = 0xc3d08d80: pid 10 "idle: cpu1"
APIC ID      = 1
currentldt   = 0x50
spin locks held:
db:0:kdb.enter.panic>  bt
Tracing pid 819 tid 100048 td 0xc4112900
kdb_enter(c0610bfe,c0610bfe,c061682c,c3b65990,1,...) at kdb_enter+0x3a
panic(c061682c,c4428c5f,2e8,c061cee6,89d,...) at panic+0x136
witness_checkorder(c4338164,9,c061cee6,89d,c4338180,...) at
witness_checkorder+0x1dc
__lockmgr_args(c4338164,80100,c4338180,0,0,...) at __lockmgr_args+0x762
ffs_lock(c3b65ae8,c04e0a7b,c061cee6,80100,c433810c,...) at ffs_lock+0x8a
VOP_LOCK1_APV(c0653a40,c3b65ae8,c0495698,c0666740,c433810c,...) at
VOP_LOCK1_APV+0xb5
_vn_lock(c433810c,80100,c061cee6,89d,4,...) at _vn_lock+0x5e
vrele(c433810c,0,c4428b6f,82,c433810c,...) at vrele+0x142
null_nodeget(c3ff9000,c433810c,c3b65bf4,2e8,c0666a20,...) at null_nodeget+0xa0
null_vptocnp(c3b65be0,c3f36d9c,c3b65c28,c3b65be0,c3b65c04,...) at
null_vptocnp+0x90
VOP_VPTOCNP_APV(c4429240,c3b65be0,c061bf01,387,c3e6e800,...) at
VOP_VPTOCNP_APV+0xa5
vn_vptocnp(c3b65c4c,c061bf01,3af,c3b65c3c,c3f36d9c,...) at vn_vptocnp+0xd9
vn_fullpath1(c3e6e800,c3b65c5c,3fc,315,c3e6e800,...) at vn_fullpath1+0x29a
kern___getcwd(c4112900,bfbfe8d4,0,400,c3b65d2c,...) at kern___getcwd+0xd0
__getcwd(c4112900,c3b65cf8,8,c0617c09,c0640290,...) at __getcwd+0x29
syscall(c3b65d38) at syscall+0x261
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (326, FreeBSD ELF32, __getcwd), eip = 0x2814edfb, esp =
0xbfbfe71c, ebp = 0xbfbfe7d8 ---


exclusive lock of (lockmgr) ufs _at_ /usr/src/sys/kern/vfs_subr.c:2205
while share locked from
/usr/local/src/sys/modules/nullfs/../../fs/nullfs/null_vnops.c:744
panic: excl->share
cpuid = 1
KDB: enter: panic
exclusive sleep mutex vnode interlock (vnode interlock) r = 0
(0xc4338180) locked _at_ /usr/src/s
ys/kern/vfs_subr.c:2174
shared lockmgr ufs (ufs) r = 0 (0xc4338164) locked _at_
/usr/local/src/sys/modules/nullfs/../../f
s/nullfs/null_vnops.c:744
shared lockmgr ufs (ufs) r = 0 (0xc4338058) locked _at_
/usr/src/sys/kern/vfs_default.c:790
exclusive sleep mutex vnode interlock (vnode interlock) r = 0
(0xc4338180) locked _at_ /usr/src/s
ys/kern/vfs_subr.c:2174
shared lockmgr ufs (ufs) r = 0 (0xc4338164) locked _at_
/usr/local/src/sys/modules/nullfs/../../f
s/nullfs/null_vnops.c:744
shared lockmgr ufs (ufs) r = 0 (0xc4338058) locked _at_
/usr/src/sys/kern/vfs_default.c:790

0xc433810c: tag ufs, type VDIR
    usecount 0, writecount 0, refcount 5 mountedhere 0
    flags (VI_OWEINACT)
 VI_LOCKed    v_object 0xc41236c8 ref 0 pages 1
    lock type ufs: SHARED (count 1)
        ino 3061760, on dev ad0s1h

0xc4338000: tag ufs, type VDIR
    usecount 1, writecount 0, refcount 4 mountedhere 0
    flags ()
    v_object 0xc4113554 ref 0 pages 1
    lock type ufs: SHARED (count 1)
        ino 3583142, on dev ad0s1h

0xc4359b84: tag null, type VDIR
    usecount 2, writecount 0, refcount 2 mountedhere 0
    flags (VV_ROOT)
    lock type ufs: SHARED (count 1)
        vp=0xc4359b84, lowervp=0xc433810c

0xc4383218: tag null, type VDIR
    usecount 4, writecount 0, refcount 5 mountedhere 0
    flags ()
    lock type ufs: SHARED (count 1)
        vp=0xc4383218, lowervp=0xc4338000