Commit 85368cd4 authored by Martin Mareš's avatar Martin Mareš

Full protocol tracing.

parent 85a291ff
...@@ -6,7 +6,7 @@ ...@@ -6,7 +6,7 @@
* Can be freely distributed and used under the terms of the GNU GPL. * Can be freely distributed and used under the terms of the GNU GPL.
*/ */
#define LOCAL_DEBUG #undef LOCAL_DEBUG
#include <stdlib.h> #include <stdlib.h>
...@@ -280,14 +280,14 @@ bgp_new_bucket(struct bgp_proto *p, ea_list *new, unsigned hash) ...@@ -280,14 +280,14 @@ bgp_new_bucket(struct bgp_proto *p, ea_list *new, unsigned hash)
/* Copy values of non-inline attributes */ /* Copy values of non-inline attributes */
for (i=0; i<new->count; i++) for (i=0; i<new->count; i++)
{ {
eattr *a = &new->attrs[i]; eattr *a = &b->eattrs->attrs[i];
if (!(a->type & EAF_EMBEDDED)) if (!(a->type & EAF_EMBEDDED))
{ {
struct adata *oa = a->u.ptr; struct adata *oa = a->u.ptr;
struct adata *na = (struct adata *) dest; struct adata *na = (struct adata *) dest;
memcpy(na, oa, sizeof(struct adata) + oa->length); memcpy(na, oa, sizeof(struct adata) + oa->length);
a->u.ptr = na; a->u.ptr = na;
dest += ALIGN(na->length, CPU_STRUCT_ALIGN); dest += ALIGN(sizeof(struct adata) + na->length, CPU_STRUCT_ALIGN);
} }
} }
......
...@@ -6,7 +6,7 @@ ...@@ -6,7 +6,7 @@
* Can be freely distributed and used under the terms of the GNU GPL. * Can be freely distributed and used under the terms of the GNU GPL.
*/ */
#define LOCAL_DEBUG #undef LOCAL_DEBUG
#include "nest/bird.h" #include "nest/bird.h"
#include "nest/iface.h" #include "nest/iface.h"
...@@ -135,8 +135,9 @@ static void ...@@ -135,8 +135,9 @@ static void
bgp_connected(sock *sk) bgp_connected(sock *sk)
{ {
struct bgp_conn *conn = sk->data; struct bgp_conn *conn = sk->data;
struct bgp_proto *p = conn->bgp;
DBG("BGP: Connected\n"); BGP_TRACE(D_EVENTS, "Connected");
bgp_send_open(conn); bgp_send_open(conn);
} }
...@@ -144,18 +145,20 @@ static void ...@@ -144,18 +145,20 @@ static void
bgp_connect_timeout(timer *t) bgp_connect_timeout(timer *t)
{ {
struct bgp_conn *conn = t->data; struct bgp_conn *conn = t->data;
struct bgp_proto *p = conn->bgp;
DBG("BGP: Connect timeout, retrying\n"); DBG("BGP: connect_timeout\n");
bgp_close_conn(conn); bgp_close_conn(conn);
bgp_connect(conn->bgp); bgp_connect(p);
} }
static void static void
bgp_sock_err(sock *sk, int err) bgp_sock_err(sock *sk, int err)
{ {
struct bgp_conn *conn = sk->data; struct bgp_conn *conn = sk->data;
struct bgp_proto *p = conn->bgp;
DBG("BGP: Socket error %d in state %d\n", err, conn->state); BGP_TRACE(D_EVENTS, "Connection closed (socket error %d)", err);
switch (conn->state) switch (conn->state)
{ {
case BS_CONNECT: case BS_CONNECT:
...@@ -163,7 +166,7 @@ bgp_sock_err(sock *sk, int err) ...@@ -163,7 +166,7 @@ bgp_sock_err(sock *sk, int err)
sk_close(conn->sk); sk_close(conn->sk);
conn->sk = NULL; conn->sk = NULL;
conn->state = BS_ACTIVE; conn->state = BS_ACTIVE;
bgp_start_timer(conn->connect_retry_timer, conn->bgp->cf->connect_retry_time); bgp_start_timer(conn->connect_retry_timer, p->cf->connect_retry_time);
break; break;
case BS_OPENCONFIRM: case BS_OPENCONFIRM:
case BS_ESTABLISHED: case BS_ESTABLISHED:
...@@ -242,6 +245,7 @@ bgp_connect(struct bgp_proto *p) /* Enter Connect state and start establishing c ...@@ -242,6 +245,7 @@ bgp_connect(struct bgp_proto *p) /* Enter Connect state and start establishing c
s->saddr = p->local_addr; s->saddr = p->local_addr;
s->daddr = p->cf->remote_ip; s->daddr = p->cf->remote_ip;
s->dport = BGP_PORT; s->dport = BGP_PORT;
BGP_TRACE(D_EVENTS, "Connecting to %I from local address %I", s->daddr, s->saddr);
bgp_setup_conn(p, conn); bgp_setup_conn(p, conn);
bgp_setup_sk(p, conn, s); bgp_setup_sk(p, conn, s);
s->tx_hook = bgp_connected; s->tx_hook = bgp_connected;
...@@ -265,7 +269,7 @@ bgp_initiate(struct bgp_proto *p) ...@@ -265,7 +269,7 @@ bgp_initiate(struct bgp_proto *p)
delay = p->startup_delay; delay = p->startup_delay;
if (delay) if (delay)
{ {
DBG("BGP: Connect delayed by %d seconds\n", delay); BGP_TRACE(D_EVENTS, "Connect delayed by %d seconds", delay);
bgp_setup_conn(p, &p->outgoing_conn); bgp_setup_conn(p, &p->outgoing_conn);
bgp_start_timer(p->outgoing_conn.connect_retry_timer, delay); bgp_start_timer(p->outgoing_conn.connect_retry_timer, delay);
} }
...@@ -284,7 +288,7 @@ bgp_incoming_connection(sock *sk, int dummy) ...@@ -284,7 +288,7 @@ bgp_incoming_connection(sock *sk, int dummy)
struct bgp_proto *p = SKIP_BACK(struct bgp_proto, bgp_node, n); struct bgp_proto *p = SKIP_BACK(struct bgp_proto, bgp_node, n);
if (ipa_equal(p->cf->remote_ip, sk->daddr)) if (ipa_equal(p->cf->remote_ip, sk->daddr))
{ {
DBG("BGP: Authorized\n"); BGP_TRACE(D_EVENTS, "Incoming connection from %I port %d", sk->daddr, sk->dport);
if (p->incoming_conn.sk) if (p->incoming_conn.sk)
{ {
DBG("BGP: But one incoming connection already exists, how is that possible?\n"); DBG("BGP: But one incoming connection already exists, how is that possible?\n");
...@@ -296,7 +300,7 @@ bgp_incoming_connection(sock *sk, int dummy) ...@@ -296,7 +300,7 @@ bgp_incoming_connection(sock *sk, int dummy)
return 0; return 0;
} }
} }
DBG("BGP: Unauthorized\n"); log(L_AUTH "BGP: Unauthorized connect from %I port %d", sk->daddr, sk->dport);
rfree(sk); rfree(sk);
return 0; return 0;
} }
...@@ -340,12 +344,12 @@ bgp_neigh_notify(neighbor *n) ...@@ -340,12 +344,12 @@ bgp_neigh_notify(neighbor *n)
if (n->iface) if (n->iface)
{ {
DBG("BGP: Neighbor is reachable\n"); BGP_TRACE(D_EVENTS, "Neighbor found");
bgp_start_neighbor(p); bgp_start_neighbor(p);
} }
else else
{ {
DBG("BGP: Neighbor is unreachable\n"); BGP_TRACE(D_EVENTS, "Neighbor lost");
/* Send cease packets, but don't wait for them to be delivered */ /* Send cease packets, but don't wait for them to be delivered */
bgp_graceful_close_conn(&p->outgoing_conn); bgp_graceful_close_conn(&p->outgoing_conn);
bgp_graceful_close_conn(&p->incoming_conn); bgp_graceful_close_conn(&p->incoming_conn);
...@@ -372,7 +376,7 @@ bgp_start_locked(struct object_lock *lock) ...@@ -372,7 +376,7 @@ bgp_start_locked(struct object_lock *lock)
else if (p->neigh->iface) else if (p->neigh->iface)
bgp_start_neighbor(p); bgp_start_neighbor(p);
else else
DBG("BGP: Waiting for neighbor\n"); BGP_TRACE(D_EVENTS, "Waiting for %I to become my neighbor", p->next_hop);
} }
static int static int
...@@ -408,7 +412,7 @@ bgp_shutdown(struct proto *P) ...@@ -408,7 +412,7 @@ bgp_shutdown(struct proto *P)
{ {
struct bgp_proto *p = (struct bgp_proto *) P; struct bgp_proto *p = (struct bgp_proto *) P;
DBG("BGP: Explicit shutdown\n"); BGP_TRACE(D_EVENTS, "Shutdown requested");
/* /*
* We want to send the Cease notification message to all connections * We want to send the Cease notification message to all connections
......
...@@ -101,6 +101,14 @@ void bgp_check(struct bgp_config *c); ...@@ -101,6 +101,14 @@ void bgp_check(struct bgp_config *c);
void bgp_error(struct bgp_conn *c, unsigned code, unsigned subcode, byte *data, int len); void bgp_error(struct bgp_conn *c, unsigned code, unsigned subcode, byte *data, int len);
void bgp_close_conn(struct bgp_conn *c); void bgp_close_conn(struct bgp_conn *c);
#ifdef LOCAL_DEBUG
#define BGP_FORCE_DEBUG 1
#else
#define BGP_FORCE_DEBUG 0
#endif
#define BGP_TRACE(flags, msg, args...) do { if ((p->p.debug & flags) || BGP_FORCE_DEBUG) \
log(L_TRACE "%s: " msg, p->p.name , ## args ); } while(0)
/* attrs.c */ /* attrs.c */
struct rta *bgp_decode_attrs(struct bgp_conn *conn, byte *a, unsigned int len, struct linpool *pool, int mandatory); struct rta *bgp_decode_attrs(struct bgp_conn *conn, byte *a, unsigned int len, struct linpool *pool, int mandatory);
......
...@@ -6,7 +6,7 @@ ...@@ -6,7 +6,7 @@
* Can be freely distributed and used under the terms of the GNU GPL. * Can be freely distributed and used under the terms of the GNU GPL.
*/ */
#define LOCAL_DEBUG #undef LOCAL_DEBUG
#include "nest/bird.h" #include "nest/bird.h"
#include "nest/iface.h" #include "nest/iface.h"
...@@ -21,7 +21,9 @@ ...@@ -21,7 +21,9 @@
static byte * static byte *
bgp_create_notification(struct bgp_conn *conn, byte *buf) bgp_create_notification(struct bgp_conn *conn, byte *buf)
{ {
DBG("BGP: Sending notification: code=%d, sub=%d\n", conn->notify_code, conn->notify_subcode); struct bgp_proto *p = conn->bgp;
BGP_TRACE(D_PACKETS, "Sending NOTIFICATION(code=%d.%d)", conn->notify_code, conn->notify_subcode);
buf[0] = conn->notify_code; buf[0] = conn->notify_code;
buf[1] = conn->notify_subcode; buf[1] = conn->notify_subcode;
memcpy(buf+2, conn->notify_data, conn->notify_size); memcpy(buf+2, conn->notify_data, conn->notify_size);
...@@ -31,11 +33,14 @@ bgp_create_notification(struct bgp_conn *conn, byte *buf) ...@@ -31,11 +33,14 @@ bgp_create_notification(struct bgp_conn *conn, byte *buf)
static byte * static byte *
bgp_create_open(struct bgp_conn *conn, byte *buf) bgp_create_open(struct bgp_conn *conn, byte *buf)
{ {
DBG("BGP: Sending open\n"); struct bgp_proto *p = conn->bgp;
BGP_TRACE(D_PACKETS, "Sending OPEN(ver=%d,as=%d,hold=%d,id=%08x)",
BGP_VERSION, p->local_as, p->cf->hold_time, p->local_id);
buf[0] = BGP_VERSION; buf[0] = BGP_VERSION;
put_u16(buf+1, conn->bgp->local_as); put_u16(buf+1, p->local_as);
put_u16(buf+3, conn->bgp->cf->hold_time); put_u16(buf+3, p->cf->hold_time);
put_u32(buf+5, conn->bgp->local_id); put_u32(buf+5, p->local_id);
buf[9] = 0; /* No optional parameters */ buf[9] = 0; /* No optional parameters */
return buf+10; return buf+10;
} }
...@@ -66,7 +71,7 @@ bgp_encode_prefixes(struct bgp_proto *p, byte *w, struct bgp_bucket *buck, unsig ...@@ -66,7 +71,7 @@ bgp_encode_prefixes(struct bgp_proto *p, byte *w, struct bgp_bucket *buck, unsig
static byte * static byte *
bgp_create_update(struct bgp_conn *conn, byte *buf) bgp_create_update(struct bgp_conn *conn, byte *buf)
{ {
struct bgp_proto *bgp = conn->bgp; struct bgp_proto *p = conn->bgp;
struct bgp_bucket *buck; struct bgp_bucket *buck;
int remains = BGP_MAX_PACKET_LENGTH - BGP_HEADER_LENGTH - 4; int remains = BGP_MAX_PACKET_LENGTH - BGP_HEADER_LENGTH - 4;
byte *w, *wold; byte *w, *wold;
...@@ -74,13 +79,12 @@ bgp_create_update(struct bgp_conn *conn, byte *buf) ...@@ -74,13 +79,12 @@ bgp_create_update(struct bgp_conn *conn, byte *buf)
int wd_size = 0; int wd_size = 0;
int r_size = 0; int r_size = 0;
DBG("BGP: Sending update\n"); BGP_TRACE(D_PACKETS, "Sending UPDATE");
/* FIXME: Better timing of updates */
w = buf+2; w = buf+2;
if ((buck = bgp->withdraw_bucket) && !EMPTY_LIST(buck->prefixes)) if ((buck = p->withdraw_bucket) && !EMPTY_LIST(buck->prefixes))
{ {
DBG("Withdrawn routes:\n"); DBG("Withdrawn routes:\n");
wd_size = bgp_encode_prefixes(bgp, w, buck, remains); wd_size = bgp_encode_prefixes(p, w, buck, remains);
w += wd_size; w += wd_size;
remains -= wd_size; remains -= wd_size;
} }
...@@ -88,19 +92,19 @@ bgp_create_update(struct bgp_conn *conn, byte *buf) ...@@ -88,19 +92,19 @@ bgp_create_update(struct bgp_conn *conn, byte *buf)
if (remains >= 2048) if (remains >= 2048)
{ {
while ((buck = (struct bgp_bucket *) HEAD(bgp->bucket_queue))->send_node.next) while ((buck = (struct bgp_bucket *) HEAD(p->bucket_queue))->send_node.next)
{ {
if (EMPTY_LIST(buck->prefixes)) if (EMPTY_LIST(buck->prefixes))
{ {
DBG("Deleting empty bucket %p\n", buck); DBG("Deleting empty bucket %p\n", buck);
rem_node(&buck->send_node); rem_node(&buck->send_node);
bgp_free_bucket(bgp, buck); bgp_free_bucket(p, buck);
continue; continue;
} }
DBG("Processing bucket %p\n", buck); DBG("Processing bucket %p\n", buck);
w = bgp_encode_attrs(w, buck); w = bgp_encode_attrs(w, buck);
remains = BGP_MAX_PACKET_LENGTH - BGP_HEADER_LENGTH - (w-buf); remains = BGP_MAX_PACKET_LENGTH - BGP_HEADER_LENGTH - (w-buf);
r_size = bgp_encode_prefixes(bgp, w, buck, remains); r_size = bgp_encode_prefixes(p, w, buck, remains);
w += r_size; w += r_size;
break; break;
} }
...@@ -124,6 +128,7 @@ bgp_create_header(byte *buf, unsigned int len, unsigned int type) ...@@ -124,6 +128,7 @@ bgp_create_header(byte *buf, unsigned int len, unsigned int type)
static int static int
bgp_fire_tx(struct bgp_conn *conn) bgp_fire_tx(struct bgp_conn *conn)
{ {
struct bgp_proto *p = conn->bgp;
unsigned int s = conn->packets_to_send; unsigned int s = conn->packets_to_send;
sock *sk = conn->sk; sock *sk = conn->sk;
byte *buf = sk->tbuf; byte *buf = sk->tbuf;
...@@ -147,7 +152,7 @@ bgp_fire_tx(struct bgp_conn *conn) ...@@ -147,7 +152,7 @@ bgp_fire_tx(struct bgp_conn *conn)
s &= ~(1 << PKT_KEEPALIVE); s &= ~(1 << PKT_KEEPALIVE);
type = PKT_KEEPALIVE; type = PKT_KEEPALIVE;
end = pkt; /* Keepalives carry no data */ end = pkt; /* Keepalives carry no data */
DBG("BGP: Sending keepalive\n"); BGP_TRACE(D_PACKETS, "Sending KEEPALIVE");
bgp_start_timer(conn->keepalive_timer, conn->keepalive_time); bgp_start_timer(conn->keepalive_timer, conn->keepalive_time);
} }
else if (s & (1 << PKT_OPEN)) else if (s & (1 << PKT_OPEN))
...@@ -252,7 +257,7 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len) ...@@ -252,7 +257,7 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len)
as = get_u16(pkt+20); as = get_u16(pkt+20);
hold = get_u16(pkt+22); hold = get_u16(pkt+22);
id = get_u32(pkt+24); id = get_u32(pkt+24);
DBG("BGP: OPEN as=%d hold=%d id=%08x\n", as, hold, id); BGP_TRACE(D_PACKETS, "Got OPEN(as=%d,hold=%d,id=%08x)", as, hold, id);
if (cf->remote_as && as != p->remote_as) if (cf->remote_as && as != p->remote_as)
{ bgp_error(conn, 2, 2, pkt+20, -2); return; } { bgp_error(conn, 2, 2, pkt+20, -2); return; }
if (hold > 0 && hold < 3) if (hold > 0 && hold < 3)
...@@ -272,21 +277,21 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len) ...@@ -272,21 +277,21 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len)
case BS_CONNECT: case BS_CONNECT:
case BS_ACTIVE: case BS_ACTIVE:
case BS_OPENSENT: case BS_OPENSENT:
DBG("BGP: Collision, closing the other connection\n"); BGP_TRACE(D_EVENTS, "Connection collision, giving up the other connection");
bgp_close_conn(other); bgp_close_conn(other);
break; break;
case BS_OPENCONFIRM: case BS_OPENCONFIRM:
if ((p->local_id < id) == (conn == &p->incoming_conn)) if ((p->local_id < id) == (conn == &p->incoming_conn))
{ {
/* Should close the other connection */ /* Should close the other connection */
DBG("BGP: Collision, closing the other connection\n"); BGP_TRACE(D_EVENTS, "Connection collision, giving up the other connection");
bgp_error(other, 6, 0, NULL, 0); bgp_error(other, 6, 0, NULL, 0);
break; break;
} }
/* Fall thru */ /* Fall thru */
case BS_ESTABLISHED: case BS_ESTABLISHED:
/* Should close this connection */ /* Should close this connection */
DBG("BGP: Collision, closing this connection\n"); BGP_TRACE(D_EVENTS, "Connection collision, giving up this connection");
bgp_error(conn, 6, 0, NULL, 0); bgp_error(conn, 6, 0, NULL, 0);
return; return;
default: default:
...@@ -330,7 +335,7 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len) ...@@ -330,7 +335,7 @@ bgp_rx_open(struct bgp_conn *conn, byte *pkt, int len)
static void static void
bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len) bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len)
{ {
struct bgp_proto *bgp = conn->bgp; struct bgp_proto *p = conn->bgp;
byte *withdrawn, *attrs, *nlri; byte *withdrawn, *attrs, *nlri;
ip_addr prefix; ip_addr prefix;
int withdrawn_len, attr_len, nlri_len, pxlen; int withdrawn_len, attr_len, nlri_len, pxlen;
...@@ -339,7 +344,7 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len) ...@@ -339,7 +344,7 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len)
rta *a0; rta *a0;
rta *a = NULL; rta *a = NULL;
DBG("BGP: UPDATE\n"); BGP_TRACE(D_PACKETS, "Got UPDATE");
if (conn->state != BS_ESTABLISHED) if (conn->state != BS_ESTABLISHED)
{ bgp_error(conn, 5, 0, NULL, 0); return; } { bgp_error(conn, 5, 0, NULL, 0); return; }
bgp_start_timer(conn->hold_timer, conn->hold_time); bgp_start_timer(conn->hold_timer, conn->hold_time);
...@@ -369,8 +374,8 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len) ...@@ -369,8 +374,8 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len)
{ {
DECODE_PREFIX(withdrawn, withdrawn_len); DECODE_PREFIX(withdrawn, withdrawn_len);
DBG("Withdraw %I/%d\n", prefix, pxlen); DBG("Withdraw %I/%d\n", prefix, pxlen);
if (n = net_find(bgp->p.table, prefix, pxlen)) if (n = net_find(p->p.table, prefix, pxlen))
rte_update(bgp->p.table, n, &bgp->p, NULL); rte_update(p->p.table, n, &p->p, NULL);
} }
if (!attr_len && !nlri_len) /* shortcut */ if (!attr_len && !nlri_len) /* shortcut */
...@@ -386,10 +391,10 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len) ...@@ -386,10 +391,10 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len)
DECODE_PREFIX(nlri, nlri_len); DECODE_PREFIX(nlri, nlri_len);
DBG("Add %I/%d\n", prefix, pxlen); DBG("Add %I/%d\n", prefix, pxlen);
e = rte_get_temp(rta_clone(a)); e = rte_get_temp(rta_clone(a));
n = net_get(bgp->p.table, prefix, pxlen); n = net_get(p->p.table, prefix, pxlen);
e->net = n; e->net = n;
e->pflags = 0; e->pflags = 0;
rte_update(bgp->p.table, n, &bgp->p, e); rte_update(p->p.table, n, &p->p, e);
} }
rta_free(a); rta_free(a);
} }
...@@ -487,7 +492,9 @@ bgp_rx_notification(struct bgp_conn *conn, byte *pkt, int len) ...@@ -487,7 +492,9 @@ bgp_rx_notification(struct bgp_conn *conn, byte *pkt, int len)
static void static void
bgp_rx_keepalive(struct bgp_conn *conn, byte *pkt, unsigned len) bgp_rx_keepalive(struct bgp_conn *conn, byte *pkt, unsigned len)
{ {
DBG("BGP: KEEPALIVE\n"); struct bgp_proto *p = conn->bgp;
BGP_TRACE(D_PACKETS, "Got KEEPALIVE");
bgp_start_timer(conn->hold_timer, conn->hold_time); bgp_start_timer(conn->hold_timer, conn->hold_time);
switch (conn->state) switch (conn->state)
{ {
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment