Add ktr(9) hooks to easier tracing of the netgraph item flow through

netgraph.

1 files changed, 36 insertions, 2 deletions

diff --git a/sys/netgraph/ng_base.c b/sys/netgraph/ng_base.c
index 4350f86..b9bc290 100644
--- a/sys/netgraph/ng_base.c
+++ b/sys/netgraph/ng_base.c
@@ -52,6 +52,7 @@
 #include <sys/errno.h>
 #include <sys/kdb.h>
 #include <sys/kernel.h>
+#include <sys/ktr.h>
 #include <sys/limits.h>
 #include <sys/malloc.h>
 #include <sys/mbuf.h>
@@ -1828,6 +1829,8 @@ ng_dequeue(struct ng_queue *ngq, int *rw)
 	 * XXXGL: assert this?
 	 */
 	if (!QUEUE_ACTIVE(ngq)) {
+		CTR3(KTR_NET, "%s: node %p queue empty; queue flags 0x%lx",
+		    __func__, ngq->q_node, ngq->q_flags);
 		return (NULL);
 	}
 
@@ -1844,6 +1847,9 @@ ng_dequeue(struct ng_queue *ngq, int *rw)
 			 * get called again until something changes.
 			 */
 			ng_worklist_remove(ngq->q_node);
+			CTR3(KTR_NET, "%s: node %p queued reader can't proceed;"
+			    " queue flags 0x%lx",
+			    __func__, ngq->q_node, ngq->q_flags);
 			return (NULL);
 		}
 		/*
@@ -1910,6 +1916,9 @@ ng_dequeue(struct ng_queue *ngq, int *rw)
 		 * would be a waste of effort to do all this again.
 		 */
 		ng_worklist_remove(ngq->q_node);
+		CTR3(KTR_NET, "%s: node %p can't dequeue anything;"
+		    " queue flags 0x%lx",
+		    __func__, ngq->q_node, ngq->q_flags);
 		return (NULL);
 	}
 
@@ -1919,6 +1928,9 @@ ng_dequeue(struct ng_queue *ngq, int *rw)
 	 */
 	item = ngq->queue;
 	ngq->queue = item->el_next;
+	CTR5(KTR_NET, "%s: node %p dequeued item %p with flags 0x%lx;"
+	    " queue flags 0x%lx",
+	    __func__, ngq->q_node, item, item->el_flags, ngq->q_flags);
 	if (ngq->last == &(item->el_next)) {
 		/*
 		 * that was the last entry in the queue so set the 'last
@@ -1949,6 +1961,9 @@ ng_dequeue(struct ng_queue *ngq, int *rw)
 			ng_setisr(ngq->q_node);
 		}
 	}
+	CTR5(KTR_NET, "%s: node %p returning item %p as %s; queue flags 0x%lx",
+	    __func__, ngq->q_node, item, *rw ? "WRITER" : "READER" ,
+	    ngq->q_flags);
 	return (item);
 }
 
@@ -1969,12 +1984,17 @@ ng_queue_rw(struct ng_queue * ngq, item_p  item, int rw)
 		NGI_SET_READER(item);
 	item->el_next = NULL;	/* maybe not needed */
 	*ngq->last = item;
+	CTR4(KTR_NET, "%s: node %p queued item %p as %s",
+	    __func__, ngq->q_node, item, rw ? "WRITER" : "READER" );
 	/*
 	 * If it was the first item in the queue then we need to
 	 * set the last pointer and the type flags.
 	 */
-	if (ngq->last == &(ngq->queue))
+	if (ngq->last == &(ngq->queue)) {
 		atomic_add_long(&ngq->q_flags, OP_PENDING);
+		CTR2(KTR_NET, "%s: node %p set OP_PENDING",
+		    __func__, ngq->q_node);
+	}
 
 	ngq->last = &(item->el_next);
 	/*
@@ -2014,6 +2034,8 @@ ng_acquire_read(struct ng_queue *ngq, item_p item)
 	atomic_add_long(&ngq->q_flags, READER_INCREMENT);
 	if ((ngq->q_flags & NGQ_RMASK) == 0) {
 		/* Successfully grabbed node */
+		CTR3(KTR_NET, "%s: node %p fast acquired item %p",
+		    __func__, ngq->q_node, item);
 		return (item);
 	}
 	/* undo the damage if we didn't succeed */
@@ -2032,6 +2054,8 @@ ng_acquire_read(struct ng_queue *ngq, item_p item)
 	if ((ngq->q_flags & NGQ_RMASK) == 0) {
 		atomic_add_long(&ngq->q_flags, READER_INCREMENT);
 		mtx_unlock_spin((&ngq->q_mtx));
+		CTR3(KTR_NET, "%s: node %p slow acquired item %p",
+		    __func__, ngq->q_node, item);
 		return (item);
 	}
 
@@ -2066,6 +2090,8 @@ restart:
 			atomic_subtract_long(&ngq->q_flags, WRITER_ACTIVE);
 			goto restart;
 		}
+		CTR3(KTR_NET, "%s: node %p acquired item %p",
+		    __func__, ngq->q_node, item);
 		return (item);
 	}
 
@@ -3229,6 +3255,7 @@ ngintr(void)
 		node->nd_flags &= ~NGF_WORKQ;	
 		TAILQ_REMOVE(&ng_worklist, node, nd_work);
 		mtx_unlock_spin(&ng_worklist_mtx);
+		CTR2(KTR_NET, "%s: node %p taken off worklist", __func__, node);
 		/*
 		 * We have the node. We also take over the reference
 		 * that the list had on it.
@@ -3264,12 +3291,16 @@ ngintr(void)
 static void
 ng_worklist_remove(node_p node)
 {
+	mtx_assert(&node->nd_input_queue.q_mtx, MA_OWNED);
+
 	mtx_lock_spin(&ng_worklist_mtx);
 	if (node->nd_flags & NGF_WORKQ) {
 		node->nd_flags &= ~NGF_WORKQ;
 		TAILQ_REMOVE(&ng_worklist, node, nd_work);
 		mtx_unlock_spin(&ng_worklist_mtx);
 		NG_NODE_UNREF(node);
+		CTR2(KTR_NET, "%s: node %p removed off worklist",
+		    __func__, node);
 	} else {
 		mtx_unlock_spin(&ng_worklist_mtx);
 	}
@@ -3296,7 +3327,10 @@ ng_setisr(node_p node)
 		TAILQ_INSERT_TAIL(&ng_worklist, node, nd_work);
 		mtx_unlock_spin(&ng_worklist_mtx);
 		NG_NODE_REF(node); /* XXX fafe in mutex? */
-	}
+		CTR2(KTR_NET, "%s: node %p put on worklist", __func__, node);
+	} else
+		CTR2(KTR_NET, "%s: node %p already on worklist",
+		    __func__, node);
 	schednetisr(NETISR_NETGRAPH);
 }