Fixes some BFD bugs and makes logging thread-safe.

18 files changed, 324 insertions, 235 deletions

diff --git a/conf/confbase.Y b/conf/confbase.Y
index b793acb0..8b9f206a 100644
--- a/conf/confbase.Y
+++ b/conf/confbase.Y
@@ -87,7 +87,7 @@ CF_DECLS
 %left '!'
 %nonassoc '.'
 
-CF_KEYWORDS(DEFINE, ON, OFF, YES, NO, XS, XMS, XUS)
+CF_KEYWORDS(DEFINE, ON, OFF, YES, NO, S, MS, US)
 
 CF_GRAMMAR
 
@@ -126,11 +126,10 @@ expr:
  ;
 
 
-/* XXX fix X* symbols, they collide with macros */
 expr_us:
-   expr XS  { $$ = (u32) $1 * 1000000; }
- | expr XMS { $$ = (u32) $1 * 1000; }
- | expr XUS { $$ = (u32) $1 * 1; }
+   expr S  { $$ = (u32) $1 * 1000000; }
+ | expr MS { $$ = (u32) $1 * 1000; }
+ | expr US { $$ = (u32) $1 * 1; }
  ;
 
 /* expr_u16: expr { check_u16($1); $$ = $1; }; */
diff --git a/filter/filter.c b/filter/filter.c
index 25587e0f..ff4000e8 100644
--- a/filter/filter.c
+++ b/filter/filter.c
@@ -75,41 +75,35 @@ pm_path_compare(struct f_path_mask *m1, struct f_path_mask *m2)
 u32 f_eval_asn(struct f_inst *expr);
 
 static void
-pm_format(struct f_path_mask *p, byte *buf, unsigned int size)
+pm_format(struct f_path_mask *p, buffer *buf)
 {
-  byte *end = buf + size - 16;
+  buffer_puts(buf, "[= ");
 
   while (p)
+  {
+    switch(p->kind)
     {
-      if (buf > end)
-	{
-	  strcpy(buf, " ...");
-	  return;
-	}
-
-      switch(p->kind)
-	{
-	case PM_ASN:
-	  buf += bsprintf(buf, " %u", p->val);
-	  break;
-
-	case PM_QUESTION:
-	  buf += bsprintf(buf, " ?");
-	  break;
+    case PM_ASN:
+      buffer_print(buf, "%u ", p->val);
+      break;
 
-	case PM_ASTERISK:
-	  buf += bsprintf(buf, " *");
-	  break;
+    case PM_QUESTION:
+      buffer_puts(buf, "? ");
+      break;
 
-	case PM_ASN_EXPR:
-	  buf += bsprintf(buf, " %u", f_eval_asn((struct f_inst *) p->val));
-	  break;
-	}
+    case PM_ASTERISK:
+      buffer_puts(buf, "* ");
+      break;
 
-      p = p->next;
+    case PM_ASN_EXPR:
+      buffer_print(buf, "%u ", f_eval_asn((struct f_inst *) p->val));
+      break;
     }
 
-  *buf = 0;
+    p = p->next;
+  }
+
+  buffer_puts(buf, "=]");
 }
 
 static inline int int_cmp(int i1, int i2)
@@ -119,7 +113,7 @@ static inline int int_cmp(int i1, int i2)
   else return 1;
 }
 
-static inline int uint_cmp(unsigned int i1, unsigned int i2)
+static inline int uint_cmp(uint i1, uint i2)
 {
   if (i1 == i2) return 0;
   if (i1 < i2) return -1;
@@ -440,60 +434,32 @@ val_in_range(struct f_val v1, struct f_val v2)
   return CMP_ERROR;
 }
 
-static void
-tree_node_print(struct f_tree *t, char **sep)
-{
-  if (t == NULL)
-    return;
-
-  tree_node_print(t->left, sep);
-
-  logn(*sep);
-  val_print(t->from);
-  if (val_compare(t->from, t->to) != 0)
-    {
-      logn( ".." );
-      val_print(t->to);
-    }
-  *sep = ", ";
-
-  tree_node_print(t->right, sep);
-}
-
-static void
-tree_print(struct f_tree *t)
-{
-  char *sep = "";
-  logn( "[" );
-  tree_node_print(t, &sep);
-  logn( "] " );
-}
-
 /*
- * val_print - format filter value
+ * val_format - format filter value
  */
 void
-val_print(struct f_val v)
+val_format(struct f_val v, buffer *buf)
 {
   char buf2[1024];
-  switch (v.type) {
-  case T_VOID: logn("(void)"); return;
-  case T_BOOL: logn(v.val.i ? "TRUE" : "FALSE"); return;
-  case T_INT: logn("%d", v.val.i); return;
-  case T_STRING: logn("%s", v.val.s); return;
-  case T_IP: logn("%I", v.val.px.ip); return;
-  case T_PREFIX: logn("%I/%d", v.val.px.ip, v.val.px.len); return;
-  case T_PAIR: logn("(%d,%d)", v.val.i >> 16, v.val.i & 0xffff); return;
-  case T_QUAD: logn("%R", v.val.i); return;
-  case T_EC: ec_format(buf2, v.val.ec); logn("%s", buf2); return;
-  case T_PREFIX_SET: trie_print(v.val.ti); return;
-  case T_SET: tree_print(v.val.t); return;
-  case T_ENUM: logn("(enum %x)%d", v.type, v.val.i); return;
-  case T_PATH: as_path_format(v.val.ad, buf2, 1000); logn("(path %s)", buf2); return;
-  case T_CLIST: int_set_format(v.val.ad, 1, -1, buf2, 1000); logn("(clist %s)", buf2); return;
-  case T_ECLIST: ec_set_format(v.val.ad, -1, buf2, 1000); logn("(eclist %s)", buf2); return;
-  case T_PATH_MASK: pm_format(v.val.path_mask, buf2, 1000); logn("(pathmask%s)", buf2); return;
-  default: logn( "[unknown type %x]", v.type ); return;
+  switch (v.type)
+  {
+  case T_VOID:	buffer_puts(buf, "(void)"); return;
+  case T_BOOL:	buffer_puts(buf, v.val.i ? "TRUE" : "FALSE"); return;
+  case T_INT:	buffer_print(buf, "%d", v.val.i); return;
+  case T_STRING: buffer_print(buf, "%s", v.val.s); return;
+  case T_IP:	buffer_print(buf, "%I", v.val.px.ip); return;
+  case T_PREFIX: buffer_print(buf, "%I/%d", v.val.px.ip, v.val.px.len); return;
+  case T_PAIR:	buffer_print(buf, "(%d,%d)", v.val.i >> 16, v.val.i & 0xffff); return;
+  case T_QUAD:	buffer_print(buf, "%R", v.val.i); return;
+  case T_EC:	ec_format(buf2, v.val.ec); buffer_print(buf, "%s", buf2); return;
+  case T_PREFIX_SET: trie_format(v.val.ti, buf); return;
+  case T_SET:	tree_format(v.val.t, buf); return;
+  case T_ENUM:	buffer_print(buf, "(enum %x)%d", v.type, v.val.i); return;
+  case T_PATH:	as_path_format(v.val.ad, buf2, 1000); buffer_print(buf, "(path %s)", buf2); return;
+  case T_CLIST:	int_set_format(v.val.ad, 1, -1, buf2, 1000); buffer_print(buf, "(clist %s)", buf2); return;
+  case T_ECLIST: ec_set_format(v.val.ad, -1, buf2, 1000); buffer_print(buf, "(eclist %s)", buf2); return;
+  case T_PATH_MASK: pm_format(v.val.path_mask, buf); return;
+  default:	buffer_print(buf, "[unknown type %x]", v.type); return;
   }
 }
 
@@ -501,6 +467,7 @@ static struct rte **f_rte;
 static struct rta *f_old_rta;
 static struct ea_list **f_tmp_attrs;
 static struct linpool *f_pool;
+static struct buffer f_buf;
 static int f_flags;
 
 static inline void f_rte_cow(void)
@@ -782,7 +749,7 @@ interpret(struct f_inst *what)
     break;
   case 'p':
     ONEARG;
-    val_print(v1);
+    val_format(v1, &f_buf);
     break;
   case '?':	/* ? has really strange error value, so we can implement if ... else nicely :-) */
     ONEARG;
@@ -800,7 +767,7 @@ interpret(struct f_inst *what)
   case P('p',','):
     ONEARG;
     if (what->a2.i == F_NOP || (what->a2.i != F_NONL && what->a1.p))
-      log_commit(*L_INFO);
+      log_commit(*L_INFO, &f_buf);
 
     switch (what->a2.i) {
     case F_QUITBIRD:
@@ -1502,7 +1469,8 @@ f_run(struct filter *filter, struct rte **rte, struct ea_list **tmp_attrs, struc
   f_pool = tmp_pool;
   f_flags = flags;
 
-  log_reset();
+  LOG_BUFFER_INIT(f_buf);
+
   struct f_val res = interpret(filter->root);
 
   if (f_old_rta) {
@@ -1541,7 +1509,8 @@ f_eval(struct f_inst *expr, struct linpool *tmp_pool)
   f_rte = NULL;
   f_pool = tmp_pool;
 
-  log_reset();
+  LOG_BUFFER_INIT(f_buf);
+
   return interpret(expr);
 }
 
diff --git a/filter/filter.h b/filter/filter.h
index 1d5150e7..0cef9f36 100644
--- a/filter/filter.h
+++ b/filter/filter.h
@@ -78,12 +78,13 @@ struct f_inst *f_generate_roa_check(struct symbol *sym, struct f_inst *prefix, s
 struct f_tree *build_tree(struct f_tree *);
 struct f_tree *find_tree(struct f_tree *t, struct f_val val);
 int same_tree(struct f_tree *t1, struct f_tree *t2);
+void tree_format(struct f_tree *t, buffer *buf);
 
 struct f_trie *f_new_trie(linpool *lp);
 void trie_add_prefix(struct f_trie *t, ip_addr px, int plen, int l, int h);
 int trie_match_prefix(struct f_trie *t, ip_addr px, int plen);
 int trie_same(struct f_trie *t1, struct f_trie *t2);
-void trie_print(struct f_trie *t);
+void trie_format(struct f_trie *t, buffer *buf);
 
 void fprefix_get_bounds(struct f_prefix *px, int *l, int *h);
 
@@ -118,7 +119,8 @@ int i_same(struct f_inst *f1, struct f_inst *f2);
 int val_compare(struct f_val v1, struct f_val v2);
 int tree_compare(const void *p1, const void *p2);
 
-void val_print(struct f_val v);
+void val_format(struct f_val v, buffer *buf);
+
 
 #define F_NOP 0
 #define F_NONL 1
diff --git a/filter/test.conf b/filter/test.conf
index 048983b5..3d35ed05 100644
--- a/filter/test.conf
+++ b/filter/test.conf
@@ -106,7 +106,7 @@ eclist el2;
 	print "5 = ", p2.len;
 	print "Delete 3:   ", delete(p2, 3);
 	print "Filter 1-3: ", filter(p2, [1..3]);
-	
+
 	pm1 = [= 1 2 * 3 4 5 =];
 	p2 = prepend( + empty +, 5 );
 	p2 = prepend( p2, 4 );
diff --git a/filter/tree.c b/filter/tree.c
index f6ab75b4..5e1d606a 100644
--- a/filter/tree.c
+++ b/filter/tree.c
@@ -132,3 +132,37 @@ same_tree(struct f_tree *t1, struct f_tree *t2)
     return 0;
   return 1;
 }
+
+
+static void
+tree_node_format(struct f_tree *t, buffer *buf)
+{
+  if (t == NULL)
+    return;
+
+  tree_node_format(t->left, buf);
+
+  val_format(t->from, buf);
+  if (val_compare(t->from, t->to) != 0)
+  {
+    buffer_puts(buf, "..");
+    val_format(t->to, buf);
+  }
+  buffer_puts(buf, ", ");
+
+  tree_node_format(t->right, buf);
+}
+
+void
+tree_format(struct f_tree *t, buffer *buf)
+{
+  buffer_puts(buf, "[");
+ 
+ tree_node_format(t, buf);
+
+ /* Undo last separator */
+  if (buf->pos[-1] != '[')
+    buf->pos -= 2;
+ 
+  buffer_puts(buf, "]");
+}
diff --git a/filter/trie.c b/filter/trie.c
index 581332c6..52b1ed47 100644
--- a/filter/trie.c
+++ b/filter/trie.c
@@ -265,37 +265,37 @@ trie_same(struct f_trie *t1, struct f_trie *t2)
 }
 
 static void
-trie_node_print(struct f_trie_node *t, char **sep)
+trie_node_format(struct f_trie_node *t, buffer *buf)
 {
   if (t == NULL)
     return;
 
   if (ipa_nonzero(t->accept))
-    {
-      logn("%s%I/%d{%I}", *sep, t->addr, t->plen, t->accept);
-      *sep = ", ";
-    }
+    buffer_print(buf, "%I/%d{%I}, ", t->addr, t->plen, t->accept);
 
-  trie_node_print(t->c[0], sep);
-  trie_node_print(t->c[1], sep);
+  trie_node_format(t->c[0], buf);
+  trie_node_format(t->c[1], buf);
 }
 
 /**
- * trie_print
- * @t: trie to be printed
+ * trie_format
+ * @t: trie to be formatted
+ * @buf: destination buffer
  *
- * Prints the trie to the log buffer.
+ * Prints the trie to the supplied buffer.
  */
 void
-trie_print(struct f_trie *t)
+trie_format(struct f_trie *t, buffer *buf)
 {
-  char *sep = "";
-  logn("[");
+  buffer_puts(buf, "[");
+
   if (t->zero)
-    {
-      logn("0.0.0.0/0");
-      sep = ", ";
-    }
-  trie_node_print(&t->root, &sep);
-  logn("]");
+    buffer_print(buf, "0.0.0.0/0, ");
+  trie_node_format(&t->root, buf);
+
+  /* Undo last separator */
+  if (buf->pos[-1] != '[')
+    buf->pos -= 2;
+
+  buffer_puts(buf, "]");
 }
diff --git a/lib/birdlib.h b/lib/birdlib.h
index 479f3d5c..2d6849e1 100644
--- a/lib/birdlib.h
+++ b/lib/birdlib.h
@@ -10,6 +10,7 @@
 #define _BIRD_BIRDLIB_H_
 
 #include "timer.h"
+#include "alloca.h"
 
 /* Ugly structure offset handling macros */
 
@@ -19,12 +20,12 @@
 
 /* Utility macros */
 
-#ifdef PARSER
 #define _MIN(a,b) (((a)<(b))?(a):(b))
 #define _MAX(a,b) (((a)>(b))?(a):(b))
-#else
-#define MIN(a,b) (((a)<(b))?(a):(b))
-#define MAX(a,b) (((a)>(b))?(a):(b))
+
+#ifndef PARSER
+#define MIN(a,b) _MIN(a,b)
+#define MAX(a,b) _MAX(a,b)
 #endif
 
 #define ABS(a)   ((a)>=0 ? (a) : -(a))
@@ -34,24 +35,61 @@
 #define NULL ((void *) 0)
 #endif
 
+
 /* Macros for gcc attributes */
 
 #define NORET __attribute__((noreturn))
 #define UNUSED __attribute__((unused))
 
+
+/* Microsecond time */
+
+typedef s64 btime;
+
+#define _S	*1000000
+#define _MS	*1000
+#define _US	*1
+#define TO_S	/1000000
+#define TO_MS	/1000
+#define TO_US	/1
+
+#ifndef PARSER
+#define S	_S
+#define MS	_MS
+#define US	_US
+#endif
+
+
 /* Logging and dying */
 
+typedef struct buffer {
+  byte *start;
+  byte *pos;
+  byte *end;
+} buffer;
+
+#define STACK_BUFFER_INIT(buf,size)		\
+  do {						\
+    buf.start = alloca(size);			\
+    buf.pos = buf.start;			\
+    buf.end = buf.start + size;			\
+  } while(0)
+
+#define LOG_BUFFER_INIT(buf)			\
+  STACK_BUFFER_INIT(buf, LOG_BUFFER_SIZE)
+
+#define LOG_BUFFER_SIZE 1024
+
+
 struct rate_limit {
   bird_clock_t timestamp;
   int count;
 };
 
 #define log log_msg
-void log_reset(void);
-void log_commit(int class);
+void log_commit(int class, buffer *buf);
 void log_msg(char *msg, ...);
 void log_rl(struct rate_limit *rl, char *msg, ...);
-void logn(char *msg, ...);
 void die(char *msg, ...) NORET;
 void bug(char *msg, ...) NORET;
 
diff --git a/lib/printf.c b/lib/printf.c
index 14af1062..d8600b61 100644
--- a/lib/printf.c
+++ b/lib/printf.c
@@ -410,3 +410,40 @@ int bsnprintf(char * buf, int size, const char *fmt, ...)
   va_end(args);
   return i;
 }
+
+int
+buffer_vprint(buffer *buf, const char *fmt, va_list args)
+{
+  int i = bvsnprintf((char *) buf->pos, buf->end - buf->pos, fmt, args);
+  buf->pos = (i >= 0) ? (buf->pos + i) : buf->end;
+  return i;
+}
+
+int
+buffer_print(buffer *buf, const char *fmt, ...)
+{
+  va_list args;
+  int i;
+
+  va_start(args, fmt);
+  i=bvsnprintf((char *) buf->pos, buf->end - buf->pos, fmt, args);
+  va_end(args);
+
+  buf->pos = (i >= 0) ? (buf->pos + i) : buf->end;
+  return i;
+}
+
+void
+buffer_puts(buffer *buf, const char *str)
+{
+  byte *bp = buf->pos;
+  byte *be = buf->end;
+
+  while (bp < be && *str)
+    *bp++ = *str++;
+
+  if (bp < be)
+    *bp = 0;
+
+  buf->pos = bp;
+}
diff --git a/lib/string.h b/lib/string.h
index 14eaa360..2c477294 100644
--- a/lib/string.h
+++ b/lib/string.h
@@ -17,6 +17,10 @@ int bvsprintf(char *str, const char *fmt, va_list args);
 int bsnprintf(char *str, int size, const char *fmt, ...);
 int bvsnprintf(char *str, int size, const char *fmt, va_list args);
 
+int buffer_vprint(buffer *buf, const char *fmt, va_list args);
+int buffer_print(buffer *buf, const char *fmt, ...);
+void buffer_puts(buffer *buf, const char *str);
+
 int patmatch(byte *pat, byte *str);
 
 #endif
diff --git a/nest/cmds.c b/nest/cmds.c
index 9bdd66cd..ec6bc762 100644
--- a/nest/cmds.c
+++ b/nest/cmds.c
@@ -92,13 +92,10 @@ cmd_show_memory(void)
   cli_msg(0, "");
 }
 
-extern const char *log_buffer_ptr;
-
 void
 cmd_eval(struct f_inst *expr)
 {
   struct f_val v = f_eval(expr, this_cli->parser_pool);
-  log_reset();
 
   if (v.type == T_RETURN)
     {
@@ -106,7 +103,8 @@ cmd_eval(struct f_inst *expr)
       return;
     }
 
-  val_print(v);
-  cli_msg(23, "%s", log_buffer_ptr);
-  log_reset();
+  buffer buf;
+  LOG_BUFFER_INIT(buf);
+  val_format(v, &buf);
+  cli_msg(23, "%s", buf.start);
 }
diff --git a/proto/bfd/bfd.c b/proto/bfd/bfd.c
index 6e38102b..3e2af9d5 100644
--- a/proto/bfd/bfd.c
+++ b/proto/bfd/bfd.c
@@ -17,6 +17,9 @@
 #define HASH_IP_EQ(a,b)		ipa_equal(a,b)
 #define HASH_IP_FN(k)		ipa_hash(k)
 
+
+const char *bfd_state_names[] = { "AdminDown", "Down", "Init", "Up" };
+
 static inline void bfd_notify_kick(struct bfd_proto *p);
 
 static void 
@@ -28,7 +31,7 @@ bfd_session_update_state(struct bfd_session *s, uint state, uint diag)
   if (s->loc_state == state)
     return;
 
-  //TRACE(D_EVENTS, "Session changed %I %d %d", s->addr, state, diag);
+  TRACE(D_EVENTS, "Session changed %I %d %d", s->addr, state, diag);
   debug("STATE %I %d %d %d\n", s->addr, s->loc_state, state, diag);
     
   bfd_lock_sessions(p);
@@ -547,8 +550,6 @@ bfd_start(struct proto *P)
   init_list(&p->sock_list);
 
 
-  birdloop_mask_wakeups(p->loop);
-
   init_list(&p->notify_list);
   bfd_notify_init(p);
 
@@ -561,7 +562,7 @@ bfd_start(struct proto *P)
   WALK_LIST(n, cf->neigh_list)
     bfd_start_neighbor(p, n);
 
-  birdloop_unmask_wakeups(p->loop);
+  birdloop_start(p->loop);
 
   return PS_UP;
 }
@@ -572,6 +573,13 @@ bfd_shutdown(struct proto *P)
 {
   struct bfd_proto *p = (struct bfd_proto *) P;
 
+  birdloop_stop(p->loop);
+
+  /* FIXME: This is hack */
+  birdloop_enter(p->loop);
+  rfree(p->tpool);
+  birdloop_leave(p->loop);
+
   return PS_DOWN;
 }
 
@@ -661,8 +669,8 @@ bfd_show_sessions(struct proto *P)
     tx_int = (MAX(s->des_min_tx_int, s->rem_min_rx_int) TO_MS);
     timeout = (MAX(s->req_min_rx_int, s->rem_min_tx_int) TO_MS) * s->rem_detect_mult;
 
-    cli_msg(-1013, "%I\t%s\t%d %d\t%u\t%u",
-	    s->addr, ifname, state, diag, tx_int, timeout);
+    cli_msg(-1013, "%I\t%s\t%s %d\t%u\t%u",
+	    s->addr, ifname, bfd_state_names[state], diag, tx_int, timeout);
   }
   HASH_WALK_END;
 
diff --git a/proto/bfd/bfd.h b/proto/bfd/bfd.h
index 97ccb507..66c6ed17 100644
--- a/proto/bfd/bfd.h
+++ b/proto/bfd/bfd.h
@@ -27,9 +27,9 @@
 #define BFD_ECHO_PORT		3785
 #define BFD_MULTI_CTL_PORT	4784
 
-#define BFD_DEFAULT_MIN_RX_INT	(10 MS)
-#define BFD_DEFAULT_MIN_TX_INT	(100 MS)
-#define BFD_DEFAULT_IDLE_TX_INT	(1 S)
+#define BFD_DEFAULT_MIN_RX_INT	(10 _MS)
+#define BFD_DEFAULT_MIN_TX_INT	(100 _MS)
+#define BFD_DEFAULT_IDLE_TX_INT	(1 _S)
 #define BFD_DEFAULT_MULTIPLIER	5
 
 
@@ -127,6 +127,7 @@ struct bfd_session
 };
 
 
+extern const char *bfd_state_names[];
 
 #define BFD_STATE_ADMIN_DOWN	0
 #define BFD_STATE_DOWN		1
@@ -146,6 +147,7 @@ struct bfd_session
 #define BFD_POLL_TX		1
 #define BFD_POLL_RX		2
 
+#define BFD_FLAGS		0x3f
 #define BFD_FLAG_POLL		(1 << 5)
 #define BFD_FLAG_FINAL		(1 << 4)
 #define BFD_FLAG_CPI		(1 << 3)
diff --git a/proto/bfd/io.c b/proto/bfd/io.c
index c5f2d1b0..2c1f7b03 100644
--- a/proto/bfd/io.c
+++ b/proto/bfd/io.c
@@ -35,6 +35,7 @@ struct birdloop
   btime real_time;
   u8 use_monotonic_clock;
 
+  u8 stop_called;
   u8 poll_active;
   u8 wakeup_masked;
   int wakeup_fds[2];
@@ -85,7 +86,7 @@ times_init(struct birdloop *loop)
   rv = clock_gettime(CLOCK_MONOTONIC, &ts);
   if (rv < 0)
   {
-    // log(L_WARN "Monotonic clock is missing");
+    log(L_WARN "Monotonic clock is missing");
 
     loop->use_monotonic_clock = 0;
     loop->last_time = 0;
@@ -94,13 +95,11 @@ times_init(struct birdloop *loop)
     return;
   }
 
-  /*
   if ((ts.tv_sec < 0) || (((s64) ts.tv_sec) > ((s64) 1 << 40)))
     log(L_WARN "Monotonic clock is crazy");
-  */
 
   loop->use_monotonic_clock = 1;
-  loop->last_time = (ts.tv_sec S) + (ts.tv_nsec / 1000);
+  loop->last_time = ((s64) ts.tv_sec S) + (ts.tv_nsec / 1000);
   loop->real_time = 0;
 }
 
@@ -114,12 +113,10 @@ times_update_pri(struct birdloop *loop)
   if (rv < 0)
     die("clock_gettime: %m");
 
-  btime new_time = (ts.tv_sec S) + (ts.tv_nsec / 1000);
+  btime new_time = ((s64) ts.tv_sec S) + (ts.tv_nsec / 1000);
 
-  /*
   if (new_time < loop->last_time)
     log(L_ERR "Monotonic clock is broken");
-  */
 
   loop->last_time = new_time;
   loop->real_time = 0;
@@ -135,15 +132,13 @@ times_update_alt(struct birdloop *loop)
   if (rv < 0)
     die("gettimeofday: %m");
 
-  btime new_time = (tv.tv_sec S) + tv.tv_usec;
+  btime new_time = ((s64) tv.tv_sec S) + tv.tv_usec;
   btime delta = new_time - loop->real_time;
 
   if ((delta < 0) || (delta > (60 S)))
   {
-    /*
     if (loop->real_time)
       log(L_WARN "Time jump, delta %d us", (int) delta);
-    */
 
     delta = 100 MS;
   }
@@ -621,14 +616,31 @@ birdloop_new(pool *p)
   timers_init(loop);
   sockets_init(loop);
 
+  return loop;
+}
 
+void
+birdloop_start(struct birdloop *loop)
+{
   int rv = pthread_create(&loop->thread, NULL, birdloop_main, loop);
-  if (rv < 0)
-    die("pthread_create(): %m");
+  if (rv)
+    die("pthread_create(): %M", rv);
+}
 
-  return loop;
+void
+birdloop_stop(struct birdloop *loop)
+{
+  pthread_mutex_lock(&loop->mutex);
+  loop->stop_called = 1;
+  wakeup_do_kick(loop);
+  pthread_mutex_unlock(&loop->mutex);
+
+  int rv = pthread_join(loop->thread, NULL);
+  if (rv)
+    die("pthread_join(): %M", rv);
 }
 
+
 void
 birdloop_enter(struct birdloop *loop)
 {
@@ -707,12 +719,18 @@ birdloop_main(void *arg)
     if (loop->close_scheduled)
       sockets_close_fds(loop);
 
+    if (loop->stop_called)
+      break;
+
     if (rv)
       sockets_fire(loop);
 
     timers_fire(loop);
   }
 
+  loop->stop_called = 0;
+  pthread_mutex_unlock(&loop->mutex);
+
   return NULL;
 }
 
diff --git a/proto/bfd/io.h b/proto/bfd/io.h
index c186ba2b..4f7c678d 100644
--- a/proto/bfd/io.h
+++ b/proto/bfd/io.h
@@ -15,16 +15,6 @@
 // #include "lib/timer.h"
 
 
-#define S	*1000000
-#define MS	*1000
-#define US	*1
-#define TO_S	/1000000
-#define TO_MS	/1000
-#define TO_US	/1
-
-
-typedef s64 btime;
-
 typedef struct timer2
 {
   resource r;
@@ -89,6 +79,8 @@ void sk_stop(sock *s);
 
 
 struct birdloop *birdloop_new(pool *p);
+void birdloop_start(struct birdloop *loop);
+void birdloop_stop(struct birdloop *loop);
 void birdloop_enter(struct birdloop *loop);
 void birdloop_leave(struct birdloop *loop);
 void birdloop_mask_wakeups(struct birdloop *loop);
diff --git a/proto/bfd/packets.c b/proto/bfd/packets.c
index 8f7a1f65..0e24114b 100644
--- a/proto/bfd/packets.c
+++ b/proto/bfd/packets.c
@@ -20,8 +20,8 @@ struct bfd_ctl_packet
   u32 req_min_echo_rx_int;
 };
 
-#define BFD_BASE_LEN sizeof(struct bfd_ctl_packet)
-
+#define BFD_BASE_LEN	sizeof(struct bfd_ctl_packet)
+#define BFD_MAX_LEN	64
 
 static inline u8 bfd_pack_vdiag(u8 version, u8 diag)
 { return (version << 5) | diag; }
@@ -43,11 +43,28 @@ static inline void bfd_pkt_set_state(struct bfd_ctl_packet *pkt, u8 val)
 { pkt->flags = val << 6; }
 
 
+char *
+bfd_format_flags(u8 flags, char *buf)
+{
+  char *bp = buf;
+  if (flags & BFD_FLAGS)	*bp++ = ' ';
+  if (flags & BFD_FLAG_POLL)	*bp++ = 'P';
+  if (flags & BFD_FLAG_FINAL)	*bp++ = 'F';
+  if (flags & BFD_FLAG_CPI)	*bp++ = 'C';
+  if (flags & BFD_FLAG_AP)	*bp++ = 'A';
+  if (flags & BFD_FLAG_DEMAND)	*bp++ = 'D';
+  if (flags & BFD_FLAG_MULTIPOINT) *bp++ = 'M';
+  *bp = 0;
+
+  return buf;
+}
+
 void
 bfd_send_ctl(struct bfd_proto *p, struct bfd_session *s, int final)
 {
   sock *sk = s->bsock->sk;
   struct bfd_ctl_packet *pkt = (struct bfd_ctl_packet *) sk->tbuf;
+  char fb[8];
 
   pkt->vdiag = bfd_pack_vdiag(1, s->loc_diag);
   pkt->flags = bfd_pack_flags(s->loc_state, 0);
@@ -65,7 +82,10 @@ bfd_send_ctl(struct bfd_proto *p, struct bfd_session *s, int final)
     pkt->flags |= BFD_FLAG_POLL;
 
   if (sk->tbuf != sk->tpos)
-    log(L_ERR "%s: old packet was overwritten in TX buffer", p->p.name);
+    log(L_WARN "%s: Old packet overwritten in TX buffer", p->p.name);
+
+  TRACE(D_PACKETS, "Sending CTL to %I [%s%s]", s->addr,
+	bfd_state_names[s->loc_state], bfd_format_flags(pkt->flags, fb));
 
   sk_send_to(sk, pkt->length, s->addr, sk->dport);
 }
@@ -79,6 +99,10 @@ bfd_rx_hook(sock *sk, int len)
   struct bfd_ctl_packet *pkt = (struct bfd_ctl_packet *) sk->rbuf;
   const char *err_dsc = NULL;
   uint err_val = 0;
+  char fb[8];
+
+  if ((sk->sport == BFD_CONTROL_PORT) && (sk->ttl < 255))
+    DROP("wrong TTL", sk->ttl);
 
   if (len < BFD_BASE_LEN)
     DROP("too short", len);
@@ -93,7 +117,8 @@ bfd_rx_hook(sock *sk, int len)
   if (pkt->detect_mult == 0)
     DROP("invalid detect mult", 0);
 
-  if (pkt->flags & BFD_FLAG_MULTIPOINT)
+  if ((pkt->flags & BFD_FLAG_MULTIPOINT) ||
+      ((pkt->flags & BFD_FLAG_POLL) && (pkt->flags & BFD_FLAG_FINAL)))
     DROP("invalid flags", pkt->flags);
 
   if (pkt->snd_id == 0)
@@ -107,7 +132,7 @@ bfd_rx_hook(sock *sk, int len)
     s = bfd_find_session_by_id(p, id);
 
     if (!s)
-      DROP("unknown session", id);
+      DROP("unknown session id", id);
   }
   else
   {
@@ -138,11 +163,14 @@ bfd_rx_hook(sock *sk, int len)
   s->rem_min_rx_int = ntohl(pkt->req_min_rx_int);
   s->rem_detect_mult = pkt->detect_mult;
 
+  TRACE(D_PACKETS, "CTL received from %I [%s%s]", sk->faddr,
+	bfd_state_names[s->rem_state], bfd_format_flags(pkt->flags, fb));
+
   bfd_session_process_ctl(s, pkt->flags, old_tx_int, old_rx_int);
   return 1;
 
  drop:
-  // log(L_WARN "%s: Bad packet from %I - %s (%u)", p->p.name, sk->faddr, err_dsc, err_val);
+  log(L_REMOTE "%s: Bad packet from %I - %s (%u)", p->p.name, sk->faddr, err_dsc, err_val);
   return 1;
 }
 
@@ -161,7 +189,7 @@ bfd_open_rx_sk(struct bfd_proto *p, int multihop)
   sk->sport = !multihop ? BFD_CONTROL_PORT : BFD_MULTI_CTL_PORT;
   sk->data = p;
 
-  sk->rbsize = 64; // XXX
+  sk->rbsize = BFD_MAX_LEN;
   sk->rx_hook = bfd_rx_hook;
   sk->err_hook = bfd_err_hook;
 
@@ -195,7 +223,7 @@ bfd_open_tx_sk(struct bfd_proto *p, ip_addr local, struct iface *ifa)
   sk->iface = ifa;
   sk->data = p;
 
-  sk->tbsize = 64; // XXX
+  sk->tbsize = BFD_MAX_LEN;
   sk->err_hook = bfd_err_hook;
 
   /* TODO: configurable ToS, priority and TTL security */
diff --git a/sysdep/unix/io.c b/sysdep/unix/io.c
index f3ea5d39..f0ec6dae 100644
--- a/sysdep/unix/io.c
+++ b/sysdep/unix/io.c
@@ -538,6 +538,9 @@ sk_free(resource *r)
   if (s->fd >= 0)
     {
       close(s->fd);
+      if (s->flags & SKF_THREAD)
+	return;
+
       if (s == current_sock)
 	current_sock = sk_next(s);
       if (s == stored_sock)
diff --git a/sysdep/unix/log.c b/sysdep/unix/log.c
index f3a66f8b..67b70773 100644
--- a/sysdep/unix/log.c
+++ b/sysdep/unix/log.c
@@ -32,8 +32,17 @@ static FILE *dbgf;
 static list *current_log_list;
 static char *current_syslog_name; /* NULL -> syslog closed */
 
-bird_clock_t rate_limit_time = 5;
-int rate_limit_count = 5;
+static const bird_clock_t rate_limit_time = 5;
+static const int rate_limit_count = 5;
+
+
+// XXX add ifdef for threads
+
+#include <pthread.h>
+static pthread_mutex_t log_mutex;
+static inline void log_lock(void) { pthread_mutex_lock(&log_mutex); }
+static inline void log_unlock(void) { pthread_mutex_unlock(&log_mutex); }
+
 
 #ifdef HAVE_SYSLOG
 #include <sys/syslog.h>
@@ -65,28 +74,6 @@ static char *class_names[] = {
   "BUG"
 };
 
-#define LOG_BUFFER_SIZE 1024
-static char log_buffer[LOG_BUFFER_SIZE];
-static char *log_buffer_pos;
-static int log_buffer_remains;
-
-const char *log_buffer_ptr = log_buffer;
-
-
-/**
- * log_reset - reset the log buffer
- *
- * This function resets a log buffer and discards buffered
- * messages. Should be used before a log message is prepared
- * using logn().
- */
-void
-log_reset(void)
-{
-  log_buffer_pos = log_buffer;
-  log_buffer_remains = LOG_BUFFER_SIZE;
-  log_buffer[0] = 0;
-}
 
 /**
  * log_commit - commit a log message
@@ -101,10 +88,14 @@ log_reset(void)
  * in log(), so it should be written like *L_INFO.
  */
 void
-log_commit(int class)
+log_commit(int class, buffer *buf)
 {
   struct log_config *l;
 
+  if (buf->pos == buf->end)
+    strcpy(buf->end - 100, " ... <too long>");
+
+  log_lock();
   WALK_LIST(l, *current_log_list)
     {
       if (!(l->mask & (1 << class)))
@@ -119,47 +110,30 @@ log_commit(int class)
 	      tm_format_datetime(tbuf, &config->tf_log, now);
 	      fprintf(l->fh, "%s <%s> ", tbuf, class_names[class]);
 	    }
-	  fputs(log_buffer, l->fh);
+	  fputs(buf->start, l->fh);
 	  fputc('\n', l->fh);
 	  fflush(l->fh);
 	}
 #ifdef HAVE_SYSLOG
       else
-	syslog(syslog_priorities[class], "%s", log_buffer);
+	syslog(syslog_priorities[class], "%s", buf->start);
 #endif
     }
-  cli_echo(class, log_buffer);
-
-  log_reset();
-}
-
-static void
-log_print(const char *msg, va_list args)
-{
-  int i;
-
-  if (log_buffer_remains == 0)
-    return;
-
-  i=bvsnprintf(log_buffer_pos, log_buffer_remains, msg, args);
-  if (i < 0)
-    {
-      bsprintf(log_buffer + LOG_BUFFER_SIZE - 100, " ... <too long>");
-      log_buffer_remains = 0;
-      return;
-    }
+  log_unlock();
 
-  log_buffer_pos += i;
-  log_buffer_remains -= i;
+  /* FIXME: cli_echo is not thread-safe */
+  cli_echo(class, buf->start);
 }
 
+int buffer_vprint(buffer *buf, const char *fmt, va_list args);
 
 static void
 vlog(int class, const char *msg, va_list args)
 {
-  log_reset();
-  log_print(msg, args);
-  log_commit(class);
+  buffer buf;
+  LOG_BUFFER_INIT(buf);
+  buffer_vprint(&buf, msg, args);
+  log_commit(class, &buf);
 }
 
 
@@ -188,26 +162,6 @@ log_msg(char *msg, ...)
   va_end(args);
 }
 
-/**
- * logn - prepare a partial message in the log buffer
- * @msg: printf-like formatting string (without message class information)
- *
- * This function formats a message according to the format string @msg
- * and adds it to the log buffer. Messages in the log buffer are
- * logged when the buffer is flushed using log_commit() function. The
- * message should not contain |\n|, log_commit() also terminates a
- * line.
- */
-void
-logn(char *msg, ...)
-{
-  va_list args;
-
-  va_start(args, msg);
-  log_print(msg, args);
-  va_end(args);
-}
-
 void
 log_rl(struct rate_limit *rl, char *msg, ...)
 {
diff --git a/sysdep/unix/main.c b/sysdep/unix/main.c
index bd80ba2c..ecf67b65 100644
--- a/sysdep/unix/main.c
+++ b/sysdep/unix/main.c
@@ -199,7 +199,7 @@ unix_read_config(struct config **cp, char *name)
   return ret;
 }
 
-static void
+static struct config *
 read_config(void)
 {
   struct config *conf;
@@ -211,7 +211,8 @@ read_config(void)
       else
 	die("Unable to open configuration file %s: %m", config_name);
     }
-  config_commit(conf, RECONFIG_HARD, 0);
+
+  return conf;
 }
 
 void
@@ -713,7 +714,7 @@ main(int argc, char **argv)
   proto_build(&proto_unix_kernel);
   proto_build(&proto_unix_iface);
 
-  read_config();
+  struct config *conf = read_config();
 
   if (parse_and_exit)
     exit(0);
@@ -735,6 +736,8 @@ main(int argc, char **argv)
 
   signal_init();
 
+  config_commit(conf, RECONFIG_HARD, 0);
+
 #ifdef LOCAL_DEBUG
   async_dump_flag = 1;
 #endif