Implemented echoing of log messages to CLI connections. Just try `echo all'.

TODO

@@ -33,9 +33,6 @@ Core
 - krt: rescan interfaces when route addition fails?
 - krt: does PERSIST mode have any sense if kernel syncer is shut down as last?
 
-- cmdline: implement
-- cmdline: echo of debug/log messages
-
 - tagging of external routes?
 
 - port to FreeBSD

nest/cli.c

@@ -15,6 +15,34 @@
 
 pool *cli_pool;
 
+static byte *
+cli_alloc_out(cli *c, int size)
+{
+  struct cli_out *o;
+
+  if (!(o = c->tx_write) || o->wpos + size > o->end)
+    {
+      if (!o && c->tx_buf)
+	o = c->tx_buf;
+      else
+	{
+	  o = mb_alloc(c->pool, sizeof(struct cli_out) + CLI_TX_BUF_SIZE);
+	  if (c->tx_write)
+	    c->tx_write->next = o;
+	  else
+	    c->tx_buf = o;
+	  o->next = NULL;
+	  o->wpos = o->outpos = o->buf;
+	  o->end = o->buf + CLI_TX_BUF_SIZE;
+	}
+      c->tx_write = o;
+      if (!c->tx_pos)
+	c->tx_pos = o;
+    }
+  o->wpos += size;
+  return o->wpos - size;
+}
+
 void
 cli_printf(cli *c, int code, char *msg, ...)
 {
@@ -22,7 +50,6 @@ cli_printf(cli *c, int code, char *msg, ...)
   byte buf[1024];
   int cd = code;
   int size, cnt;
-  struct cli_out *o;
 
   va_start(args, msg);
   if (cd < 0)
@@ -46,27 +73,44 @@ cli_printf(cli *c, int code, char *msg, ...)
     }
   size += cnt;
   buf[size++] = '\n';
-  if (!(o = c->tx_write) || o->wpos + size > o->end)
+  memcpy(cli_alloc_out(c, size), buf, size);
-    {
-      if (!o && c->tx_buf)
-	o = c->tx_buf;
-      else
-	{
-	  o = mb_alloc(c->pool, sizeof(struct cli_out) + CLI_TX_BUF_SIZE);
-	  if (c->tx_write)
-	    c->tx_write->next = o;
-	  else
-	    c->tx_buf = o;
-	  o->next = NULL;
-	  o->wpos = o->outpos = o->buf;
-	  o->end = o->buf + CLI_TX_BUF_SIZE;
 }
-      c->tx_write = o;
+
-      if (!c->tx_pos)
+static void
-	c->tx_pos = o;
+cli_copy_message(cli *c)
+{
+  byte *p, *q;
+  unsigned int cnt = 2;
+
+  if (c->ring_overflow)
+    {
+      byte buf[64];
+      int n = bsprintf(buf, "<%d messages lost>\n", c->ring_overflow);
+      c->ring_overflow = 0;
+      memcpy(cli_alloc_out(c, n), buf, n);
     }
-  memcpy(o->wpos, buf, size);
+  p = c->ring_read;
-  o->wpos += size;
+  while (*p)
+    {
+      cnt++;
+      p++;
+      if (p == c->ring_end)
+	p = c->ring_buf;
+      ASSERT(p != c->ring_write);
+    }
+  c->async_msg_size += cnt;
+  q = cli_alloc_out(c, cnt);
+  *q++ = '+';
+  p = c->ring_read;
+  do
+    {
+      *q = *p++;
+      if (p == c->ring_end)
+	p = c->ring_buf;
+    }
+  while (*q++);
+  c->ring_read = p;
+  q[-1] = '\n';
 }
 
 static void
@@ -83,7 +127,7 @@ cli_free_out(cli *c)
 
   if (o = c->tx_buf)
     {
-      c->tx_write = NULL;
+      c->tx_write = c->tx_pos = NULL;
       o->wpos = o->outpos = o->buf;
       while (p = o->next)
 	{
@@ -91,6 +135,7 @@ cli_free_out(cli *c)
 	  mb_free(p);
 	}
     }
+  c->async_msg_size = 0;
 }
 
 static byte *cli_rh_pos;
@@ -140,6 +185,10 @@ cli_event(void *data)
   cli *c = data;
   int err;
 
+  while (c->ring_read != c->ring_write &&
+      c->async_msg_size < CLI_MAX_ASYNC_QUEUE)
+    cli_copy_message(c);
+
   if (c->tx_pos)
     ;
   else if (c->cont)
@@ -168,16 +217,15 @@ cli_new(void *priv)
   pool *p = rp_new(cli_pool, "CLI");
   cli *c = mb_alloc(p, sizeof(cli));
 
+  bzero(c, sizeof(cli));
   c->pool = p;
   c->priv = priv;
   c->event = ev_new(p);
   c->event->hook = cli_event;
   c->event->data = c;
-  c->tx_buf = c->tx_pos = c->tx_write = NULL;
   c->cont = cli_hello;
-  c->cleanup = NULL;
-  c->last_reply = 0;
   c->parser_pool = lp_new(c->pool, 4096);
+  c->rx_buf = mb_alloc(c->pool, CLI_RX_BUF_SIZE);
   ev_schedule(c->event);
   return c;
 }
@@ -196,9 +244,80 @@ cli_written(cli *c)
   ev_schedule(c->event);
 }
 
+static list cli_log_hooks;
+static int cli_log_inited;
+
+void
+cli_set_log_echo(cli *c, unsigned int mask, unsigned int size)
+{
+  if (c->ring_buf)
+    {
+      mb_free(c->ring_buf);
+      c->ring_buf = c->ring_end = c->ring_read = c->ring_write = NULL;
+      rem_node(&c->n);
+    }
+  c->log_mask = mask;
+  if (mask && size)
+    {
+      c->ring_buf = mb_alloc(c->pool, size);
+      c->ring_end = c->ring_buf + size;
+      c->ring_read = c->ring_write = c->ring_buf;
+      add_tail(&cli_log_hooks, &c->n);
+      c->log_threshold = size / 8;
+    }
+  c->ring_overflow = 0;
+}
+
+void
+cli_echo(unsigned int class, byte *msg)
+{
+  unsigned len, free, i, l;
+  cli *c;
+  byte *m;
+
+  if (!cli_log_inited || EMPTY_LIST(cli_log_hooks))
+    return;
+  len = strlen(msg) + 1;
+  WALK_LIST(c, cli_log_hooks)
+    {
+      if (!(c->log_mask & (1 << class)))
+	continue;
+      if (c->ring_read <= c->ring_write)
+	free = (c->ring_end - c->ring_buf) - (c->ring_write - c->ring_read + 1);
+      else
+	free = c->ring_read - c->ring_write - 1;
+      if (len > free ||
+	  free < c->log_threshold && class < (unsigned) L_INFO[0])
+	{
+	  c->ring_overflow++;
+	  continue;
+	}
+      if (c->ring_read == c->ring_write)
+	ev_schedule(c->event);
+      m = msg;
+      l = len;
+      while (l)
+	{
+	  if (c->ring_read <= c->ring_write)
+	    i = c->ring_end - c->ring_write;
+	  else
+	    i = c->ring_read - c->ring_write;
+	  if (i > l)
+	    i = l;
+	  memcpy(c->ring_write, m, i);
+	  m += i;
+	  l -= i;
+	  c->ring_write += i;
+	  if (c->ring_write == c->ring_end)
+	    c->ring_write = c->ring_buf;
+	}
+    }
+}
+
 void
 cli_free(cli *c)
 {
+  cli_set_log_echo(c, 0, 0);
   if (c->cleanup)
     c->cleanup(c);
   rfree(c->pool);
@@ -208,4 +327,6 @@ void
 cli_init(void)
 {
   cli_pool = rp_new(&root_pool, "CLI");
+  init_list(&cli_log_hooks);
+  cli_log_inited = 1;
 }

nest/cli.h

@@ -14,6 +14,7 @@
 
 #define CLI_RX_BUF_SIZE 4096
 #define CLI_TX_BUF_SIZE 4096
+#define CLI_MAX_ASYNC_QUEUE 4096
 
 struct cli_out {
   struct cli_out *next;
@@ -22,10 +23,10 @@ struct cli_out {
 };
 
 typedef struct cli {
+  node n;				/* Node in list of all log hooks */
   pool *pool;
   void *priv;				/* Private to sysdep layer */
-  byte rx_buf[CLI_RX_BUF_SIZE];
+  byte *rx_buf, *rx_pos, *rx_aux;	/* sysdep */
-  byte *rx_pos, *rx_aux;		/* sysdep */
   struct cli_out *tx_buf, *tx_pos, *tx_write;
   event *event;
   void (*cont)(struct cli *c);
@@ -33,6 +34,12 @@ typedef struct cli {
   void *rover;				/* Private to continuation routine */
   int last_reply;
   struct linpool *parser_pool;		/* Pool used during parsing */
+  byte *ring_buf;			/* Ring buffer for asynchronous messages */
+  byte *ring_end, *ring_read, *ring_write;	/* Pointers to the ring buffer */
+  unsigned int ring_overflow;		/* Counter of ring overflows */
+  unsigned int log_mask;		/* Mask of allowed message levels */
+  unsigned int log_threshold;		/* When free < log_threshold, store only important messages */
+  unsigned int async_msg_size;		/* Total size of async messages queued in tx_buf */
 } cli;
 
 extern pool *cli_pool;
@@ -42,6 +49,7 @@ extern struct cli *this_cli;		/* Used during parsing */
 
 void cli_printf(cli *, int, char *, ...);
 #define cli_msg(x...) cli_printf(this_cli, x)
+void cli_set_log_echo(cli *, unsigned int mask, unsigned int size);
 
 /* Functions provided to sysdep layer */
 
@@ -50,6 +58,7 @@ void cli_init(void);
 void cli_free(cli *);
 void cli_kick(cli *);
 void cli_written(cli *);
+void cli_echo(unsigned int class, byte *msg);
 
 /* Functions provided by sysdep layer */
 

nest/config.Y

@@ -29,6 +29,7 @@ CF_ENUM(T_ENUM_RTS, RTS_, DUMMY, STATIC, INHERIT, DEVICE, STATIC_DEVICE, REDIREC
 %type <p> password_list password_begin
 %type <s> optsym
 %type <ra> r_args
+%type <i> echo_mask echo_size
 
 CF_GRAMMAR
 
@@ -253,19 +254,38 @@ r_args:
 
 CF_CLI_HELP(DEBUG, <subsystem>, [[Show debugging information]])
 CF_CLI(DEBUG RESOURCES,,, [[Show all allocated resource]])
-{ rdump(&root_pool); cli_msg(0, ""); }
+{ rdump(&root_pool); cli_msg(0, ""); } ;
 CF_CLI(DEBUG SOCKETS,,, [[Show open sockets]])
-{ sk_dump_all(); cli_msg(0, ""); }
+{ sk_dump_all(); cli_msg(0, ""); } ;
 CF_CLI(DEBUG INTERFACES,,, [[Show interface information]])
-{ if_dump_all(); cli_msg(0, ""); }
+{ if_dump_all(); cli_msg(0, ""); } ;
 CF_CLI(DEBUG NEIGHBORS,,, [[Show neighbor cache]])
-{ neigh_dump_all(); cli_msg(0, ""); }
+{ neigh_dump_all(); cli_msg(0, ""); } ;
 CF_CLI(DEBUG ATTRIBUTES,,, [[Show attribute cache]])
-{ rta_dump_all(); cli_msg(0, ""); }
+{ rta_dump_all(); cli_msg(0, ""); } ;
 CF_CLI(DEBUG ROUTES,,, [[Show routing table]])
-{ rt_dump_all(); cli_msg(0, ""); }
+{ rt_dump_all(); cli_msg(0, ""); } ;
 CF_CLI(DEBUG PROTOCOLS,,, [[Show protocol information]])
-{ protos_dump_all(); cli_msg(0, ""); }
+{ protos_dump_all(); cli_msg(0, ""); } ;
+
+CF_CLI(ECHO, echo_mask echo_size, [all | off | <mask>] [<buffer-size>], [[Configure echoing of log messages]]) {
+  cli_set_log_echo(this_cli, $2, $3);
+  cli_msg(0, "");
+} ;
+
+echo_mask:
+   ALL { $$ = ~0; }
+ | OFF { $$ = 0; }
+ | NUM
+ ;
+
+echo_size:
+   /* empty */ { $$ = 4096; }
+ | NUM {
+     if ($1 < 256 || $1 > 65536) cf_error("Invalid log buffer size");
+     $$ = $1;
+   }
+ ;
 
 CF_CODE
 

sysdep/unix/client-main.c

@@ -14,6 +14,7 @@
 #include "nest/bird.h"
 #include "lib/resource.h"	/* For dmalloc */
 #include "client/client.h"
+#include "nest/cli.h"
 
 #include "unix.h"
 
@@ -41,6 +42,11 @@ parse_args(int argc, char **argv)
     usage();
 }
 
+void
+cli_echo(unsigned int class, byte *buf)
+{
+}
+
 int
 client_main(int argc, char **argv)
 {

sysdep/unix/log.c

@@ -1,7 +1,7 @@
 /*
  *	BIRD Library -- Logging Functions
  *
- *	(c) 1998 Martin Mares <mj@ucw.cz>
+ *	(c) 1998--1999 Martin Mares <mj@ucw.cz>
  *
  *	Can be freely distributed and used under the terms of the GNU GPL.
  */
@@ -12,6 +12,7 @@
 #include <sys/time.h>
 
 #include "nest/bird.h"
+#include "nest/cli.h"
 #include "lib/string.h"
 
 static int log_inited;
@@ -42,40 +43,21 @@ static char *class_names[] = {
   "FATAL"
 };
 
-/* FIXME: Use better buffering */
-
-static void
-bvfprintf(FILE *f, char *fmt, va_list args)
-{
-  char buf[4096];
-  int n;
-
-  n = bvsnprintf(buf, sizeof(buf), fmt, args);
-  if (n >= 0)
-    fwrite(buf, n, sizeof(char), f);
-  else
-    fprintf(stderr, "BIRD: warning: logging buffer overflow!\n");
-}
-
-static void
-bfprintf(FILE *f, char *fmt, ...)
-{
-  va_list args;
-
-  va_start(args, fmt);
-  bvfprintf(f, fmt, args);
-  va_end(args);
-}
-
 static void
 vlog(int class, char *msg, va_list args)
 {
+  char buf[1024];
+  char date[32];
+
+  if (bvsnprintf(buf, sizeof(buf)-1, msg, args) < 0)
+    bsprintf(buf + sizeof(buf) - 100, " ... <too long>");
+
   if (logf)
     {
       time_t now = time(NULL);
       struct tm *tm = localtime(&now);
 
-      bfprintf(logf, "%02d-%02d-%04d %02d:%02d:%02d <%s> ",
+      bsprintf(date, "%02d-%02d-%04d %02d:%02d:%02d <%s> ",
 	       tm->tm_mday,
 	       tm->tm_mon+1,
 	       tm->tm_year+1900,
@@ -83,21 +65,23 @@ vlog(int class, char *msg, va_list args)
 	       tm->tm_min,
 	       tm->tm_sec,
 	       class_names[class]);
-      bvfprintf(logf, msg, args);
+      fputs(date, logf);
+      fputs(buf, logf);
       fputc('\n', logf);
       fflush(logf);
     }
 #ifdef HAVE_SYSLOG
   else if (log_inited)
-    vsyslog(syslog_priorities[class], msg, args);
+    syslog(syslog_priorities[class], "%s", buf);
 #endif
   else
     {
       fputs("bird: ", stderr);
-      bvfprintf(stderr, msg, args);
+      fputs(buf, stderr);
       fputc('\n', stderr);
       fflush(stderr);
     }
+  cli_echo(class, buf);
 }
 
 void
@@ -137,10 +121,13 @@ void
 debug(char *msg, ...)
 {
   va_list args;
+  char buf[1024];
 
   va_start(args, msg);
+  if (bvsnprintf(buf, sizeof(buf), msg, args) < 0)
+    bsprintf(buf + sizeof(buf) - 100, " ... <too long>\n");
   if (dbgf)
-    bvfprintf(dbgf, msg, args);
+    fputs(buf, dbgf);
   va_end(args);
 }