From 8298d780be5a5b00c31c10a37a5f3a1353d6e234 Mon Sep 17 00:00:00 2001 From: Ondrej Zajicek Date: Mon, 6 Apr 2009 16:17:47 +0200 Subject: [PATCH] Better OSPF packet tracing log messages. Replaces old OSPF packet tracing messages with uniform messages with packet dumps. --- proto/ospf/dbdes.c | 43 +++++++++++++++++++++++----------- proto/ospf/hello.c | 7 +++--- proto/ospf/lsack.c | 32 ++++++++++++++++++++++--- proto/ospf/lsreq.c | 25 ++++++++++++++++++-- proto/ospf/lsupd.c | 58 +++++++++++++++++++++++++++++++++++++++++----- proto/ospf/lsupd.h | 2 ++ proto/ospf/ospf.h | 5 ++++ 7 files changed, 145 insertions(+), 27 deletions(-) diff --git a/proto/ospf/dbdes.c b/proto/ospf/dbdes.c index 4cba667c..4f7ebb7a 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 ce87431b..c7d20273 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 bb1afa0a..46528257 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 f43a08fe..e179189e 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 76d4e6ae..6b99728c 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 64d9aeff..524a0a2d 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 fcefa813..4e37c184 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"