Better OSPF packet tracing log messages.

Replaces old OSPF packet tracing messages with
uniform messages with packet dumps.
This commit is contained in:
Ondrej Zajicek 2009-04-06 16:17:47 +02:00
parent bcb81251b4
commit 8298d780be
7 changed files with 145 additions and 27 deletions

View file

@ -8,6 +8,30 @@
#include "ospf.h" #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 * ospf_dbdes_send - transmit database description packet
* @n: neighbor * @n: neighbor
@ -45,9 +69,9 @@ ospf_dbdes_send(struct ospf_neighbor *n)
pkt->ddseq = htonl(n->dds); pkt->ddseq = htonl(n->dds);
length = sizeof(struct ospf_dbdes_packet); length = sizeof(struct ospf_dbdes_packet);
op->length = htons(length); 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_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; break;
case NEIGHBOR_EXCHANGE: case NEIGHBOR_EXCHANGE:
@ -128,7 +152,6 @@ ospf_dbdes_send(struct ospf_neighbor *n)
case NEIGHBOR_LOADING: case NEIGHBOR_LOADING:
case NEIGHBOR_FULL: case NEIGHBOR_FULL:
pkt = n->ldbdes;
length = ntohs(((struct ospf_packet *) n->ldbdes)->length); length = ntohs(((struct ospf_packet *) n->ldbdes)->length);
if (!length) if (!length)
@ -138,18 +161,15 @@ ospf_dbdes_send(struct ospf_neighbor *n)
return; return;
} }
memcpy(ifa->ip_sk->tbuf, n->ldbdes, length);
/* Copy last sent packet again */ /* 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); 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 */ 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.ms)
{ {
if ((n->myimms.bit.m == 0) && (n->imms.bit.m == 0) && 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; u32 myrid = p->cf->global->router_id;
unsigned int size = ntohs(ps->ospf_packet.length); unsigned int size = ntohs(ps->ospf_packet.length);
OSPF_TRACE(D_PACKETS, "Received dbdes from %I via %s.", n->ip, OSPF_PACKET(ospf_dump_dbdes, ps, "DBDES packet received from %I via %s", n->ip, ifa->iface->name);
ifa->iface->name);
DBG("DB_DES PS=%u, M=%u SIZE=%u\n", ntohl(ps->ddseq), ps->imms.bit.m, size);
ospf_neigh_sm(n, INM_HELLOREC); ospf_neigh_sm(n, INM_HELLOREC);

View file

@ -19,7 +19,7 @@ ospf_hello_receive(struct ospf_hello_packet *ps,
struct proto *p = (struct proto *) ifa->oa->po; struct proto *p = (struct proto *) ifa->oa->po;
unsigned int size = ntohs(ps->ospf_packet.length), i, twoway, oldpriority, eligible = 0, peers; 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); (ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name);
mask = ps->netmask; mask = ps->netmask;
ipa_ntoh(mask); ipa_ntoh(mask);
@ -282,6 +282,7 @@ ospf_hello_send(timer * timer, int poll, struct ospf_neighbor *dirn)
default: default:
ospf_send_to(ifa->hello_sk, IPA_NONE, ifa); ospf_send_to(ifa->hello_sk, IPA_NONE, ifa);
} }
OSPF_TRACE(D_PACKETS, "Hello sent via %s%s",
OSPF_TRACE(D_PACKETS, "HELLO packet sent via %s%s",
(ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name); (ifa->type == OSPF_IT_VLINK ? "vlink-" : ""), ifa->iface->name);
} }

View file

@ -10,6 +10,25 @@
char *s_queue[] = { "direct", "delayed" }; 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! * 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])) if (EMPTY_LIST(n->ackl[queue]))
return; return;
OSPF_TRACE(D_PACKETS, "LS ack sent to %I (%s)", n->ip, s_queue[queue]);
if (ifa->type == OSPF_IT_BCAST) if (ifa->type == OSPF_IT_BCAST)
sk = ifa->hello_sk; sk = ifa->hello_sk;
else else
@ -74,6 +91,10 @@ ospf_lsack_send(struct ospf_neighbor *n, int queue)
i * sizeof(struct ospf_lsa_header); i * sizeof(struct ospf_lsa_header);
op->length = htons(len); op->length = htons(len);
DBG("Sending and continuing! Len=%u\n", 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->type == OSPF_IT_BCAST)
{ {
if ((ifa->state == OSPF_IS_DR) || (ifa->state == OSPF_IS_BACKUP)) 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); len = sizeof(struct ospf_lsack_packet) + i * sizeof(struct ospf_lsa_header);
op->length = htons(len); op->length = htons(len);
DBG("Sending! Len=%u\n", 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->type == OSPF_IT_BCAST)
{ {
if ((ifa->state == OSPF_IS_DR) || (ifa->state == OSPF_IS_BACKUP)) 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; struct proto *p = &ifa->oa->po->proto;
unsigned int size = ntohs(ps->ospf_packet.length), i; 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); ospf_neigh_sm(n, INM_HELLOREC);
if (n->state < NEIGHBOR_EXCHANGE) if (n->state < NEIGHBOR_EXCHANGE)

View file

@ -8,6 +8,24 @@
#include "ospf.h" #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 void
ospf_lsreq_send(struct ospf_neighbor *n) ospf_lsreq_send(struct ospf_neighbor *n)
{ {
@ -59,8 +77,10 @@ ospf_lsreq_send(struct ospf_neighbor *n)
sizeof(struct ospf_lsreq_packet) + (j - sizeof(struct ospf_lsreq_packet) + (j -
i) * sizeof(struct ospf_lsreq_header); i) * sizeof(struct ospf_lsreq_header);
op->length = htons(length); 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_send_to(n->ifa->ip_sk, n->ip, n->ifa);
OSPF_TRACE(D_PACKETS, "LS request sent to: %I", n->rid);
} }
void void
@ -77,10 +97,11 @@ ospf_lsreq_receive(struct ospf_lsreq_packet *ps,
struct proto_ospf *po = oa->po; struct proto_ospf *po = oa->po;
struct proto *p = &po->proto; 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) if (n->state < NEIGHBOR_EXCHANGE)
return; return;
OSPF_TRACE(D_EVENTS, "Received LS req from neighbor: %I", n->ip);
ospf_neigh_sm(n, INM_HELLOREC); ospf_neigh_sm(n, INM_HELLOREC);
lsh = (void *) (ps + 1); lsh = (void *) (ps + 1);

View file

@ -8,6 +8,49 @@
#include "ospf.h" #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 * ospf_lsupd_flood - send received or generated lsa to the neighbors
* @n: neighbor than sent this lsa (or NULL if generated) * @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); lh->age = htons(age);
op->length = htons(len); 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), OSPF_PACKET(ospf_dump_lsupd, (struct ospf_lsupd_packet *) sk->tbuf,
ntohl(lh->sn)); "LSUPD packet flooded via %s", ifa->iface->name);
switch (ifa->type) switch (ifa->type)
{ {
@ -257,8 +300,9 @@ ospf_lsupd_send_list(struct ospf_neighbor *n, list * l)
pk->lsano = htonl(lsano); pk->lsano = htonl(lsano);
op->length = htons(len); 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_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"); DBG("LSupd: next packet\n");
ospf_pkt_fill_hdr(n->ifa, pk, LSUPD_P); 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); pk->lsano = htonl(lsano);
op->length = htons(len); 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); 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; struct proto *p = &po->proto;
unsigned int i, sendreq = 1, size = ntohs(ps->ospf_packet.length); 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) if (n->state < NEIGHBOR_EXCHANGE)
{ {
OSPF_TRACE(D_PACKETS, OSPF_TRACE(D_PACKETS,
@ -311,7 +358,6 @@ ospf_lsupd_receive(struct ospf_lsupd_packet *ps,
return; return;
} }
OSPF_TRACE(D_PACKETS, "Received LS upd from %I", n->ip);
ospf_neigh_sm(n, INM_HELLOREC); /* Questionable */ ospf_neigh_sm(n, INM_HELLOREC); /* Questionable */
lsa = (struct ospf_lsa_header *) (ps + 1); lsa = (struct ospf_lsa_header *) (ps + 1);

View file

@ -10,6 +10,8 @@
#ifndef _BIRD_OSPF_LSUPD_H_ #ifndef _BIRD_OSPF_LSUPD_H_
#define _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_send_list(struct ospf_neighbor *n, list * l);
void ospf_lsupd_receive(struct ospf_lsupd_packet *ps, void ospf_lsupd_receive(struct ospf_lsupd_packet *ps,
struct ospf_iface *ifa, struct ospf_neighbor *n); struct ospf_iface *ifa, struct ospf_neighbor *n);

View file

@ -26,6 +26,11 @@
#define OSPF_TRACE(flags, msg, args...) do { if ((p->debug & flags) || OSPF_FORCE_DEBUG) \ #define OSPF_TRACE(flags, msg, args...) do { if ((p->debug & flags) || OSPF_FORCE_DEBUG) \
log(L_TRACE "%s: " msg, p->name , ## args ); } while(0) 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 "nest/bird.h"
#include "lib/checksum.h" #include "lib/checksum.h"