Date: Wed, 7 Apr 2010 09:00:44 +0200 (CEST) From: Petr Salinger <Petr.Salinger@seznam.cz> To: Kostik Belousov <kostikbel@gmail.com> Cc: freebsd-hackers@freebsd.org Subject: Re: leak of the vnodes Message-ID: <Pine.LNX.4.62.1004070838050.27621@sci.felk.cvut.cz> In-Reply-To: <20100406210321.GE2415@deviant.kiev.zoral.com.ua> References: <20100403210829.GW2415@deviant.kiev.zoral.com.ua> <Pine.LNX.4.62.1004052223210.23732@sci.felk.cvut.cz> <20100405185924.GS2415@deviant.kiev.zoral.com.ua> <Pine.LNX.4.62.1004061011470.24982@sci.felk.cvut.cz> <20100406092429.GV2415@deviant.kiev.zoral.com.ua> <Pine.LNX.4.62.1004061700590.25851@sci.felk.cvut.cz> <20100406140308.GY2415@deviant.kiev.zoral.com.ua> <20100406140852.GZ2415@deviant.kiev.zoral.com.ua> <20100406144402.GB2415@deviant.kiev.zoral.com.ua> <Pine.LNX.4.62.1004062154060.26438@sci.felk.cvut.cz> <20100406210321.GE2415@deviant.kiev.zoral.com.ua>
next in thread | previous in thread | raw e-mail | index | archive | help
[-- Attachment #1 --]
On Wed, 7 Apr 2010, Kostik Belousov wrote:
> On Tue, Apr 06, 2010 at 10:01:56PM +0200, Petr Salinger wrote:
>>> Can you try to get a backtrace at the points you have shown me ?
>>
>> All are similar to this, with ptyp5/ptyp6/ptyp7 name changes.
>>
>> a vnode 0xffffff0058978000: tag devfs, type VCHR
>> usecount 1, writecount 1, refcount 2 mountedhere 0xffffff0039cb0c00
>> flags (VI_DOOMED)
>> lock type devfs: EXCL by thread 0xffffff0039e16760 (pid 31427)
>> dev ptyp5
>> KDB: stack backtrace:
>> db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
>> vgonel() at vgonel+0x424
>> vgone() at vgone+0x39
>> devfs_delete() at devfs_delete+0x1b1
>> devfs_populate_loop() at devfs_populate_loop+0x228
>> devfs_populate() at devfs_populate+0x42
>> devfs_lookup() at devfs_lookup+0x258
>> VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e
>> lookup() at lookup+0x467
>> namei() at namei+0x3ea
>> vn_open_cred() at vn_open_cred+0x211
>> kern_openat() at kern_openat+0x188
>> syscall() at syscall+0x168
>> Xfast_syscall() at Xfast_syscall+0xdc
>> --- syscall (5, FreeBSD ELF64, open), rip = 0x800622097, rsp =
>> 0x7fffffffbb88, rbp = 0x7fffffffbe30 ---
>> KDB: stack backtrace:
>> db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
>> vgonel() at vgonel+0x39d
>> vgone() at vgone+0x39
>> devfs_delete() at devfs_delete+0x1b1
>> devfs_populate_loop() at devfs_populate_loop+0x228
>> devfs_populate() at devfs_populate+0x42
>> devfs_lookup() at devfs_lookup+0x258
>> VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e
>> lookup() at lookup+0x467
>> namei() at namei+0x3ea
>> vn_open_cred() at vn_open_cred+0x211
>> kern_openat() at kern_openat+0x188
>> syscall() at syscall+0x168
>> Xfast_syscall() at Xfast_syscall+0xdc
>> --- syscall (5, FreeBSD ELF64, open), rip = 0x800622097, rsp =
>> 0x7fffffffbb88, rbp = 0x7fffffffbe30 ---
>> a vnode 0xffffff00589b5b40: tag devfs, type VCHR
>> usecount 1, writecount 1, refcount 2 mountedhere 0xffffff0028d75600
>> flags (VI_DOOMED)
>> lock type devfs: EXCL by thread 0xffffff0028cfb3b0 (pid 4529)
>> dev ptyp6
>> KDB: stack backtrace:
>> db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
>> vgonel() at vgonel+0x424
>> vgone() at vgone+0x39
>> devfs_delete() at devfs_delete+0x1b1
>> devfs_populate_loop() at devfs_populate_loop+0x228
>> devfs_populate() at devfs_populate+0x42
>> devfs_lookup() at devfs_lookup+0x258
>> VOP_LOOKUP_APV() at VOP_LOOKUP_APV+0x7e
>> lookup() at lookup+0x467
>> namei() at namei+0x3ea
>> vn_open_cred() at vn_open_cred+0x211
>> kern_openat() at kern_openat+0x188
>> syscall() at syscall+0x168
>> Xfast_syscall() at Xfast_syscall+0xdc
>
> Why do you think that this is the problem ?
I used the attached diff, with hackish snooping
on allocated/freed memory for vnodes. When the vp pointer have been
logged as active1/active2, it is (much) later shown with
dead_vnodeops in DUMP_VP().
> One refcount unit is coming from devfs_delete() calling vhold() around
> vgone() to prevent the vnode from disappearing under it.
>
> Second refcount unit comes in pair with use count unit. Use count
> implies refcount, and use count is allocated when vnode is e.g. opened,
> to account for struct file having a reference to struct vnode.
>
> What *might* happen for the device nodes you have shown, is that some
> application has file opened for the node /dev/ttyp*, and then master pty
> device closed. The slave /dev/ttyp* node is destroyed, that you see as
> devfs_populate->devfs_delete() sequence. The vnode will be eventually
> freed when corresponding file is closed.
> If you can confirm that some process has file opened with the reclaimed
> vnode, then my theory will be confirmed.
What have to be logged ?
> I think there should be something else going on.
May be both processes share file and memory space (RFMEM).
Petr
[-- Attachment #2 --]
Index: vfs_subr.c
===================================================================
--- vfs_subr.c (revision 206142)
+++ vfs_subr.c (working copy)
@@ -280,6 +280,62 @@
#define VSHOULDBUSY(vp) (((vp)->v_iflag & VI_FREE) && (vp)->v_holdcnt)
+#define MAX_LVNODE 20000
+struct vnode *lbuf[MAX_LVNODE];
+int lcnt;
+
+
+static inline int FIND_VP(struct vnode *vp)
+{
+int pos;
+for (pos = 0 ; pos < MAX_LVNODE; pos++)
+{
+ if (lbuf[pos] == vp)
+ return pos;
+}
+return -1;
+
+}
+
+static inline void DROP_VP(struct vnode *vp)
+{
+ int pos = FIND_VP(vp);
+ if (pos != -1)
+ lbuf[pos] = NULL;
+
+
+}
+
+static inline void ADD_VP(struct vnode *vp)
+{
+ if (lcnt < MAX_LVNODE)
+ {
+ lbuf[lcnt] = vp;
+ lcnt++;
+ }
+ else
+ {
+ int pos = FIND_VP(NULL);
+ if (pos != -1)
+ lbuf[pos] = vp;
+ };
+}
+
+
+static inline void DUMP_VP(void)
+{
+int pos;
+struct vnode *vp;
+for (pos = 0 ; pos < MAX_LVNODE; pos++)
+{
+ if (lbuf[pos] != NULL)
+ {
+ vp = lbuf[pos];
+ CTR6(KTR_SPARE3, "vp %p tag %s type %d flags %08x use count %d hold count %d", vp, vp->v_tag, vp->v_type, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
+ }
+}
+};
+
/*
* Initialize the vnode management data structures.
*/
@@ -305,6 +361,9 @@
desiredvnodes, MAXVNODES_MAX);
desiredvnodes = MAXVNODES_MAX;
}
+ memset(lbuf, MAX_LVNODE * (sizeof(struct vnode *)), 0);
+ lcnt = 0;
+
wantfreevnodes = desiredvnodes / 4;
mtx_init(&mntid_mtx, "mntid", NULL, MTX_DEF);
TAILQ_INIT(&vnode_free_list);
@@ -800,6 +859,7 @@
}
mtx_unlock(&mountlist_mtx);
if (done == 0) {
+ DUMP_VP();
EVENTHANDLER_INVOKE(vfs_lowvnodes, desiredvnodes / 10);
#if 0
/* These messages are temporary debugging aids */
@@ -864,6 +924,7 @@
lockdestroy(vp->v_vnlock);
mtx_destroy(&vp->v_interlock);
mtx_destroy(BO_MTX(bo));
+ DROP_VP(vp);
uma_zfree(vnode_zone, vp);
}
@@ -970,6 +1031,8 @@
numvnodes++;
mtx_unlock(&vnode_free_list_mtx);
vp = (struct vnode *) uma_zalloc(vnode_zone, M_WAITOK|M_ZERO);
+ ADD_VP(vp);
+
/*
* Setup locks.
*/
@@ -2299,6 +2362,12 @@
if (vp->v_holdcnt <= 0)
panic("vdrop: holdcnt %d", vp->v_holdcnt);
vp->v_holdcnt--;
+
+ if (vp->v_iflag & VI_DOOMED)
+ {
+ CTR5(KTR_SPARE4, "%s: vp %p flags %08x use count %d hold count %d", __func__, vp, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
+ }
+
if (vp->v_holdcnt == 0) {
if (vp->v_iflag & VI_DOOMED) {
CTR2(KTR_VFS, "%s: destroying the vnode %p", __func__,
@@ -2525,12 +2594,19 @@
("vgonel: vp %p has no reference.", vp));
CTR2(KTR_VFS, "%s: vp %p", __func__, vp);
td = curthread;
+
+
+ CTR5(KTR_SPARE4, "%s: vp %p flags %08x use count %d hold count %d", __func__, vp, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
/*
* Don't vgonel if we're already doomed.
*/
if (vp->v_iflag & VI_DOOMED)
+ {
+ CTR6(KTR_SPARE3, "already %p tag %s type %d flags %08x use count %d hold count %d", vp, vp->v_tag, vp->v_type, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
+
return;
+ }
vp->v_iflag |= VI_DOOMED;
/*
* Check to see if the vnode is in use. If so, we have to call
@@ -2554,12 +2630,22 @@
* deactivated before being reclaimed.
*/
if (active)
+ {
+ CTR6(KTR_SPARE3, "active1 %p tag %s type %d flags %08x use count %d hold count %d", vp, vp->v_tag, vp->v_type, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
+ vn_printf(vp, "a vnode ");
+
+ kdb_backtrace();
VOP_CLOSE(vp, FNONBLOCK, NOCRED, td);
+ }
if (oweinact || active) {
VI_LOCK(vp);
if ((vp->v_iflag & VI_DOINGINACT) == 0)
vinactive(vp, td);
VI_UNLOCK(vp);
+ CTR6(KTR_SPARE3, "active2 %p tag %s type %d flags %08x use count %d hold count %d", vp, vp->v_tag, vp->v_type, vp->v_iflag, vp->v_usecount, vp->v_holdcnt);
+ kdb_backtrace();
+
+
}
/*
* Reclaim the vnode.
@@ -2586,7 +2672,7 @@
VI_LOCK(vp);
vp->v_vnlock = &vp->v_lock;
vp->v_op = &dead_vnodeops;
- vp->v_tag = "none";
+// vp->v_tag = "none";
vp->v_type = VBAD;
}
@@ -2635,9 +2721,9 @@
va_start(ap, fmt);
vprintf(fmt, ap);
va_end(ap);
- printf("%p: ", (void *)vp);
- printf("tag %s, type %s\n", vp->v_tag, typename[vp->v_type]);
- printf(" usecount %d, writecount %d, refcount %d mountedhere %p\n",
+ db_printf("%p: ", (void *)vp);
+ db_printf("tag %s, type %s\n", vp->v_tag, typename[vp->v_type]);
+ db_printf(" usecount %d, writecount %d, refcount %d mountedhere %p\n",
vp->v_usecount, vp->v_writecount, vp->v_holdcnt, vp->v_mountedhere);
buf[0] = '\0';
buf[1] = '\0';
@@ -2688,14 +2774,14 @@
snprintf(buf2, sizeof(buf2), "|VI(0x%lx)", flags);
strlcat(buf, buf2, sizeof(buf));
}
- printf(" flags (%s)\n", buf + 1);
+ db_printf(" flags (%s)\n", buf + 1);
if (mtx_owned(VI_MTX(vp)))
- printf(" VI_LOCKed");
+ db_printf(" VI_LOCKed");
if (vp->v_object != NULL)
- printf(" v_object %p ref %d pages %d\n",
+ db_printf(" v_object %p ref %d pages %d\n",
vp->v_object, vp->v_object->ref_count,
vp->v_object->resident_page_count);
- printf(" ");
+ db_printf(" ");
lockmgr_printinfo(vp->v_vnlock);
if (vp->v_data != NULL)
VOP_PRINT(vp);
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?Pine.LNX.4.62.1004070838050.27621>