Better OSPF packet tracing log messages.

Replaces old OSPF packet tracing messages with
uniform messages with packet dumps.

7 files changed, 145 insertions, 27 deletions

diff --git a/proto/ospf/dbdes.c b/proto/ospf/dbdes.c
index 4cba667..4f7ebb7 100644
--- a/proto/ospf/dbdes.c
+++ b/proto/ospf/dbdes.c
@@ -8,6 +8,30 @@
 
 #include "ospf.h"
 
+  
+static void ospf_dump_dbdes(struct proto *p, struct ospf_dbdes_packet *pkt)
+{
+  struct ospf_packet *op = &pkt->ospf_packet;
+
+  ASSERT(op->type == DBDES_P);
+  ospf_dump_common(p, op);
+  log(L_TRACE "%s:     imms     %s%s%s",
+      p->name, pkt->imms.bit.ms ? "MS " : "",
+      pkt->imms.bit.m ? "M " : "",
+      pkt->imms.bit.i ? "I " : "" );
+  log(L_TRACE "%s:     ddseq    %u", p->name, ntohl(pkt->ddseq));
+
+  struct ospf_lsa_header *plsa = (void *) (pkt + 1);
+  int i, j;
+
+  j = (ntohs(op->length) - sizeof(struct ospf_dbdes_packet)) /
+    sizeof(struct ospf_lsa_header);
+
+  for (i = 0; i < j; i++)
+    ospf_dump_lsahdr(p, plsa + i);
+}
+
+
 /**
  * ospf_dbdes_send - transmit database description packet
  * @n: neighbor
@@ -45,9 +69,9 @@ ospf_dbdes_send(struct ospf_neighbor *n)
     pkt->ddseq = htonl(n->dds);
     length = sizeof(struct ospf_dbdes_packet);
     op->length = htons(length);
+
+    OSPF_PACKET(ospf_dump_dbdes, pkt, "DBDES packet sent to %I via %s", n->ip, ifa->iface->name);
     ospf_send_to(ifa->ip_sk, n->ip, ifa);
-    OSPF_TRACE(D_PACKETS, "DB_DES (I) sent to %I via %s.", n->ip,
-	       ifa->iface->name);
     break;
 
   case NEIGHBOR_EXCHANGE:
@@ -128,7 +152,6 @@ ospf_dbdes_send(struct ospf_neighbor *n)
 
   case NEIGHBOR_LOADING:
   case NEIGHBOR_FULL:
-    pkt = n->ldbdes;
     length = ntohs(((struct ospf_packet *) n->ldbdes)->length);
 
     if (!length)
@@ -138,18 +161,15 @@ ospf_dbdes_send(struct ospf_neighbor *n)
       return;
     }
 
-    memcpy(ifa->ip_sk->tbuf, n->ldbdes, length);
     /* Copy last sent packet again */
+    memcpy(ifa->ip_sk->tbuf, n->ldbdes, length);
 
+    OSPF_PACKET(ospf_dump_dbdes, (struct ospf_dbdes_packet *) ifa->ip_sk->tbuf,
+		"DBDES packet sent to %I via %s", n->ip, ifa->iface->name);
     ospf_send_to(ifa->ip_sk, n->ip, n->ifa);
 
     if(n->myimms.bit.ms) tm_start(n->rxmt_timer, n->ifa->rxmtint);		/* Restart timer */
 
-    OSPF_TRACE(D_PACKETS, "DB_DES (M) sent to %I via %s.", n->ip,
-	       ifa->iface->name);
-
-    DBG("DB_DES PS=%u, M=%u\n", ntohl(pkt->ddseq), pkt->imms.bit.m);
-
     if (!n->myimms.bit.ms)
     {
       if ((n->myimms.bit.m == 0) && (n->imms.bit.m == 0) &&
@@ -207,10 +227,7 @@ ospf_dbdes_receive(struct ospf_dbdes_packet *ps,
   u32 myrid = p->cf->global->router_id;
   unsigned int size = ntohs(ps->ospf_packet.length);
 
-  OSPF_TRACE(D_PACKETS, "Received dbdes from %I via %s.", n->ip,
-	     ifa->iface->name);
-
-  DBG("DB_DES PS=%u, M=%u SIZE=%u\n", ntohl(ps->ddseq), ps->imms.bit.m, size);
+  OSPF_PACKET(ospf_dump_dbdes, ps, "DBDES packet received from %I via %s", n->ip, ifa->iface->name);
 
   ospf_neigh_sm(n, INM_HELLOREC);
 
diff --git a/proto/ospf/hello.c b/proto/ospf/hello.c
index ce87431..c7d2027 100644
--- a/proto/ospf/hello.c
+++ b/proto/ospf/hello.c
@@ -19,7 +19,7 @@ ospf_hello_receive(struct ospf_hello_packet *ps,
   struct proto *p = (struct proto *) ifa->oa->po;
   unsigned int size = ntohs(ps->ospf_packet.length), i, twoway, oldpriority, eligible = 0, peers;
 
-  OSPF_TRACE(D_PACKETS, "Received hello from %I via %s%s", faddr,
+  OSPF_TRACE(D_PACKETS, "HELLO packet received from %I via %s%s", faddr,
       (ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name);
   mask = ps->netmask;
   ipa_ntoh(mask);
@@ -282,6 +282,7 @@ ospf_hello_send(timer * timer, int poll, struct ospf_neighbor *dirn)
     default:
       ospf_send_to(ifa->hello_sk, IPA_NONE, ifa);
   }
-  OSPF_TRACE(D_PACKETS, "Hello sent via %s%s",
-      (ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name);
+
+  OSPF_TRACE(D_PACKETS, "HELLO packet sent via %s%s",
+	     (ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name);
 }
diff --git a/proto/ospf/lsack.c b/proto/ospf/lsack.c
index bb1afa0..4652825 100644
--- a/proto/ospf/lsack.c
+++ b/proto/ospf/lsack.c
@@ -10,6 +10,25 @@
 
 char *s_queue[] = { "direct", "delayed" };
 
+
+static void ospf_dump_lsack(struct proto *p, struct ospf_lsack_packet *pkt)
+{
+  struct ospf_packet *op = &pkt->ospf_packet;
+
+  ASSERT(op->type == LSACK_P);
+  ospf_dump_common(p, op);
+
+  struct ospf_lsa_header *plsa = (void *) (pkt + 1);
+  int i, j;
+
+  j = (ntohs(op->length) - sizeof(struct ospf_lsack_packet)) /
+    sizeof(struct ospf_lsa_header);
+
+  for (i = 0; i < j; i++)
+    ospf_dump_lsahdr(p, plsa + i);
+}
+
+
 /*
  * =====================================
  * Note, that h is in network endianity!
@@ -42,8 +61,6 @@ ospf_lsack_send(struct ospf_neighbor *n, int queue)
   if (EMPTY_LIST(n->ackl[queue]))
     return;
 
-  OSPF_TRACE(D_PACKETS, "LS ack sent to %I (%s)", n->ip, s_queue[queue]);
-
   if (ifa->type == OSPF_IT_BCAST)
     sk = ifa->hello_sk;
   else
@@ -74,6 +91,10 @@ ospf_lsack_send(struct ospf_neighbor *n, int queue)
 	  i * sizeof(struct ospf_lsa_header);
 	op->length = htons(len);
 	DBG("Sending and continuing! Len=%u\n", len);
+
+	OSPF_PACKET(ospf_dump_lsack, (struct ospf_lsack_packet *) sk->tbuf,
+		    "LSACK packet sent via %s", ifa->iface->name);
+
 	if (ifa->type == OSPF_IT_BCAST)
 	{
 	  if ((ifa->state == OSPF_IS_DR) || (ifa->state == OSPF_IS_BACKUP))
@@ -98,6 +119,10 @@ ospf_lsack_send(struct ospf_neighbor *n, int queue)
   len = sizeof(struct ospf_lsack_packet) + i * sizeof(struct ospf_lsa_header);
   op->length = htons(len);
   DBG("Sending! Len=%u\n", len);
+
+  OSPF_PACKET(ospf_dump_lsack, (struct ospf_lsack_packet *) sk->tbuf,
+	      "LSACK packet sent via %s", ifa->iface->name);
+
   if (ifa->type == OSPF_IT_BCAST)
   {
     if ((ifa->state == OSPF_IS_DR) || (ifa->state == OSPF_IS_BACKUP))
@@ -125,7 +150,8 @@ ospf_lsack_receive(struct ospf_lsack_packet *ps,
   struct proto *p = &ifa->oa->po->proto;
   unsigned int size = ntohs(ps->ospf_packet.length), i;
 
-  OSPF_TRACE(D_PACKETS, "Received LS ack from %I", n->ip);
+  OSPF_PACKET(ospf_dump_lsack, ps, "LSACK packet received from %I via %s", n->ip, ifa->iface->name);
+
   ospf_neigh_sm(n, INM_HELLOREC);
 
   if (n->state < NEIGHBOR_EXCHANGE)
diff --git a/proto/ospf/lsreq.c b/proto/ospf/lsreq.c
index f43a08f..e179189 100644
--- a/proto/ospf/lsreq.c
+++ b/proto/ospf/lsreq.c
@@ -8,6 +8,24 @@
 
 #include "ospf.h"
 
+static void ospf_dump_lsreq(struct proto *p, struct ospf_lsreq_packet *pkt)
+{
+  struct ospf_packet *op = &pkt->ospf_packet;
+
+  ASSERT(op->type == LSREQ_P);
+  ospf_dump_common(p, op);
+
+  struct ospf_lsreq_header *plsr = (void *) (pkt + 1);
+  int i, j;
+
+  j = (ntohs(op->length) - sizeof(struct ospf_dbdes_packet)) /
+    sizeof(struct ospf_lsreq_header);
+
+  for (i = 0; i < j; i++)
+    log(L_TRACE "%s:     LSR      Id: %I, Rt: %I, Type: %u",
+	p->name, htonl(plsr[i].id), htonl(plsr[i].rt), plsr[i].type);
+}
+
 void
 ospf_lsreq_send(struct ospf_neighbor *n)
 {
@@ -59,8 +77,10 @@ ospf_lsreq_send(struct ospf_neighbor *n)
     sizeof(struct ospf_lsreq_packet) + (j -
 					i) * sizeof(struct ospf_lsreq_header);
   op->length = htons(length);
+
+  OSPF_PACKET(ospf_dump_lsreq, (struct ospf_lsreq_packet *) n->ifa->ip_sk->tbuf,
+	      "LSREQ packet sent to %I via %s", n->ip, n->ifa->iface->name);
   ospf_send_to(n->ifa->ip_sk, n->ip, n->ifa);
-  OSPF_TRACE(D_PACKETS, "LS request sent to: %I", n->rid);
 }
 
 void
@@ -77,10 +97,11 @@ ospf_lsreq_receive(struct ospf_lsreq_packet *ps,
   struct proto_ospf *po = oa->po;
   struct proto *p = &po->proto;
 
+  OSPF_PACKET(ospf_dump_lsreq, ps, "LSREQ packet received from %I via %s", n->ip, ifa->iface->name);
+
   if (n->state < NEIGHBOR_EXCHANGE)
     return;
 
-  OSPF_TRACE(D_EVENTS, "Received LS req from neighbor: %I", n->ip);
   ospf_neigh_sm(n, INM_HELLOREC);
 
   lsh = (void *) (ps + 1);
diff --git a/proto/ospf/lsupd.c b/proto/ospf/lsupd.c
index 76d4e6a..6b99728 100644
--- a/proto/ospf/lsupd.c
+++ b/proto/ospf/lsupd.c
@@ -8,6 +8,49 @@
 
 #include "ospf.h"
 
+
+void ospf_dump_lsahdr(struct proto *p, struct ospf_lsa_header *lsa_n)
+{
+  struct ospf_lsa_header lsa;
+  ntohlsah(lsa_n, &lsa);
+
+  log(L_TRACE "%s:     LSA      Id: %I, Rt: %I, Type: %u, Age: %u, Seqno: 0x%08x, Sum: %u",
+      p->name, lsa.id, lsa.rt, lsa.type, lsa.age, lsa.sn, lsa.checksum);
+}
+
+void ospf_dump_common(struct proto *p, struct ospf_packet *op)
+{
+  log(L_TRACE "%s:     length   %d", p->name, ntohs(op->length));
+  log(L_TRACE "%s:     router   %I", p->name, _MI(ntohl(op->routerid)));
+}
+
+static void ospf_dump_lsupd(struct proto *p, struct ospf_lsupd_packet *pkt)
+{
+  struct ospf_packet *op = &pkt->ospf_packet;
+
+  ASSERT(op->type == LSUPD_P);
+  ospf_dump_common(p, op);
+
+  u8 *pbuf= (u8 *) pkt;
+  int offset = sizeof(struct ospf_lsupd_packet);
+  int bound = ntohs(op->length) - sizeof(struct ospf_lsa_header);
+  int i, j;
+
+  j = ntohl(pkt->lsano);
+  for (i = 0; i < j; i++)
+    {
+      if (offset > bound)
+	{
+	  log(L_TRACE "%s:     LSA      invalid", p->name);
+	  return;
+	}
+
+      struct ospf_lsa_header *lsa = (void *) (pbuf + offset);
+      ospf_dump_lsahdr(p, lsa);
+      offset += ntohs(lsa->length);
+    }
+}
+
 /**
  * ospf_lsupd_flood - send received or generated lsa to the neighbors
  * @n: neighbor than sent this lsa (or NULL if generated)
@@ -187,9 +230,9 @@ ospf_lsupd_flood(struct ospf_neighbor *n, struct ospf_lsa_header *hn,
       lh->age = htons(age);
 
       op->length = htons(len);
-      OSPF_TRACE(D_PACKETS, "LS upd flooded via %s", ifa->iface->name);
-      DBG("ID=%I, AGE=%d, SEQ=%x\n", ntohl(lh->id), ntohs(lh->age),
-	  ntohl(lh->sn));
+
+      OSPF_PACKET(ospf_dump_lsupd,  (struct ospf_lsupd_packet *) sk->tbuf,
+		  "LSUPD packet flooded via %s", ifa->iface->name);
 
       switch (ifa->type)
       {
@@ -257,8 +300,9 @@ ospf_lsupd_send_list(struct ospf_neighbor *n, list * l)
       pk->lsano = htonl(lsano);
       op->length = htons(len);
 
+      OSPF_PACKET(ospf_dump_lsupd,  (struct ospf_lsupd_packet *) n->ifa->ip_sk->tbuf,
+		  "LSUPD packet sent to %I via %s", n->ip, n->ifa->iface->name);
       ospf_send_to(n->ifa->ip_sk, n->ip, n->ifa);
-      OSPF_TRACE(D_PACKETS, "LS upd sent to %I (%d LSAs)", n->ip, lsano);
 
       DBG("LSupd: next packet\n");
       ospf_pkt_fill_hdr(n->ifa, pk, LSUPD_P);
@@ -279,7 +323,8 @@ ospf_lsupd_send_list(struct ospf_neighbor *n, list * l)
     pk->lsano = htonl(lsano);
     op->length = htons(len);
 
-    OSPF_TRACE(D_PACKETS, "LS upd sent to %I (%d LSAs)", n->ip, lsano);
+    OSPF_PACKET(ospf_dump_lsupd,  (struct ospf_lsupd_packet *) n->ifa->ip_sk->tbuf,
+		"LSUPD packet sent to %I via %s", n->ip, n->ifa->iface->name);
     ospf_send_to(n->ifa->ip_sk, n->ip, n->ifa);
   }
 }
@@ -296,6 +341,8 @@ ospf_lsupd_receive(struct ospf_lsupd_packet *ps,
   struct proto *p = &po->proto;
   unsigned int i, sendreq = 1, size = ntohs(ps->ospf_packet.length);
 
+  OSPF_PACKET(ospf_dump_lsupd, ps, "LSUPD packet received from %I via %s", n->ip, ifa->iface->name);
+
   if (n->state < NEIGHBOR_EXCHANGE)
   {
     OSPF_TRACE(D_PACKETS,
@@ -311,7 +358,6 @@ ospf_lsupd_receive(struct ospf_lsupd_packet *ps,
     return;
   }
 
-  OSPF_TRACE(D_PACKETS, "Received LS upd from %I", n->ip);
   ospf_neigh_sm(n, INM_HELLOREC);	/* Questionable */
 
   lsa = (struct ospf_lsa_header *) (ps + 1);
diff --git a/proto/ospf/lsupd.h b/proto/ospf/lsupd.h
index 64d9aef..524a0a2 100644
--- a/proto/ospf/lsupd.h
+++ b/proto/ospf/lsupd.h
@@ -10,6 +10,8 @@
 #ifndef _BIRD_OSPF_LSUPD_H_
 #define _BIRD_OSPF_LSUPD_H_
 
+void ospf_dump_lsahdr(struct proto *p, struct ospf_lsa_header *lsa_n);
+void ospf_dump_common(struct proto *p, struct ospf_packet *op);
 void ospf_lsupd_send_list(struct ospf_neighbor *n, list * l);
 void ospf_lsupd_receive(struct ospf_lsupd_packet *ps,
 			struct ospf_iface *ifa, struct ospf_neighbor *n);
diff --git a/proto/ospf/ospf.h b/proto/ospf/ospf.h
index fcefa81..4e37c18 100644
--- a/proto/ospf/ospf.h
+++ b/proto/ospf/ospf.h
@@ -26,6 +26,11 @@
 #define OSPF_TRACE(flags, msg, args...) do { if ((p->debug & flags) || OSPF_FORCE_DEBUG) \
   log(L_TRACE "%s: " msg, p->name , ## args ); } while(0)
 
+#define OSPF_PACKET(dumpfn, buffer, msg, args...) \
+do { if ((p->debug & D_PACKETS) || OSPF_FORCE_DEBUG) \
+{ log(L_TRACE "%s: " msg, p->name, ## args ); dumpfn(p, buffer); } } while(0)
+
+
 #include "nest/bird.h"
 
 #include "lib/checksum.h"