--- //depot/vendor/freebsd/src/sys/kern/vfs_mount.c 2008/12/16 23:20:16 +++ //depot/user/attilio/attilio_lockmgr/kern/vfs_mount.c 2009/02/02 16:43:07 @@ -386,6 +386,8 @@ u_int iovcnt; AUDIT_ARG(fflags, uap->flags); + CTR4(KTR_VFS, "%s: iovp %p with iovcnt %d and flags %d", __func__, + uap->iovp, uap->iovcnt, uap->flags); /* * Filter out MNT_ROOTFS. We do not want clients of nmount() in @@ -400,16 +402,24 @@ * Check that we have an even number of iovec's * and that we have at least two options. */ - if ((iovcnt & 1) || (iovcnt < 4)) + if ((iovcnt & 1) || (iovcnt < 4)) { + CTR2(KTR_VFS, "%s: failed for invalid iovcnt %d", __func__, + uap->iovcnt); return (EINVAL); + } error = copyinuio(uap->iovp, iovcnt, &auio); - if (error) + if (error) { + CTR2(KTR_VFS, "%s: failed for invalid uio op with %d errno", + __func__, error); return (error); + } iov = auio->uio_iov; for (i = 0; i < iovcnt; i++) { if (iov->iov_len > MMAXOPTIONLEN) { free(auio, M_IOV); + CTR1(KTR_VFS, "%s: failed for invalid new auio", + __func__); return (EINVAL); } iov++; @@ -429,6 +439,7 @@ vfs_ref(struct mount *mp) { + CTR2(KTR_VFS, "%s: mp %p", __func__, mp); MNT_ILOCK(mp); MNT_REF(mp); MNT_IUNLOCK(mp); @@ -438,6 +449,7 @@ vfs_rel(struct mount *mp) { + CTR2(KTR_VFS, "%s: mp %p", __func__, mp); MNT_ILOCK(mp); MNT_REL(mp); MNT_IUNLOCK(mp); --- //depot/vendor/freebsd/src/sys/kern/vfs_subr.c 2009/01/23 22:15:14 +++ //depot/user/attilio/attilio_lockmgr/kern/vfs_subr.c 2009/02/02 16:57:31 @@ -341,6 +341,7 @@ { MPASS((flags & ~MBF_MASK) == 0); + CTR3(KTR_VFS, "%s: mp %p with flags %d", __func__, mp, flags); MNT_ILOCK(mp); MNT_REF(mp); @@ -348,6 +349,8 @@ if (flags & MBF_NOWAIT || mp->mnt_kern_flag & MNTK_REFEXPIRE) { MNT_REL(mp); MNT_IUNLOCK(mp); + CTR1(KTR_VFS, "%s: failed busying before to sleep", + __func__); return (ENOENT); } if (flags & MBF_MNTLSTLOCK) @@ -358,6 +361,7 @@ MNT_IUNLOCK(mp); if (flags & MBF_MNTLSTLOCK) mtx_lock(&mountlist_mtx); + CTR1(KTR_VFS, "%s: failed busying after sleep", __func__); return (ENOENT); } if (flags & MBF_MNTLSTLOCK) @@ -374,11 +378,13 @@ vfs_unbusy(struct mount *mp) { + CTR2(KTR_VFS, "%s: mp %p", __func__, mp); MNT_ILOCK(mp); MNT_REL(mp); mp->mnt_lockref--; if (mp->mnt_lockref == 0 && (mp->mnt_kern_flag & MNTK_DRAINING) != 0) { MPASS(mp->mnt_kern_flag & MNTK_UNMOUNT); + CTR1(KTR_VFS, "%s: waking up waiters", __func__); mp->mnt_kern_flag &= ~MNTK_DRAINING; wakeup(&mp->mnt_lockref); } @@ -393,6 +399,7 @@ { struct mount *mp; + CTR2(KTR_VFS, "%s: fsid %p", __func__, fsid); mtx_lock(&mountlist_mtx); TAILQ_FOREACH(mp, &mountlist, mnt_list) { if (mp->mnt_stat.f_fsid.val[0] == fsid->val[0] && @@ -403,6 +410,7 @@ } } mtx_unlock(&mountlist_mtx); + CTR2(KTR_VFS, "%s: lookup failed for %p id", __func__, fsid); return ((struct mount *) 0); } @@ -416,6 +424,7 @@ struct mount *mp; int error; + CTR2(KTR_VFS, "%s: fsid %p", __func__, fsid); mtx_lock(&mountlist_mtx); TAILQ_FOREACH(mp, &mountlist, mnt_list) { if (mp->mnt_stat.f_fsid.val[0] == fsid->val[0] && @@ -428,6 +437,7 @@ return (mp); } } + CTR2(KTR_VFS, "%s: lookup failed for %p id", __func__, fsid); mtx_unlock(&mountlist_mtx); return ((struct mount *) 0); } @@ -498,6 +508,7 @@ fsid_t tfsid; int mtype; + CTR2(KTR_VFS, "%s: mp %p", __func__, mp); mtx_lock(&mntid_mtx); mtype = mp->mnt_vfc->vfc_typenum; tfsid.val[1] = mtype; @@ -822,7 +833,7 @@ { struct bufobj *bo; - CTR1(KTR_VFS, "vdestroy vp %p", vp); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); mtx_lock(&vnode_free_list_mtx); numvnodes--; mtx_unlock(&vnode_free_list_mtx); @@ -867,20 +878,27 @@ { struct mount *vnmp; - CTR1(KTR_VFS, "vtryrecycle: trying vp %p", vp); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); VNASSERT(vp->v_holdcnt, vp, ("vtryrecycle: Recycling vp %p without a reference.", vp)); /* * This vnode may found and locked via some other list, if so we * can't recycle it yet. */ - if (VOP_LOCK(vp, LK_EXCLUSIVE | LK_NOWAIT) != 0) + if (VOP_LOCK(vp, LK_EXCLUSIVE | LK_NOWAIT) != 0) { + CTR2(KTR_VFS, + "%s: impossible to recycle, the vp %p lock is alredy held", + __func__, vp); return (EWOULDBLOCK); + } /* * Don't recycle if its filesystem is being suspended. */ if (vn_start_write(vp, &vnmp, V_NOWAIT) != 0) { VOP_UNLOCK(vp, 0); + CTR2(KTR_VFS, + "%s: impossible to recycle, can not start the write for %p", + __func__, vp); return (EBUSY); } /* @@ -893,13 +911,15 @@ if (vp->v_usecount) { VOP_UNLOCK(vp, LK_INTERLOCK); vn_finished_write(vnmp); + CTR2(KTR_VFS, + "%s: impossible to recycle, %p is alredy referenced", + __func__, vp); return (EBUSY); } if ((vp->v_iflag & VI_DOOMED) == 0) vgonel(vp); VOP_UNLOCK(vp, LK_INTERLOCK); vn_finished_write(vnmp); - CTR1(KTR_VFS, "vtryrecycle: recycled vp %p", vp); return (0); } @@ -913,6 +933,7 @@ struct vnode *vp = NULL; struct bufobj *bo; + CTR3(KTR_VFS, "%s: mp %p with tag %s", __func__, mp, tag); mtx_lock(&vnode_free_list_mtx); /* * Lend our context to reclaim vnodes if they've exceeded the max. @@ -995,7 +1016,6 @@ vp->v_vflag |= VV_NOKNOTE; } - CTR2(KTR_VFS, "getnewvnode: mp %p vp %p", mp, vp); *vpp = vp; return (0); } @@ -1173,7 +1193,7 @@ vinvalbuf(struct vnode *vp, int flags, int slpflag, int slptimeo) { - CTR2(KTR_VFS, "vinvalbuf vp %p flags %d", vp, flags); + CTR3(KTR_VFS, "%s: vp %p with flags %d", __func__, vp, flags); ASSERT_VOP_LOCKED(vp, "vinvalbuf"); return (bufobj_invalbuf(&vp->v_bufobj, flags, slpflag, slptimeo)); } @@ -1265,7 +1285,9 @@ int trunclbn; struct bufobj *bo; - CTR2(KTR_VFS, "vtruncbuf vp %p length %jd", vp, length); + CTR5(KTR_VFS, "%s: vp %p with cred %p, and the block %d:%ju", __func__, + vp, cred, blksize, (uintmax_t)length); + /* * Round up to the *next* lbn. */ @@ -1974,8 +1996,7 @@ v_incr_usecount(struct vnode *vp) { - CTR3(KTR_VFS, "v_incr_usecount: vp %p holdcnt %d usecount %d\n", - vp, vp->v_holdcnt, vp->v_usecount); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_usecount++; if (vp->v_type == VCHR && vp->v_rdev != NULL) { dev_lock(); @@ -1993,8 +2014,7 @@ v_upgrade_usecount(struct vnode *vp) { - CTR3(KTR_VFS, "v_upgrade_usecount: vp %p holdcnt %d usecount %d\n", - vp, vp->v_holdcnt, vp->v_usecount); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_usecount++; if (vp->v_type == VCHR && vp->v_rdev != NULL) { dev_lock(); @@ -2012,11 +2032,10 @@ v_decr_usecount(struct vnode *vp) { - CTR3(KTR_VFS, "v_decr_usecount: vp %p holdcnt %d usecount %d\n", - vp, vp->v_holdcnt, vp->v_usecount); ASSERT_VI_LOCKED(vp, __FUNCTION__); VNASSERT(vp->v_usecount > 0, vp, ("v_decr_usecount: negative usecount")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_usecount--; if (vp->v_type == VCHR && vp->v_rdev != NULL) { dev_lock(); @@ -2036,11 +2055,10 @@ v_decr_useonly(struct vnode *vp) { - CTR3(KTR_VFS, "v_decr_useonly: vp %p holdcnt %d usecount %d\n", - vp, vp->v_holdcnt, vp->v_usecount); ASSERT_VI_LOCKED(vp, __FUNCTION__); VNASSERT(vp->v_usecount > 0, vp, ("v_decr_useonly: negative usecount")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_usecount--; if (vp->v_type == VCHR && vp->v_rdev != NULL) { dev_lock(); @@ -2065,11 +2083,15 @@ VFS_ASSERT_GIANT(vp->v_mount); VNASSERT((flags & LK_TYPE_MASK) != 0, vp, ("vget: invalid lock operation")); + CTR3(KTR_VFS, "%s: vp %p with flags %d", __func__, vp, flags); + if ((flags & LK_INTERLOCK) == 0) VI_LOCK(vp); vholdl(vp); if ((error = vn_lock(vp, flags | LK_INTERLOCK)) != 0) { vdrop(vp); + CTR2(KTR_VFS, "%s: impossible to lock the vnode %p", __func__, + vp); return (error); } if (vp->v_iflag & VI_DOOMED && (flags & LK_RETRY) == 0) @@ -2100,6 +2122,7 @@ vref(struct vnode *vp) { + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); VI_LOCK(vp); v_incr_usecount(vp); VI_UNLOCK(vp); @@ -2144,6 +2167,7 @@ /* Skip this v_writecount check if we're going to panic below. */ VNASSERT(vp->v_writecount < vp->v_usecount || vp->v_usecount < 1, vp, ("vrele: missed vn_close")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); if (vp->v_usecount > 1 || ((vp->v_iflag & VI_DOINGINACT) && vp->v_usecount == 1)) { @@ -2157,6 +2181,7 @@ VI_UNLOCK(vp); panic("vrele: negative ref cnt"); } + CTR2(KTR_VFS, "%s: return to freelist the vnode %p", __func__, vp); /* * We want to hold the vnode until the inactive finishes to * prevent vgone() races. We drop the use count here and the @@ -2197,6 +2222,7 @@ KASSERT(vp != NULL, ("vput: null vp")); ASSERT_VOP_LOCKED(vp, "vput"); VFS_ASSERT_GIANT(vp->v_mount); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); VI_LOCK(vp); /* Skip this v_writecount check if we're going to panic below. */ VNASSERT(vp->v_writecount < vp->v_usecount || vp->v_usecount < 1, vp, @@ -2216,6 +2242,7 @@ #endif panic("vput: negative ref cnt"); } + CTR2(KTR_VFS, "%s: return to freelist the vnode %p", __func__, vp); /* * We want to hold the vnode until the inactive finishes to * prevent vgone() races. We drop the use count here and the @@ -2257,6 +2284,7 @@ vholdl(struct vnode *vp) { + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_holdcnt++; if (VSHOULDBUSY(vp)) vbusy(vp); @@ -2284,11 +2312,14 @@ { ASSERT_VI_LOCKED(vp, "vdropl"); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); if (vp->v_holdcnt <= 0) panic("vdrop: holdcnt %d", vp->v_holdcnt); vp->v_holdcnt--; if (vp->v_holdcnt == 0) { if (vp->v_iflag & VI_DOOMED) { + CTR2(KTR_VFS, "%s: destroying the vnode %p", __func__, + vp); vdestroy(vp); return; } else @@ -2311,6 +2342,7 @@ ASSERT_VI_LOCKED(vp, "vinactive"); VNASSERT((vp->v_iflag & VI_DOINGINACT) == 0, vp, ("vinactive: recursed on VI_DOINGINACT")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); vp->v_iflag |= VI_DOINGINACT; vp->v_iflag &= ~VI_OWEINACT; VI_UNLOCK(vp); @@ -2353,7 +2385,8 @@ struct vattr vattr; int busy = 0, error; - CTR1(KTR_VFS, "vflush: mp %p", mp); + CTR4(KTR_VFS, "%s: mp %p with rootrefs %d with flags %d", __func__, mp, + rootrefs, flags); if (rootrefs > 0) { KASSERT((flags & (SKIPSYSTEM | WRITECLOSE)) == 0, ("vflush: bad args")); @@ -2361,8 +2394,11 @@ * Get the filesystem root vnode. We can vput() it * immediately, since with rootrefs > 0, it won't go away. */ - if ((error = VFS_ROOT(mp, LK_EXCLUSIVE, &rootvp, td)) != 0) + if ((error = VFS_ROOT(mp, LK_EXCLUSIVE, &rootvp, td)) != 0) { + CTR2(KTR_VFS, "%s: vfs_root lookup failed with %d", + __func__, error); return (error); + } vput(rootvp); } @@ -2449,8 +2485,11 @@ } else VI_UNLOCK(rootvp); } - if (busy) + if (busy) { + CTR2(KTR_VFS, "%s: failing as %d vnodes are busy", __func__, + busy); return (EBUSY); + } for (; rootrefs > 0; rootrefs--) vrele(rootvp); return (0); @@ -2465,6 +2504,7 @@ int recycled; ASSERT_VOP_ELOCKED(vp, "vrecycle"); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); recycled = 0; VI_LOCK(vp); if (vp->v_usecount == 0) { @@ -2498,11 +2538,11 @@ int active; struct mount *mp; - CTR1(KTR_VFS, "vgonel: vp %p", vp); ASSERT_VOP_ELOCKED(vp, "vgonel"); ASSERT_VI_LOCKED(vp, "vgonel"); VNASSERT(vp->v_holdcnt, vp, ("vgonel: vp %p has no reference.", vp)); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); td = curthread; /* @@ -3099,7 +3139,9 @@ int error; KASSERT(curthread != NULL, ("vfs_unmountall: NULL curthread")); + CTR1(KTR_VFS, "%s: unmounting all fs", __func__); td = curthread; + /* * Since this only runs when rebooting, it is not interlocked. */ @@ -3140,6 +3182,7 @@ struct vnode *vp, *mvp; struct vm_object *obj; + CTR2(KTR_VFS, "%s: mp %p", __func__, mp); MNT_ILOCK(mp); MNT_VNODE_FOREACH(vp, mp, mvp) { VI_LOCK(vp); @@ -3179,7 +3222,6 @@ vfree(struct vnode *vp) { - CTR1(KTR_VFS, "vfree vp %p", vp); ASSERT_VI_LOCKED(vp, "vfree"); mtx_lock(&vnode_free_list_mtx); VNASSERT(vp->v_op != NULL, vp, ("vfree: vnode already reclaimed.")); @@ -3187,6 +3229,7 @@ VNASSERT(VSHOULDFREE(vp), vp, ("vfree: freeing when we shouldn't")); VNASSERT((vp->v_iflag & VI_DOOMED) == 0, vp, ("vfree: Freeing doomed vnode")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); if (vp->v_iflag & VI_AGE) { TAILQ_INSERT_HEAD(&vnode_free_list, vp, v_freelist); } else { @@ -3204,10 +3247,10 @@ static void vbusy(struct vnode *vp) { - CTR1(KTR_VFS, "vbusy vp %p", vp); ASSERT_VI_LOCKED(vp, "vbusy"); VNASSERT((vp->v_iflag & VI_FREE) != 0, vp, ("vnode not free")); VNASSERT(vp->v_op != NULL, vp, ("vbusy: vnode already reclaimed.")); + CTR2(KTR_VFS, "%s: vp %p", __func__, vp); mtx_lock(&vnode_free_list_mtx); TAILQ_REMOVE(&vnode_free_list, vp, v_freelist);