Rate limit for most abundant log messages

This commit is contained in:
Ondrej Zajicek 2009-02-26 14:23:54 +01:00
parent a9dc5e1ef2
commit cb53039271
7 changed files with 70 additions and 17 deletions

View file

@ -281,8 +281,10 @@ rta_cow(void)
} }
} }
static struct rate_limit rl_runtime_err;
#define runtime(x) do { \ #define runtime(x) do { \
log( L_ERR "filters, line %d: %s", what->lineno, x); \ log_rl(&rl_runtime_err, L_ERR "filters, line %d: %s", what->lineno, x); \
res.type = T_RETURN; \ res.type = T_RETURN; \
res.val.i = F_ERROR; \ res.val.i = F_ERROR; \
return res; \ return res; \

View file

@ -9,6 +9,8 @@
#ifndef _BIRD_BIRDLIB_H_ #ifndef _BIRD_BIRDLIB_H_
#define _BIRD_BIRDLIB_H_ #define _BIRD_BIRDLIB_H_
#include "timer.h"
/* Ugly structure offset handling macros */ /* Ugly structure offset handling macros */
#define OFFSETOF(s, i) ((unsigned int)&((s *)0)->i) #define OFFSETOF(s, i) ((unsigned int)&((s *)0)->i)
@ -33,8 +35,14 @@
/* Logging and dying */ /* Logging and dying */
struct rate_limit {
bird_clock_t timestamp;
int count;
};
#define log log_msg #define log log_msg
void log_msg(char *msg, ...); void log_msg(char *msg, ...);
void log_rl(struct rate_limit *rl, char *msg, ...);
void die(char *msg, ...) NORET; void die(char *msg, ...) NORET;
void bug(char *msg, ...) NORET; void bug(char *msg, ...) NORET;

View file

@ -139,6 +139,10 @@ void bgp_store_error(struct bgp_proto *p, struct bgp_conn *c, u8 class, u32 code
#define BGP_TRACE(flags, msg, args...) do { if ((p->p.debug & flags) || BGP_FORCE_DEBUG) \ #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) log(L_TRACE "%s: " msg, p->p.name , ## args ); } while(0)
#define BGP_TRACE_RL(rl, flags, msg, args...) do { if ((p->p.debug & flags) || BGP_FORCE_DEBUG) \
log_rl(rl, L_TRACE "%s: " msg, p->p.name , ## args ); } while(0)
/* attrs.c */ /* attrs.c */
void bgp_attach_attr(struct ea_list **to, struct linpool *pool, unsigned attr, uintptr_t val); void bgp_attach_attr(struct ea_list **to, struct linpool *pool, unsigned attr, uintptr_t val);

View file

@ -21,6 +21,8 @@
#include "bgp.h" #include "bgp.h"
static struct rate_limit rl_rcv_update, rl_snd_update;
static byte * static byte *
bgp_create_notification(struct bgp_conn *conn, byte *buf) bgp_create_notification(struct bgp_conn *conn, byte *buf)
{ {
@ -175,7 +177,7 @@ bgp_create_update(struct bgp_conn *conn, byte *buf)
} }
if (wd_size || r_size) if (wd_size || r_size)
{ {
BGP_TRACE(D_PACKETS, "Sending UPDATE"); BGP_TRACE_RL(&rl_snd_update, D_PACKETS, "Sending UPDATE");
return w; return w;
} }
else else
@ -282,7 +284,7 @@ bgp_create_update(struct bgp_conn *conn, byte *buf)
lp_flush(bgp_linpool); lp_flush(bgp_linpool);
if (size) if (size)
{ {
BGP_TRACE(D_PACKETS, "Sending UPDATE"); BGP_TRACE_RL(&rl_snd_update, D_PACKETS, "Sending UPDATE");
return w; return w;
} }
else else
@ -762,7 +764,8 @@ bgp_rx_update(struct bgp_conn *conn, byte *pkt, int len)
byte *withdrawn, *attrs, *nlri; byte *withdrawn, *attrs, *nlri;
int withdrawn_len, attr_len, nlri_len; int withdrawn_len, attr_len, nlri_len;
BGP_TRACE(D_PACKETS, "Got UPDATE"); BGP_TRACE_RL(&rl_rcv_update, 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);

View file

@ -129,6 +129,8 @@ nl_get_reply(void)
} }
} }
static struct rate_limit rl_netlink_err;
static int static int
nl_error(struct nlmsghdr *h) nl_error(struct nlmsghdr *h)
{ {
@ -143,7 +145,7 @@ nl_error(struct nlmsghdr *h)
e = (struct nlmsgerr *) NLMSG_DATA(h); e = (struct nlmsgerr *) NLMSG_DATA(h);
ec = -e->error; ec = -e->error;
if (ec) if (ec)
log(L_WARN "Netlink: %s", strerror(ec)); log_rl(&rl_netlink_err, L_WARN "Netlink: %s", strerror(ec));
return ec; return ec;
} }

View file

@ -183,18 +183,18 @@ struct protocol proto_unix_iface = {
* Tracing of routes * Tracing of routes
*/ */
static void
krt_trace_in_print(struct krt_proto *p, rte *e, char *msg)
{
DBG("KRT: %I/%d: %s\n", e->net->n.prefix, e->net->n.pxlen, msg);
log(L_TRACE "%s: %I/%d: %s", p->p.name, e->net->n.prefix, e->net->n.pxlen, msg);
}
static inline void static inline void
krt_trace_in(struct krt_proto *p, rte *e, char *msg) krt_trace_in(struct krt_proto *p, rte *e, char *msg)
{ {
if (p->p.debug & D_PACKETS) if (p->p.debug & D_PACKETS)
krt_trace_in_print(p, e, msg); log(L_TRACE "%s: %I/%d: %s", p->p.name, e->net->n.prefix, e->net->n.pxlen, msg);
}
static inline void
krt_trace_in_rl(struct rate_limit *rl, struct krt_proto *p, rte *e, char *msg)
{
if (p->p.debug & D_PACKETS)
log_rl(rl, L_TRACE "%s: %I/%d: %s", p->p.name, e->net->n.prefix, e->net->n.pxlen, msg);
} }
/* /*
@ -203,6 +203,8 @@ krt_trace_in(struct krt_proto *p, rte *e, char *msg)
#ifdef KRT_ALLOW_LEARN #ifdef KRT_ALLOW_LEARN
static struct rate_limit rl_alien_seen, rl_alien_updated, rl_alien_created, rl_alien_ignored;
static inline int static inline int
krt_same_key(rte *a, rte *b) krt_same_key(rte *a, rte *b)
{ {
@ -249,20 +251,20 @@ krt_learn_scan(struct krt_proto *p, rte *e)
{ {
if (krt_uptodate(m, e)) if (krt_uptodate(m, e))
{ {
krt_trace_in(p, e, "[alien] seen"); krt_trace_in_rl(&rl_alien_seen, p, e, "[alien] seen");
rte_free(e); rte_free(e);
m->u.krt.seen = 1; m->u.krt.seen = 1;
} }
else else
{ {
krt_trace_in(p, e, "[alien] updated"); krt_trace_in_rl(&rl_alien_updated, p, e, "[alien] updated");
*mm = m->next; *mm = m->next;
rte_free(m); rte_free(m);
m = NULL; m = NULL;
} }
} }
else else
krt_trace_in(p, e, "[alien] created"); krt_trace_in_rl(&rl_alien_created, p, e, "[alien] created");
if (!m) if (!m)
{ {
e->attrs = rta_lookup(e->attrs); e->attrs = rta_lookup(e->attrs);
@ -516,7 +518,7 @@ krt_got_route(struct krt_proto *p, rte *e)
krt_learn_scan(p, e); krt_learn_scan(p, e);
else else
{ {
krt_trace_in(p, e, "alien route, ignored"); krt_trace_in_rl(&rl_alien_ignored, p, e, "alien route, ignored");
rte_free(e); rte_free(e);
} }
return; return;

View file

@ -30,6 +30,9 @@ static FILE *dbgf = NULL;
static list *current_log_list; static list *current_log_list;
static list init_log_list; static list init_log_list;
bird_clock_t rate_limit_time = 5;
int rate_limit_count = 5;
#ifdef HAVE_SYSLOG #ifdef HAVE_SYSLOG
#include <sys/syslog.h> #include <sys/syslog.h>
@ -126,6 +129,35 @@ log_msg(char *msg, ...)
va_end(args); va_end(args);
} }
void
log_rl(struct rate_limit *rl, char *msg, ...)
{
int class = 1;
va_list args;
bird_clock_t delta = now - rl->timestamp;
if ((0 <= delta) && (delta < rate_limit_time))
{
rl->count++;
}
else
{
rl->timestamp = now;
rl->count = 1;
}
if (rl->count > rate_limit_count)
return;
va_start(args, msg);
if (*msg >= 1 && *msg <= 8)
class = *msg++;
vlog(class, msg, args);
if (rl->count == rate_limit_count)
vlog(class, "...", args);
va_end(args);
}
/** /**
* bug - report an internal error * bug - report an internal error
* @msg: a printf-like error message * @msg: a printf-like error message