Changes print-like filter commands to use a log instead of a stderr.

And extends the log subsystem to better handle that.

6 files changed, 169 insertions, 77 deletions

diff --git a/filter/filter.c b/filter/filter.c
index 81a43117..3b150a74 100644
--- a/filter/filter.c
+++ b/filter/filter.c
@@ -350,49 +350,61 @@ val_in_range(struct f_val v1, struct f_val v2)
   return CMP_ERROR;
 }
 
+static void val_print(struct f_val v);
+
 static void
-tree_print(struct f_tree *t)
+tree_node_print(struct f_tree *t, char **sep)
 {
-  if (!t) {
-    debug( "() " );
+  if (t == NULL)
     return;
-  }
-  debug( "[ " );
-  tree_print( t->left );
-  debug( ", " ); val_print( t->from ); debug( ".." ); val_print( t->to ); debug( ", " );
-  tree_print( t->right );
-  debug( "] " );
+
+  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
  */
-void
+static void
 val_print(struct f_val v)
 {
-  char buf[2048];
   char buf2[1024];
-#define PRINTF(a...) bsnprintf( buf, 2040, a )
-  buf[0] = 0;
   switch (v.type) {
-  case T_VOID: PRINTF( "(void)" ); break;
-  case T_BOOL: PRINTF( v.val.i ? "TRUE" : "FALSE" ); break;
-  case T_INT: PRINTF( "%d ", v.val.i ); break;
-  case T_STRING: PRINTF( "%s", v.val.s ); break;
-  case T_IP: PRINTF( "%I", v.val.px.ip ); break;
-  case T_PREFIX: PRINTF( "%I/%d", v.val.px.ip, v.val.px.len ); break;
-  case T_PAIR: PRINTF( "(%d,%d)", v.val.i >> 16, v.val.i & 0xffff ); break;
-  case T_QUAD: PRINTF( "%R", v.val.i ); break;
-  case T_PREFIX_SET: trie_print(v.val.ti, buf, 2040); break;
-  case T_SET: tree_print( v.val.t ); PRINTF( "\n" ); break;
-  case T_ENUM: PRINTF( "(enum %x)%d", v.type, v.val.i ); break;
-  case T_PATH: as_path_format(v.val.ad, buf2, 1020); PRINTF( "(path %s)", buf2 ); break;
-  case T_CLIST: int_set_format(v.val.ad, 1, buf2, 1020); PRINTF( "(clist %s)", buf2 ); break;
-  case T_PATH_MASK: pm_format(v.val.path_mask, buf2, 1020); PRINTF( "(pathmask%s)", buf2 ); break;
-  default: PRINTF( "[unknown type %x]", v.type );
-#undef PRINTF
+  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_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, buf2, 1000); logn("(clist %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;
   }
-  debug( buf );
 }
 
 static struct rte **f_rte, *f_rte_old;
@@ -628,7 +640,7 @@ interpret(struct f_inst *what)
   case P('p',','):
     ONEARG;
     if (what->a2.i == F_NOP || (what->a2.i != F_NONL && what->a1.p))
-      debug( "\n" );
+      log_commit(*L_INFO);
 
     switch (what->a2.i) {
     case F_QUITBIRD:
@@ -1101,7 +1113,10 @@ f_run(struct filter *filter, struct rte **rte, struct ea_list **tmp_attrs, struc
   f_rte_old = *rte;
   f_pool = tmp_pool;
   inst = filter->root;
+
+  log_reset();
   res = interpret(inst);
+
   if (res.type != T_RETURN) {
     log( L_ERR "Filter %s did not return accept nor reject. Make up your mind", filter->name); 
     return F_ERROR;
@@ -1113,6 +1128,7 @@ f_run(struct filter *filter, struct rte **rte, struct ea_list **tmp_attrs, struc
 int
 f_eval_int(struct f_inst *expr)
 {
+  /* Called independently in parse-time to eval expressions */
   struct f_val res;
 
   f_flags = 0;
@@ -1120,7 +1136,10 @@ f_eval_int(struct f_inst *expr)
   f_rte = NULL;
   f_rte_old = NULL;
   f_pool = cfg_mem;
+
+  log_reset();
   res = interpret(expr);
+
   if (res.type != T_INT)
     cf_error("Integer expression expected");
   return res.val.i;
@@ -1129,6 +1148,7 @@ f_eval_int(struct f_inst *expr)
 u32
 f_eval_asn(struct f_inst *expr)
 {
+  /* Called as a part of another interpret call, therefore no log_reset() */
   struct f_val res = interpret(expr);
   if (res.type != T_INT)
     cf_error("Can't operate with value of non-integer type in AS path mask constructor");
diff --git a/filter/filter.h b/filter/filter.h
index 91485181..c3eb8b4d 100644
--- a/filter/filter.h
+++ b/filter/filter.h
@@ -74,7 +74,7 @@ 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);
-int trie_print(struct f_trie *t, char *buf, int blen);
+void trie_print(struct f_trie *t);
 
 void fprefix_get_bounds(struct f_prefix *px, int *l, int *h);
 
@@ -107,7 +107,6 @@ 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);
 
 #define F_NOP 0
 #define F_NONL 1
diff --git a/filter/test.conf b/filter/test.conf
index c25f11aa..40fff19b 100644
--- a/filter/test.conf
+++ b/filter/test.conf
@@ -130,6 +130,7 @@ function __test2()
 
 function test_pxset(prefix set pxs)
 {
+	print pxs;
 	print "  must be true:  ",	10.0.0.0/8  ~ pxs, ",", 10.0.0.0/10  ~ pxs, ",", 10.0.0.0/12 ~ pxs, ",",
 					20.0.0.0/24 ~ pxs, ",", 20.0.40.0/24 ~ pxs, ",", 20.0.0.0/26 ~ pxs, ",",
 					20.0.100.0/26 ~ pxs, ",", 20.0.0.0/28 ~ pxs, ",", 20.0.255.0/28 ~ pxs;
@@ -212,6 +213,7 @@ string s;
 		", false: ", RTS_BGP ~ [RTS_STATIC, RTS_DEVICE];
 
 	ps = [(1,(one+one)), (3,4)..(4,8), (5,*), (6,3..6)];
+	print "Pair set: ", ps;
 	print "Testing pair set, true:  ", pp ~ ps,  "  ", (3,5) ~ ps, "  ", (4,1) ~ ps, "  ", (5,4) ~ ps, "  ", (5,65535) ~ ps, "  ", (6,4) ~ ps;
 	print "Testing pair set, false: ", (3,3) ~ ps, " ", (4,9) ~ ps, " ", (4,65535) ~ ps, " ", (6,2) ~ ps, " ", (6,(6+one)) ~ ps, " ", ((one+6),2) ~ ps ;
 
diff --git a/filter/trie.c b/filter/trie.c
index 2f0edfa9..581332c6 100644
--- a/filter/trie.c
+++ b/filter/trie.c
@@ -264,53 +264,38 @@ trie_same(struct f_trie *t1, struct f_trie *t2)
   return (t1->zero == t2->zero) && trie_node_same(&t1->root, &t2->root);
 }
 
-static int
-trie_node_print(struct f_trie_node *t, char *buf, int blen)
+static void
+trie_node_print(struct f_trie_node *t, char **sep)
 {
   if (t == NULL)
-    return 0;
-
-  int old_blen = blen;
-  int wb = 0; // bsnprintf(buf, blen, "%I/%d accept %I\n", t->addr, t->plen, t->accept);
-debug("%I/%d accept %I\n", t->addr, t->plen, t->accept);
+    return;
 
-  if ((wb < 0) || ((blen - wb) < 10))
+  if (ipa_nonzero(t->accept))
     {
-      bsnprintf(buf, blen, "...\n");
-      return -1;
+      logn("%s%I/%d{%I}", *sep, t->addr, t->plen, t->accept);
+      *sep = ", ";
     }
 
-  buf += wb;
-  blen -= wb;
-
-  wb = trie_node_print(t->c[0], buf, blen);
-  if (wb < 0)
-    return -1;
-
-  buf += wb;
-  blen -= wb;
-
-  wb = trie_node_print(t->c[1], buf, blen);
-  if (wb < 0)
-    return -1;
-
-  blen -= wb;
-
-  return (old_blen - blen);
+  trie_node_print(t->c[0], sep);
+  trie_node_print(t->c[1], sep);
 }
 
 /**
  * trie_print
  * @t: trie to be printed
- * @buf: buffer
- * @blen: buffer length
  *
- * Prints the trie to the buffer, using at most blen bytes.
- * Returns the number of used bytes, or -1 if there is not
- * enough space in the buffer.
+ * Prints the trie to the log buffer.
  */
-int
-trie_print(struct f_trie *t, char *buf, int blen)
+void
+trie_print(struct f_trie *t)
 {
-  return trie_node_print(&t->root, buf, blen);
+  char *sep = "";
+  logn("[");
+  if (t->zero)
+    {
+      logn("0.0.0.0/0");
+      sep = ", ";
+    }
+  trie_node_print(&t->root, &sep);
+  logn("]");
 }
diff --git a/lib/birdlib.h b/lib/birdlib.h
index 12a581b7..c377a646 100644
--- a/lib/birdlib.h
+++ b/lib/birdlib.h
@@ -41,8 +41,11 @@ struct rate_limit {
 };
 
 #define log log_msg
+void log_reset(void);
+void log_commit(int class);
 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/sysdep/unix/log.c b/sysdep/unix/log.c
index d4c36488..92f12f1e 100644
--- a/sysdep/unix/log.c
+++ b/sysdep/unix/log.c
@@ -65,14 +65,43 @@ static char *class_names[] = {
   "BUG"
 };
 
-static void
-vlog(int class, char *msg, va_list args)
+#define LOG_BUFFER_SIZE 1024
+static char log_buffer[LOG_BUFFER_SIZE];
+static char *log_buffer_pos;
+static int log_buffer_remains;
+
+
+/**
+ * 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)
 {
-  char buf[1024];
-  struct log_config *l;
+  log_buffer_pos = log_buffer;
+  log_buffer_remains = LOG_BUFFER_SIZE;
+  log_buffer[0] = 0;
+}
 
-  if (bvsnprintf(buf, sizeof(buf)-1, msg, args) < 0)
-    bsprintf(buf + sizeof(buf) - 100, " ... <too long>");
+/**
+ * log_commit - commit a log message
+ * @class: message class information (%L_DEBUG to %L_BUG, see |lib/birdlib.h|)
+ *
+ * This function writes a message prepared in the log buffer to the
+ * log file (as specified in the configuration). The log buffer is
+ * reset after that. The log message is a full line, log_commit()
+ * terminates it.
+ *
+ * The message class is an integer, not a first char of a string like
+ * in log(), so it should be written like *L_INFO.
+ */
+void
+log_commit(int class)
+{
+  struct log_config *l;
 
   WALK_LIST(l, *current_log_list)
     {
@@ -88,18 +117,51 @@ vlog(int class, char *msg, va_list args)
 	      tm_format_datetime(tbuf, &config->tf_log, now);
 	      fprintf(l->fh, "%s <%s> ", tbuf, class_names[class]);
 	    }
-	  fputs(buf, l->fh);
+	  fputs(log_buffer, l->fh);
 	  fputc('\n', l->fh);
 	  fflush(l->fh);
 	}
 #ifdef HAVE_SYSLOG
       else
-	syslog(syslog_priorities[class], "%s", buf);
+	syslog(syslog_priorities[class], "%s", log_buffer);
 #endif
     }
-  cli_echo(class, buf);
+  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_buffer_pos += i;
+  log_buffer_remains -= i;
+}
+
+
+static void
+vlog(int class, const char *msg, va_list args)
+{
+  log_reset();
+  log_print(msg, args);
+  log_commit(class);
+}
+
+
+
 /**
  * log - log a message
  * @msg: printf-like formatting string with message class information
@@ -109,6 +171,7 @@ vlog(int class, char *msg, va_list args)
  * and writes it to the corresponding log file (as specified in the
  * configuration). Please note that the message is automatically
  * formatted as a full line, no need to include |\n| inside.
+ * It is essentially a sequence of log_reset(), logn() and log_commit().
  */
 void
 log_msg(char *msg, ...)
@@ -123,6 +186,26 @@ 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, ...)
 {