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

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);
_______________________________________________
[email protected] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-hackers
To unsubscribe, send any mail to "[email protected]"

Reply via email to