Merge commit '2c7555cf2ac8439713dd9148b348128c57222a38' into thread-next

The UDP logging had to be substantially rewritten due to a different
logging backend and reconfiguration mechanisms.

Conflicts:
	doc/bird.sgml
	sysdep/unix/config.Y
	sysdep/unix/io.c
	sysdep/unix/log.c
	sysdep/unix/unix.h

doc/bird.sgml

@@ -543,11 +543,12 @@ ipv6 table
 include "tablename.conf";;
 </code>
 
-	<tag><label id="opt-log">log "<m/filename/" [<m/limit/ "<m/backup/"] | fixed "<m/filename/" <m/size/ | syslog [name <m/name/] | stderr all|{ <m/list of classes/ }</tag>
+	<tag><label id="opt-log">log "<m/filename/" [<m/limit/ "<m/backup/"] | fixed "<m/filename/" <m/size/ | syslog [name <m/name/] | stderr | udp <m/address/ [port <m/port/] all|{ <m/list of classes/ }</tag>
 	Set logging of messages having the given class (either <cf/all/ or <cf>{
 	error|trace [, <m/.../] }</cf> etc.) into selected destination - a file
 	specified as a filename string (with optional log rotation information),
-	syslog (with optional name argument), or the stderr output.
+	syslog (with optional name argument), the stderr output, or as a UDP
+	message (in <rfc id="3164"> syslog format).
 
 	Classes are:
 	<cf/info/, <cf/warning/, <cf/error/ and <cf/fatal/ for messages about local problems,

lib/birdlib.h

@@ -165,6 +165,7 @@ typedef struct buffer {
 
 enum log_buffer_pos {
   LBP_TIMESTAMP = 0,
+  LBP_UDP_HEADER,
   LBP_THREAD_ID,
   LBP_CLASS,
   LBP_MSG,

lib/socket.h

@@ -133,6 +133,7 @@ extern int sk_priority_control;		/* Suggested priority for control traffic, shou
 #define SKF_BIND	0x10	/* Bind datagram socket to given source address */
 #define SKF_HIGH_PORT	0x20	/* Choose port from high range if possible */
 #define SKF_FREEBIND	0x40	/* Allow socket to bind to a nonlocal address */
+#define SKF_CONNECT	0x80	/* Connect datagram socket to given dst address/port */
 
 #define SKF_TRUNCATED	0x200	/* Received packet was truncated, set by IO layer */
 #define SKF_HDRINCL	0x400	/* Used internally */

sysdep/unix/config.Y

@@ -17,7 +17,7 @@ static struct log_config *this_log;
 
 CF_DECLS
 
-CF_KEYWORDS(LOG, SYSLOG, ALL, DEBUG, TRACE, INFO, REMOTE, WARNING, ERROR, AUTH, FATAL, BUG, STDERR, SOFT)
+CF_KEYWORDS(LOG, SYSLOG, ALL, DEBUG, TRACE, INFO, REMOTE, WARNING, ERROR, AUTH, FATAL, BUG, STDERR, SOFT, UDP, PORT)
 CF_KEYWORDS(NAME, CONFIRM, UNDO, CHECK, TIMEOUT, DEBUG, LATENCY, LIMIT, WATCHDOG, WARNING, STATUS)
 CF_KEYWORDS(GRACEFUL, RESTART, FIXED)
 
@@ -67,8 +67,23 @@ log_file:
    }
  | SYSLOG syslog_name { this_log->rf = NULL; new_config->syslog_name = $2; }
  | STDERR { this_log->rf = &rf_stderr; this_log->terminal_flag = 1; }
+ | UDP log_udp_host log_udp_port { this_log->rf = NULL; }
  ;
 
+log_udp_host: text_or_ipa
+{
+  if ($1.type == T_STRING)
+    this_log->udp_host = $1.val.s;
+  else if ($1.type == T_IP)
+    this_log->udp_ip = $1.val.ip;
+  else bug("Bad text_or_ipa");
+};
+
+log_udp_port:
+    /* empty */ { this_log->udp_port = 514; }
+  | PORT NUM { check_u16($2); this_log->udp_port = $2; }
+  ;
+
 log_mask:
    ALL { $$ = ~0; }
  | '{' log_mask_list '}' { $$ = $2; }

sysdep/unix/io.c

@@ -32,6 +32,7 @@
 #include <netinet/tcp.h>
 #include <netinet/udp.h>
 #include <netinet/icmp6.h>
+#include <netdb.h>
 
 #include "nest/bird.h"
 #include "lib/lists.h"
@@ -139,7 +140,6 @@ struct rfile *
 rf_open(pool *p, const char *name, enum rf_mode mode, off_t limit)
 {
   int fd = rf_open_get_fd(name, mode);
-
   if (fd < 0)
     return NULL; /* The caller takes care of printing %m. */
 
@@ -170,6 +170,7 @@ rf_open(pool *p, const char *name, enum rf_mode mode, off_t limit)
       bug("rf_open() must have the mode set");
   }
 
+
   return r;
 }
 
@@ -1186,6 +1187,14 @@ sk_setup(sock *s)
   return 0;
 }
 
+static int
+sk_connect(sock *s)
+{
+  sockaddr sa;
+  sockaddr_fill(&sa, s->af, s->daddr, s->iface, s->dport);
+  return connect(s->fd, &sa.sa, SA_LEN(sa));
+}
+
 static void
 sk_tcp_connected(sock *s)
 {
@@ -1627,8 +1636,7 @@ sk_open(sock *s, struct birdloop *loop)
   switch (s->type)
   {
   case SK_TCP_ACTIVE:
-    sockaddr_fill(&sa, s->af, s->daddr, s->iface, s->dport);
+    if (sk_connect(s) >= 0)
-    if (connect(fd, &sa.sa, SA_LEN(sa)) >= 0)
       sk_tcp_connected(s);
     else if (errno != EINTR && errno != EAGAIN && errno != EINPROGRESS &&
 	     errno != ECONNREFUSED && errno != EHOSTUNREACH && errno != ENETUNREACH)
@@ -1640,6 +1648,14 @@ sk_open(sock *s, struct birdloop *loop)
       ERR2("listen");
     break;
 
+  case SK_UDP:
+    if (s->flags & SKF_CONNECT)
+      if (sk_connect(s) < 0)
+	ERR2("connect");
+
+    sk_alloc_bufs(s);
+    break;
+
   case SK_SSH_ACTIVE:
   case SK_MAGIC:
     break;
@@ -2117,10 +2133,7 @@ sk_write_noflush(sock *s)
   {
   case SK_TCP_ACTIVE:
     {
-      sockaddr sa;
+      if (sk_connect(s) >= 0 || errno == EISCONN)
-      sockaddr_fill(&sa, s->af, s->daddr, s->iface, s->dport);
-
-      if (connect(s->fd, &sa.sa, SA_LEN(sa)) >= 0 || errno == EISCONN)
 	sk_tcp_connected(s);
       else if (errno != EINTR && errno != EAGAIN && errno != EINPROGRESS)
 	s->err_hook(s, errno);
@@ -2565,3 +2578,36 @@ test_old_bird(char *path)
     die("I found another BIRD running.");
   close(fd);
 }
+
+
+/*
+ *	DNS resolver
+ */
+
+ip_addr
+resolve_hostname(const char *host, int type, const char **err_msg)
+{
+  struct addrinfo *res;
+  struct addrinfo hints = {
+    .ai_family = AF_UNSPEC,
+    .ai_socktype = (type == SK_UDP) ? SOCK_DGRAM : SOCK_STREAM,
+    .ai_flags = AI_ADDRCONFIG,
+  };
+
+  *err_msg = NULL;
+
+  int err_code = getaddrinfo(host, NULL, &hints, &res);
+  if (err_code != 0)
+  {
+    *err_msg = gai_strerror(err_code);
+    return IPA_NONE;
+  }
+
+  ip_addr addr = IPA_NONE;
+  uint unused;
+
+  sockaddr_read((sockaddr *) res->ai_addr, res->ai_family, &addr, NULL, &unused);
+  freeaddrinfo(res);
+
+  return addr;
+}

sysdep/unix/log.c

@@ -28,6 +28,7 @@
 #include "conf/conf.h"
 #include "lib/string.h"
 #include "lib/lists.h"
+#include "lib/socket.h"
 #include "sysdep/unix/unix.h"
 #include "sysdep/unix/io-loop.h"
 
@@ -91,12 +92,17 @@ struct log_channel {
   _Atomic uint mask;			/* Classes to log */
   uint new_mask;			/* Pending new mask */
   uint prepare;				/* Which message parts to prepare */
+  const char *udp_host;			/* UDP log dst host name */
+  ip_addr udp_ip;			/* UDP log dst IP address */
+  uint udp_port;			/* UDP log dst port */
+  sock * _Atomic udp_sk;		/* UDP socket */
 };
 
 struct log_thread_syncer {
   struct bird_thread_syncer sync;
   struct log_channel *lc_close;
   struct rfile *rf_close;
+  sock *sk_close;
   const char *name;
   event lts_event;
 };
@@ -110,12 +116,16 @@ lts_done(struct bird_thread_syncer *sync)
   if (lts->lc_close)
   {
     lts->rf_close = atomic_load_explicit(&lts->lc_close->rf, memory_order_relaxed);
+    lts->sk_close = atomic_load_explicit(&lts->lc_close->udp_sk, memory_order_relaxed);
     mb_free(lts->lc_close);
   }
 
   if (lts->rf_close && lts->rf_close != &rf_stderr)
     rfree(lts->rf_close);
 
+  if (lts->sk_close)
+    rfree(lts->sk_close);
+
   mb_free(lts);
   log_unlock();
 }
@@ -154,8 +164,6 @@ log_rotate(struct log_channel *lc)
   atomic_store_explicit(&lc->rf, rf, memory_order_release);
 }
 
-#define LOG_MSG_OFFSET	(TM_DATETIME_BUFFER_SIZE + 64)
-
 /**
  * log_commit - commit a log message
  * @class: message class information (%L_DEBUG to %L_BUG, see |lib/birdlib.h|)
@@ -192,7 +200,9 @@ log_commit(log_buffer *buf)
 	continue;
 
       struct rfile *rf = atomic_load_explicit(&l->rf, memory_order_acquire);
-      if (rf)
+      sock *sk = atomic_load_explicit(&l->udp_sk, memory_order_acquire);
+
+      if (rf || sk)
 	{
 	  /* Construct the iovec */
 	  static char terminal_prefix[] = "bird: ",
@@ -218,28 +228,37 @@ log_commit(log_buffer *buf)
 		};
 	    }
 
-	  iov[iov_count++] = (struct iovec) {
+	  if (rf)
-	    .iov_base = newline,
+	  {
-	    .iov_len = sizeof newline - 1,
+	    iov[iov_count++] = (struct iovec) {
-	  };
+	      .iov_base = newline,
+	      .iov_len = sizeof newline - 1,
+	    };
 
-	  do {
+	    do {
-	    if (rf_writev(rf, iov, iov_count))
+	      if (rf_writev(rf, iov, iov_count))
-	      break;
+		break;
 
-	    log_lock();
+	      log_lock();
-	    rf = atomic_load_explicit(&l->rf, memory_order_acquire);
+	      rf = atomic_load_explicit(&l->rf, memory_order_acquire);
-	    if (rf_writev(rf, iov, iov_count))
+	      if (rf_writev(rf, iov, iov_count))
-	    {
+	      {
+		log_unlock();
+		break;
+	      }
+
+	      log_rotate(l);
 	      log_unlock();
-	      break;
-	    }
 
-	    log_rotate(l);
+	      rf = atomic_load_explicit(&l->rf, memory_order_relaxed);
-	    log_unlock();
+	    } while (!rf_writev(rf, iov, iov_count));
-
+	  }
-	    rf = atomic_load_explicit(&l->rf, memory_order_relaxed);
+	  else if (sk)
-	  } while (!rf_writev(rf, iov, iov_count));
+	  {
+	    while ((writev(sk->fd, iov, iov_count) < 0) && (errno == EINTR))
+	      ;
+	    /* FIXME: Silently ignoring write errors */
+	  }
 	}
 #ifdef HAVE_SYSLOG_H
       else
@@ -275,6 +294,23 @@ log_prepare(log_buffer *buf, int class)
     *(buf->buf.pos++) = ' ';
   }
 
+  buf->pos[LBP_UDP_HEADER] = buf->buf.pos;
+  if (BIT32_TEST(&lf, LBP_UDP_HEADER))
+  {
+    /* Legacy RFC 3164 format, but with us precision */
+    buffer_print(&buf->buf, "<%d>", LOG_DAEMON | syslog_priorities[class]);
+
+    const char *fmt = "%b %d %T.%6f";
+    int t = tm_format_real_time(buf->buf.pos, buf->buf.end - buf->buf.pos, fmt, current_real_time());
+    if (t)
+      buf->buf.pos += t;
+    else
+      buffer_puts(&buf->buf, "<time format error>");
+
+    const char *hostname = (config && config->hostname) ? config->hostname : "<none>";
+    buffer_print(&buf->buf, " %s %s: ", hostname, bird_name);
+  }
+
   buf->pos[LBP_THREAD_ID] = buf->buf.pos;
   if (BIT32_TEST(&lf, LBP_THREAD_ID))
     buffer_print(&buf->buf, "[%04x] ", THIS_THREAD_ID);
@@ -473,6 +509,7 @@ default_log_list(int initial, const char **syslog_name)
   return &log_list;
 }
 
+
 void
 log_switch(int initial, list *logs, const char *new_syslog_name)
 {
@@ -549,15 +586,39 @@ log_switch(int initial, list *logs, const char *new_syslog_name)
 	  }
 
 	  l->rf = NULL;
+	  l->found_old = 1;
+	}
+    }
+    else if (ol->udp_port)
+    {
+      WALK_LIST(l, *logs)
+	if (
+	    (l->udp_port == ol->udp_port) && (
+	      (l->udp_host && !strcmp(l->udp_host, ol->udp_host)) ||
+	      (ipa_nonzero(l->udp_ip) && (ipa_equal(l->udp_ip, ol->udp_ip)))
+	      ))
+	{
+	  /* Merge the mask */
+	  ol->new_mask |= l->mask;
+	  total_mask |= l->mask;
+
+	  /* Merge flags */
+	  flags |= ol->prepare;
+
+	  /* The socket just stays open */
+	  l->found_old = 1;
 	}
     }
     else
+    {
       WALK_LIST(l, *logs)
-	if (!l->filename && !l->rf)
+	if (!l->filename && !l->rf && !l->udp_port)
 	{
 	  ol->new_mask |= l->mask;
 	  total_mask |= l->mask;
+	  l->found_old = 1;
 	}
+    }
 
     /* First only extend masks */
     atomic_fetch_or_explicit(&ol->mask, ol->new_mask, memory_order_acq_rel);
@@ -568,7 +629,10 @@ log_switch(int initial, list *logs, const char *new_syslog_name)
   /* Open new log channels */
   WALK_LIST(l, *logs)
   {
-    if (!l->rf)
+    if (l->found_old)
+      continue;
+
+    if (!l->rf && !l->udp_port)
       continue;
 
     /* Truly new log channel */
@@ -576,44 +640,110 @@ log_switch(int initial, list *logs, const char *new_syslog_name)
     struct log_channel *lc = mb_alloc(log_pool, sizeof *lc);
     log_unlock();
 
-    *lc = (struct log_channel) {
+    if (l->rf)
-      .filename = l->filename,
+    {
-      .backup = l->backup,
+      *lc = (struct log_channel) {
-      .rf = l->rf,
+	.filename = l->filename,
-      .limit = l->limit,
+	.backup = l->backup,
-      .new_mask = l->mask,
+	.rf = l->rf,
-      .prepare = BIT32_ALL(LBP_TIMESTAMP, LBP_THREAD_ID, LBP_CLASS, LBP_MSG) |
+	.limit = l->limit,
-	(l->terminal_flag ? BIT32_VAL(LBPP_TERMINAL) : 0),
+	.new_mask = l->mask,
-    };
+	.prepare = BIT32_ALL(LBP_TIMESTAMP, LBP_THREAD_ID, LBP_CLASS, LBP_MSG) |
+	  (l->terminal_flag ? BIT32_VAL(LBPP_TERMINAL) : 0),
+      };
+
+      /* Now the file handle ownership is transferred to the log channel */
+      l->rf = NULL;
+
+      /* Find more */
+      for (struct log_config *ll = NODE_NEXT(l); NODE_VALID(ll); ll = NODE_NEXT(ll))
+	if (ll->filename && ll->rf && rf_same(lc->rf, ll->rf))
+	{
+	  /* Merged with this channel */
+	  lc->new_mask |= ll->mask;
+	  total_mask |= ll->mask;
+
+	  if (l->rf != &rf_stderr)
+	  {
+	    log_lock();
+	    rfree(ll->rf);
+	    log_unlock();
+	  }
+	  ll->rf = NULL;
+	}
+    }
+    else if (l->udp_port)
+    {
+      sock *sk;
+
+      ASSERT(l->udp_host || ipa_nonzero(l->udp_ip));
+
+      *lc = (struct log_channel) {
+	.new_mask = l->mask,
+	.prepare = BIT32_ALL(LBP_UDP_HEADER, LBP_MSG),
+	.udp_host = l->udp_host,
+	.udp_port = l->udp_port,
+	.udp_ip = l->udp_ip,
+      };
+
+      if (lc->udp_host && ipa_zero(lc->udp_ip))
+      {
+	const char *err_msg;
+	lc->udp_ip = resolve_hostname(lc->udp_host, SK_UDP, &err_msg);
+
+	if (ipa_zero(lc->udp_ip))
+	{
+	  cf_warn("Cannot resolve hostname '%s': %s", l->udp_host, err_msg);
+	  goto resolve_fail;
+	}
+      }
+
+      log_lock();
+      sk = sk_new(log_pool);
+      log_unlock();
+      sk->type = SK_UDP;
+      sk->daddr = lc->udp_ip;
+      sk->dport = lc->udp_port;
+      sk->flags = SKF_CONNECT;
+
+      if (sk_open(sk, &main_birdloop) < 0)
+      {
+	cf_warn("Cannot open UDP log socket: %s%#m", sk->err);
+	rfree(sk);
+resolve_fail:
+	log_lock();
+	mb_free(lc);
+	log_unlock();
+	continue;
+      }
+
+      atomic_store_explicit(&lc->udp_sk, sk, memory_order_relaxed);
+
+      /* Find more */
+      for (struct log_config *ll = NODE_NEXT(l); NODE_VALID(ll); ll = NODE_NEXT(ll))
+	if (
+	    (l->udp_port == ll->udp_port) && (
+	      (l->udp_host && !strcmp(l->udp_host, ll->udp_host)) ||
+	      (ipa_nonzero(l->udp_ip) && (ipa_equal(l->udp_ip, ll->udp_ip)))
+	      ))
+	{
+	  /* Merged with this channel */
+	  lc->new_mask |= ll->mask;
+	  total_mask |= ll->mask;
+
+	  ll->found_old = 1;
+	}
+    }
 
     /* Mask union */
     total_mask |= l->mask;
 
+    /* Store the new final local mask */
+    atomic_store_explicit(&lc->mask, lc->new_mask, memory_order_release);
+
     /* Message preparation flags */
     flags |= lc->prepare;
 
-    /* Now the file handle ownership is transferred to the log channel */
-    l->rf = NULL;
-
-    /* Find more */
-    for (struct log_config *ll = NODE_NEXT(l); NODE_VALID(ll); ll = NODE_NEXT(ll))
-      if (ll->filename && ll->rf && rf_same(lc->rf, ll->rf))
-      {
-	/* Merged with this channel */
-	lc->new_mask |= ll->mask;
-	total_mask |= ll->mask;
-
-	if (l->rf != &rf_stderr)
-	{
-	  log_lock();
-	  rfree(ll->rf);
-	  log_unlock();
-	}
-	ll->rf = NULL;
-      }
-
-    atomic_store_explicit(&lc->mask, lc->new_mask, memory_order_release);
-
     /* Insert into the main log list */
     struct log_channel *head = atomic_load_explicit(&global_logs, memory_order_acquire);
     do atomic_store_explicit(&lc->next, head, memory_order_release);
@@ -635,7 +765,7 @@ log_switch(int initial, list *logs, const char *new_syslog_name)
     atomic_store_explicit(&ol->mask, ol->new_mask, memory_order_release);
 
     /* Never close syslog channel or debug */
-    if (ol->new_mask || !ol->rf || (ol->rf == dbg_rf))
+    if (ol->new_mask || (!ol->rf && !ol->udp_sk) || (ol->rf == dbg_rf))
     {
       pprev = &ol->next;
       ol = atomic_load_explicit(pprev, memory_order_acquire);

sysdep/unix/unix.h

@@ -130,6 +130,7 @@ void rf_write_crude(struct rfile *, const char *, int);
 extern struct rfile rf_stderr;
 
 void test_old_bird(char *path);
+ip_addr resolve_hostname(const char *host, int type, const char **err_msg);
 
 /* krt.c bits */
 
@@ -148,6 +149,10 @@ struct log_config {
   const char *backup;			/* Secondary filename (for log rotation) */
   off_t limit;				/* Log size limit */
   int terminal_flag;
+  int found_old;
+  const char *udp_host;			/* UDP log dst host name */
+  ip_addr udp_ip;			/* UDP log dst IP address */
+  uint udp_port;			/* UDP log dst port */
 };
 
 #endif