zebra: factor out rib debug logs

Introduces a logging function that takes a struct route_node * argument,
and prefixes log output with that node's prefix.  While this removes
some duplication, it will also later be useful for srcdest route nodes.

Behaviour before and after the patch should be exactly identical.

Signed-off-by: David Lamparter <equinox@opensourcerouting.org>
diff --git a/zebra/zebra_rib.c b/zebra/zebra_rib.c
index 245011e..4ee1a84 100644
--- a/zebra/zebra_rib.c
+++ b/zebra/zebra_rib.c
@@ -75,6 +75,37 @@
 /* Vector for routing table.  */
 static vector vrf_vector;
 
+static void
+_rnode_zlog(const char *_func, struct route_node *rn, int priority,
+	    const char *msgfmt, ...)
+{
+  char buf[INET6_ADDRSTRLEN + 4], *bptr;
+  char msgbuf[512];
+  va_list ap;
+
+  va_start(ap, msgfmt);
+  vsnprintf(msgbuf, sizeof(msgbuf), msgfmt, ap);
+  va_end(ap);
+
+  if (rn)
+    {
+      inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
+      bptr = buf + strlen(buf);
+      snprintf(bptr, buf + sizeof(buf) - bptr, "/%d", rn->p.prefixlen);
+    }
+  else
+    {
+      snprintf(buf, sizeof(buf), "{(route_node *) NULL}");
+    }
+
+  zlog (NULL, priority, "%s: %s: %s", _func, buf, msgbuf);
+}
+
+#define rnode_debug(node, ...) \
+	_rnode_zlog(__func__, node, LOG_DEBUG, __VA_ARGS__)
+#define rnode_info(node, ...) \
+	_rnode_zlog(__func__, node, LOG_INFO, __VA_ARGS__)
+
 /*
  * vrf_table_create
  */
@@ -1209,7 +1240,6 @@
 rib_gc_dest (struct route_node *rn)
 {
   rib_dest_t *dest;
-  char buf[INET6_ADDRSTRLEN];
 
   dest = rib_dest_from_rnode (rn);
   if (!dest)
@@ -1219,11 +1249,7 @@
     return 0;
 
   if (IS_ZEBRA_DEBUG_RIB)
-    {
-      inet_ntop (rn->p.family, &rn->p.u.prefix, buf, sizeof (buf));
-      zlog_debug ("%s: %s/%d: removing dest from table", __func__,
-		  buf, rn->p.prefixlen);
-    }
+    rnode_debug (rn, "removing dest from table");
 
   dest->rnode = NULL;
   XFREE (MTYPE_RIB_DEST, dest);
@@ -1248,16 +1274,12 @@
   int installed = 0;
   struct nexthop *nexthop = NULL, *tnexthop;
   int recursing;
-  char buf[INET6_ADDRSTRLEN];
   rib_table_info_t *info;
 
   assert (rn);
 
   info = rn->table->info;
 
-  if (IS_ZEBRA_DEBUG_RIB || IS_ZEBRA_DEBUG_RIB_Q)
-    inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
-
   RNODE_FOREACH_RIB_SAFE (rn, rib, next)
     {
       /* Currently installed rib. */
@@ -1275,8 +1297,7 @@
           if (rib != fib)
             {
               if (IS_ZEBRA_DEBUG_RIB)
-                zlog_debug ("%s: %s/%d: rn %p, removing rib %p", __func__,
-                  buf, rn->p.prefixlen, rn, rib);
+		rnode_debug (rn, "rn %p, removing rib %p", rn, rib);
 	      rib_unlink (rn, rib);
             }
           else
@@ -1350,8 +1371,8 @@
   if (select && select == fib)
     {
       if (IS_ZEBRA_DEBUG_RIB)
-        zlog_debug ("%s: %s/%d: Updating existing route, select %p, fib %p",
-                     __func__, buf, rn->p.prefixlen, select, fib);
+	rnode_debug (rn, "Updating existing route, select %p, fib %p",
+		     select, fib);
       if (CHECK_FLAG (select->flags, ZEBRA_FLAG_CHANGED))
         {
 	  zfpm_trigger_update (rn, "updating existing route");
@@ -1395,8 +1416,7 @@
   if (fib)
     {
       if (IS_ZEBRA_DEBUG_RIB)
-        zlog_debug ("%s: %s/%d: Removing existing route, fib %p", __func__,
-          buf, rn->p.prefixlen, fib);
+	rnode_debug (rn, "Removing existing route, fib %p", fib);
 
       zfpm_trigger_update (rn, "removing existing route");
 
@@ -1416,8 +1436,7 @@
   if (select)
     {
       if (IS_ZEBRA_DEBUG_RIB)
-        zlog_debug ("%s: %s/%d: Adding route, select %p", __func__, buf,
-          rn->p.prefixlen, select);
+	rnode_debug (rn, "Adding route, select %p", select);
 
       zfpm_trigger_update (rn, "new route selected");
 
@@ -1434,14 +1453,13 @@
   if (del)
     {
       if (IS_ZEBRA_DEBUG_RIB)
-        zlog_debug ("%s: %s/%d: Deleting fib %p, rn %p", __func__, buf,
-          rn->p.prefixlen, del, rn);
+        rnode_debug (rn, "Deleting fib %p, rn %p", del, rn);
       rib_unlink (rn, del);
     }
 
 end:
   if (IS_ZEBRA_DEBUG_RIB_Q)
-    zlog_debug ("%s: %s/%d: rn %p dequeued", __func__, buf, rn->p.prefixlen, rn);
+    rnode_debug (rn, "rn %p dequeued", rn);
 
   /*
    * Check if the dest can be deleted now.
@@ -1525,10 +1543,6 @@
 rib_meta_queue_add (struct meta_queue *mq, struct route_node *rn)
 {
   struct rib *rib;
-  char buf[INET6_ADDRSTRLEN];
-
-  if (IS_ZEBRA_DEBUG_RIB_Q)
-    inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
 
   RNODE_FOREACH_RIB (rn, rib)
     {
@@ -1539,8 +1553,8 @@
 		      RIB_ROUTE_QUEUED (qindex)))
 	{
 	  if (IS_ZEBRA_DEBUG_RIB_Q)
-	    zlog_debug ("%s: %s/%d: rn %p is already queued in sub-queue %u",
-			__func__, buf, rn->p.prefixlen, rn, qindex);
+	    rnode_debug (rn, "rn %p is already queued in sub-queue %u",
+			 rn, qindex);
 	  continue;
 	}
 
@@ -1550,8 +1564,8 @@
       mq->size++;
 
       if (IS_ZEBRA_DEBUG_RIB_Q)
-	zlog_debug ("%s: %s/%d: queued rn %p into sub-queue %u",
-		    __func__, buf, rn->p.prefixlen, rn, qindex);
+	rnode_debug (rn, "queued rn %p into sub-queue %u",
+		     rn, qindex);
     }
 }
 
@@ -1559,11 +1573,7 @@
 static void
 rib_queue_add (struct zebra_t *zebra, struct route_node *rn)
 {
-  char buf[INET_ADDRSTRLEN];
   assert (zebra && rn);
-  
-  if (IS_ZEBRA_DEBUG_RIB_Q)
-    inet_ntop (AF_INET, &rn->p.u.prefix, buf, INET_ADDRSTRLEN);
 
   /* Pointless to queue a route_node with no RIB entries to add or remove */
   if (!rnode_to_ribs (rn))
@@ -1575,7 +1585,7 @@
     }
 
   if (IS_ZEBRA_DEBUG_RIB_Q)
-    zlog_info ("%s: %s/%d: work queue added", __func__, buf, rn->p.prefixlen);
+    rnode_info (rn, "work queue added");
 
   assert (zebra);
 
@@ -1599,7 +1609,7 @@
   rib_meta_queue_add (zebra->mq, rn);
 
   if (IS_ZEBRA_DEBUG_RIB_Q)
-    zlog_debug ("%s: %s/%d: rn %p queued", __func__, buf, rn->p.prefixlen, rn);
+    rnode_debug (rn, "rn %p queued", rn);
 
   return;
 }
@@ -1696,25 +1706,17 @@
 {
   struct rib *head;
   rib_dest_t *dest;
-  char buf[INET6_ADDRSTRLEN];
 
   assert (rib && rn);
   
   if (IS_ZEBRA_DEBUG_RIB)
-  {
-    inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
-    zlog_debug ("%s: %s/%d: rn %p, rib %p", __func__,
-      buf, rn->p.prefixlen, rn, rib);
-  }
+    rnode_debug (rn, "rn %p, rib %p", rn, rib);
 
   dest = rib_dest_from_rnode (rn);
   if (!dest)
     {
       if (IS_ZEBRA_DEBUG_RIB)
-	{
-	  zlog_debug ("%s: %s/%d: adding dest to table", __func__,
-		      buf, rn->p.prefixlen);
-	}
+	rnode_debug (rn, "adding dest to table");
 
       dest = XCALLOC (MTYPE_RIB_DEST, sizeof (rib_dest_t));
       route_lock_node (rn); /* rn route table reference */
@@ -1741,12 +1743,8 @@
   if (CHECK_FLAG (rib->status, RIB_ENTRY_REMOVED))
     {
       if (IS_ZEBRA_DEBUG_RIB)
-      {
-        char buf[INET6_ADDRSTRLEN];
-        inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
-        zlog_debug ("%s: %s/%d: rn %p, un-removed rib %p",
-                    __func__, buf, rn->p.prefixlen, rn, rib);
-      }
+        rnode_debug (rn, "rn %p, un-removed rib %p", rn, rib);
+
       UNSET_FLAG (rib->status, RIB_ENTRY_REMOVED);
       return;
     }
@@ -1765,17 +1763,12 @@
 static void
 rib_unlink (struct route_node *rn, struct rib *rib)
 {
-  char buf[INET6_ADDRSTRLEN];
   rib_dest_t *dest;
 
   assert (rn && rib);
 
   if (IS_ZEBRA_DEBUG_RIB)
-  {
-    inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
-    zlog_debug ("%s: %s/%d: rn %p, rib %p",
-                __func__, buf, rn->p.prefixlen, rn, rib);
-  }
+    rnode_debug (rn, "rn %p, rib %p", rn, rib);
 
   dest = rib_dest_from_rnode (rn);
 
@@ -1799,12 +1792,7 @@
 rib_delnode (struct route_node *rn, struct rib *rib)
 {
   if (IS_ZEBRA_DEBUG_RIB)
-  {
-    char buf[INET6_ADDRSTRLEN];
-    inet_ntop (rn->p.family, &rn->p.u.prefix, buf, INET6_ADDRSTRLEN);
-    zlog_debug ("%s: %s/%d: rn %p, rib %p, removing", __func__,
-      buf, rn->p.prefixlen, rn, rib);
-  }
+    rnode_debug (rn, "rn %p, rib %p, removing", rn, rib);
   SET_FLAG (rib->status, RIB_ENTRY_REMOVED);
   rib_queue_add (&zebrad, rn);
 }