syslogd log_debug

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
18 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

syslogd log_debug

Alexander Bluhm
Hi,

This is the next step for refactoring internal syslogd(8) logging.

Replace logdebug() with generic log_debug() from log.c.  Implement
log_debugadd() to construct debug message incrementally.

ok?

bluhm

Index: usr.sbin/syslogd/log.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/log.c,v
retrieving revision 1.1
diff -u -p -r1.1 log.c
--- usr.sbin/syslogd/log.c 16 Mar 2017 23:55:19 -0000 1.1
+++ usr.sbin/syslogd/log.c 17 Mar 2017 00:47:46 -0000
@@ -17,8 +17,10 @@
  * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  */
 
+#include <err.h>
 #include <errno.h>
 #include <stdio.h>
+#include <stdlib.h>
 #include <string.h>
 #include <syslog.h>
 #include <time.h>
@@ -30,6 +32,8 @@ static int debug;
 static int verbose;
 static int facility;
 static const char *log_procname;
+static char *debug_ebuf;
+static size_t debug_length;
 
 void
 log_init(int n_debug, int fac)
@@ -41,6 +45,12 @@ log_init(int n_debug, int fac)
  facility = fac;
  log_procinit(__progname);
 
+ if (debug_ebuf == NULL)
+ if ((debug_ebuf = malloc(ERRBUFSIZE)) == NULL)
+ err(1, "allocate debug buffer");
+ debug_ebuf[0] = '\0';
+ debug_length = 0;
+
  tzset();
 }
 
@@ -150,16 +160,42 @@ log_info(int pri, const char *emsg, ...)
 void
 log_debug(const char *emsg, ...)
 {
- char ebuf[ERRBUFSIZE];
  va_list ap;
  int saved_errno;
 
  if (verbose) {
  saved_errno = errno;
  va_start(ap, emsg);
- vsnprintf(ebuf, sizeof(ebuf), emsg, ap);
- fprintf(stderr, "%s\n", ebuf);
+ if (debug_length < ERRBUFSIZE - 1)
+ vsnprintf(debug_ebuf + debug_length,
+    ERRBUFSIZE - debug_length, emsg, ap);
+ fprintf(stderr, "%s\n", debug_ebuf);
  fflush(stderr);
+ va_end(ap);
+ errno = saved_errno;
+ }
+ debug_ebuf[0] = '\0';
+ debug_length = 0;
+}
+
+void
+log_debugadd(const char *emsg, ...)
+{
+ size_t l;
+ va_list ap;
+ int saved_errno;
+
+ if (verbose) {
+ saved_errno = errno;
+ va_start(ap, emsg);
+ if (debug_length < ERRBUFSIZE - 1) {
+ l = vsnprintf(debug_ebuf + debug_length,
+    ERRBUFSIZE - debug_length, emsg, ap);
+ if (l < ERRBUFSIZE - debug_length)
+ debug_length += l;
+ else
+ debug_length = ERRBUFSIZE - 1;
+ }
  va_end(ap);
  errno = saved_errno;
  }
Index: usr.sbin/syslogd/log.h
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/log.h,v
retrieving revision 1.1
diff -u -p -r1.1 log.h
--- usr.sbin/syslogd/log.h 16 Mar 2017 23:55:19 -0000 1.1
+++ usr.sbin/syslogd/log.h 17 Mar 2017 00:47:53 -0000
@@ -38,6 +38,8 @@ void log_info(int, const char *, ...)
     __attribute__((__format__ (printf, 2, 3)));
 void log_debug(const char *, ...)
     __attribute__((__format__ (printf, 1, 2)));
+void log_debugadd(const char *, ...)
+    __attribute__((__format__ (printf, 1, 2)));
 void logit(int, const char *, ...)
     __attribute__((__format__ (printf, 2, 3)));
 void vlog(int, const char *, va_list)
Index: usr.sbin/syslogd/privsep.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/privsep.c,v
retrieving revision 1.66
diff -u -p -r1.66 privsep.c
--- usr.sbin/syslogd/privsep.c 30 Dec 2016 23:21:26 -0000 1.66
+++ usr.sbin/syslogd/privsep.c 17 Mar 2017 00:08:48 -0000
@@ -35,6 +35,7 @@
 #include <unistd.h>
 #include <utmp.h>
 
+#include "log.h"
 #include "syslogd.h"
 
 /*
@@ -208,7 +209,7 @@ priv_exec(char *conf, int numeric, int c
  sigaction(SIGCHLD, &sa, NULL);
 
  setproctitle("[priv]");
- logdebug("[priv]: fork+exec done\n");
+ log_debug("[priv]: fork+exec done");
 
  sigemptyset(&sigmask);
  if (sigprocmask(SIG_SETMASK, &sigmask, NULL) == -1)
@@ -226,7 +227,7 @@ priv_exec(char *conf, int numeric, int c
  break;
  switch (cmd) {
  case PRIV_OPEN_TTY:
- logdebug("[priv]: msg PRIV_OPEN_TTY received\n");
+ log_debug("[priv]: msg PRIV_OPEN_TTY received");
  /* Expecting: length, path */
  must_read(sock, &path_len, sizeof(size_t));
  if (path_len == 0 || path_len > sizeof(path))
@@ -244,7 +245,7 @@ priv_exec(char *conf, int numeric, int c
 
  case PRIV_OPEN_LOG:
  case PRIV_OPEN_PIPE:
- logdebug("[priv]: msg PRIV_OPEN_%s received\n",
+ log_debug("[priv]: msg PRIV_OPEN_%s received",
     cmd == PRIV_OPEN_PIPE ? "PIPE" : "LOG");
  /* Expecting: length, path */
  must_read(sock, &path_len, sizeof(size_t));
@@ -269,7 +270,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_OPEN_UTMP:
- logdebug("[priv]: msg PRIV_OPEN_UTMP received\n");
+ log_debug("[priv]: msg PRIV_OPEN_UTMP received");
  fd = open(_PATH_UTMP, O_RDONLY|O_NONBLOCK, 0);
  send_fd(sock, fd);
  if (fd < 0)
@@ -279,7 +280,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_OPEN_CONFIG:
- logdebug("[priv]: msg PRIV_OPEN_CONFIG received\n");
+ log_debug("[priv]: msg PRIV_OPEN_CONFIG received");
  stat(conf, &cf_info);
  fd = open(conf, O_RDONLY|O_NONBLOCK, 0);
  send_fd(sock, fd);
@@ -290,12 +291,12 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_CONFIG_MODIFIED:
- logdebug("[priv]: msg PRIV_CONFIG_MODIFIED received\n");
+ log_debug("[priv]: msg PRIV_CONFIG_MODIFIED received");
  if (stat(conf, &cf_stat) < 0 ||
     timespeccmp(&cf_info.st_mtimespec,
     &cf_stat.st_mtimespec, <) ||
     cf_info.st_size != cf_stat.st_size) {
- logdebug("config file modified: restarting\n");
+ log_debug("config file modified: restarting");
  restart = result = 1;
  must_write(sock, &result, sizeof(int));
  } else {
@@ -305,13 +306,13 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_DONE_CONFIG_PARSE:
- logdebug("[priv]: msg PRIV_DONE_CONFIG_PARSE "
-    "received\n");
+ log_debug("[priv]: msg PRIV_DONE_CONFIG_PARSE "
+    "received");
  increase_state(STATE_RUNNING);
  break;
 
  case PRIV_GETADDRINFO:
- logdebug("[priv]: msg PRIV_GETADDRINFO received\n");
+ log_debug("[priv]: msg PRIV_GETADDRINFO received");
  /* Expecting: len, proto, len, host, len, serv */
  must_read(sock, &protoname_len, sizeof(size_t));
  if (protoname_len == 0 ||
@@ -377,7 +378,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_GETNAMEINFO:
- logdebug("[priv]: msg PRIV_GETNAMEINFO received\n");
+ log_debug("[priv]: msg PRIV_GETNAMEINFO received");
  if (numeric)
  errx(1, "rejected attempt to getnameinfo");
  /* Expecting: length, sockaddr */
Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.230
diff -u -p -r1.230 syslogd.c
--- usr.sbin/syslogd/syslogd.c 16 Mar 2017 23:55:19 -0000 1.230
+++ usr.sbin/syslogd/syslogd.c 17 Mar 2017 00:49:29 -0000
@@ -564,7 +564,7 @@ main(int argc, char *argv[])
  if (path_ctlsock != NULL) {
  fd_ctlsock = unix_socket(path_ctlsock, SOCK_STREAM, 0600);
  if (fd_ctlsock == -1) {
- logdebug("can't open %s (%d)\n", path_ctlsock, errno);
+ log_debug("can't open %s (%d)", path_ctlsock, errno);
  if (!Debug)
  die(0);
  } else {
@@ -577,10 +577,10 @@ main(int argc, char *argv[])
 
  fd_klog = open(_PATH_KLOG, O_RDONLY, 0);
  if (fd_klog == -1) {
- logdebug("can't open %s (%d)\n", _PATH_KLOG, errno);
+ log_debug("can't open %s (%d)", _PATH_KLOG, errno);
  } else {
  if (ioctl(fd_klog, LIOCSFD, &pair[1]) == -1)
- logdebug("LIOCSFD errno %d\n", errno);
+ log_debug("LIOCSFD errno %d", errno);
  }
  close(pair[1]);
 
@@ -611,7 +611,7 @@ main(int argc, char *argv[])
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(client_config, "", 0);
  } else
- logdebug("CAfile %s\n", CAfile);
+ log_debug("CAfile %s", CAfile);
  }
  if (ClientCertfile && ClientKeyfile) {
  if (tls_config_set_cert_file(client_config,
@@ -619,14 +619,14 @@ main(int argc, char *argv[])
  logerrortlsconf("Load client TLS cert failed",
     client_config);
  else
- logdebug("ClientCertfile %s\n", ClientCertfile);
+ log_debug("ClientCertfile %s", ClientCertfile);
 
  if (tls_config_set_key_file(client_config,
     ClientKeyfile) == -1)
  logerrortlsconf("Load client TLS key failed",
     client_config);
  else
- logdebug("ClientKeyfile %s\n", ClientKeyfile);
+ log_debug("ClientKeyfile %s", ClientKeyfile);
  } else if (ClientCertfile || ClientKeyfile) {
  logerrorx("options -c and -k must be used together");
  }
@@ -654,7 +654,7 @@ main(int argc, char *argv[])
  free(p);
  continue;
  }
- logdebug("Keyfile %s\n", p);
+ log_debug("Keyfile %s", p);
  free(p);
  if (asprintf(&p, "/etc/ssl/%s.crt", names[i]) == -1)
  continue;
@@ -664,7 +664,7 @@ main(int argc, char *argv[])
  free(p);
  continue;
  }
- logdebug("Certfile %s\n", p);
+ log_debug("Certfile %s", p);
  free(p);
  break;
  }
@@ -677,7 +677,7 @@ main(int argc, char *argv[])
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(server_config, "", 0);
  } else
- logdebug("Server CAfile %s\n", ServerCAfile);
+ log_debug("Server CAfile %s", ServerCAfile);
  tls_config_verify_client(server_config);
  }
  if (tls_config_set_protocols(server_config,
@@ -696,7 +696,7 @@ main(int argc, char *argv[])
  }
  }
 
- logdebug("off & running....\n");
+ log_debug("off & running....");
 
  if (!Debug && !Foreground) {
  char c;
@@ -856,7 +856,7 @@ main(int argc, char *argv[])
  evtimer_add(ev_mark, &to);
 
  logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: start", LocalHostName, ADDDATE);
- logdebug("syslogd: started\n");
+ log_debug("syslogd: started");
 
  sigemptyset(&sigmask);
  if (sigprocmask(SIG_SETMASK, &sigmask, NULL) == -1)
@@ -941,7 +941,7 @@ socket_bind(const char *proto, const cha
     sizeof(hostname), servname, sizeof(servname),
     NI_NUMERICHOST | NI_NUMERICSERV |
     (res->ai_socktype == SOCK_DGRAM ? NI_DGRAM : 0)) != 0) {
- logdebug("Malformed bind address\n");
+ log_debug("Malformed bind address");
  hostname[0] = servname[0] = '\0';
  }
  if (shutread && shutdown(*fdp, SHUT_RD) == -1) {
@@ -1026,7 +1026,7 @@ udp_readcb(int fd, short event, void *ar
 
  linebuf[n] = '\0';
  cvthname((struct sockaddr *)&sa, resolve, sizeof(resolve));
- logdebug("cvthname res: %s\n", resolve);
+ log_debug("cvthname res: %s", resolve);
  printline(resolve, linebuf);
  } else if (n < 0 && errno != EINTR && errno != EWOULDBLOCK)
  logerror("recvfrom udp");
@@ -1058,7 +1058,7 @@ reserve_accept4(int lfd, int event, stru
  int afd;
 
  if (event & EV_TIMEOUT) {
- logdebug("Listen again\n");
+ log_debug("Listen again");
  /* Enable the listen event, there is no timeout anymore. */
  event_set(ev, lfd, EV_READ|EV_PERSIST, cb, ev);
  event_add(ev, NULL);
@@ -1121,17 +1121,17 @@ acceptcb(int lfd, short event, void *arg
  logerror("accept tcp socket");
  return;
  }
- logdebug("Accepting tcp connection\n");
+ log_debug("Accepting tcp connection");
 
  if (getnameinfo((struct sockaddr *)&ss, sslen, hostname,
     sizeof(hostname), servname, sizeof(servname),
     NI_NUMERICHOST | NI_NUMERICSERV) != 0 ||
     asprintf(&peername, ss.ss_family == AF_INET6 ?
     "[%s]:%s" : "%s:%s", hostname, servname) == -1) {
- logdebug("Malformed accept address\n");
+ log_debug("Malformed accept address");
  peername = hostname_unknown;
  }
- logdebug("Peer addresss and port %s\n", peername);
+ log_debug("Peer addresss and port %s", peername);
  if ((p = malloc(sizeof(*p))) == NULL) {
  snprintf(ebuf, sizeof(ebuf), "malloc \"%s\"", peername);
  logerror(ebuf);
@@ -1160,18 +1160,18 @@ acceptcb(int lfd, short event, void *arg
  }
  buffertls_set(&p->p_buftls, p->p_bufev, p->p_ctx, fd);
  buffertls_accept(&p->p_buftls, fd);
- logdebug("tcp accept callback: tls context success\n");
+ log_debug("tcp accept callback: tls context success");
  }
  if (!NoDNS && peername != hostname_unknown &&
     priv_getnameinfo((struct sockaddr *)&ss, ss.ss_len, hostname,
     sizeof(hostname)) != 0) {
- logdebug("Host name for accept address (%s) unknown\n",
+ log_debug("Host name for accept address (%s) unknown",
     hostname);
  }
  if (peername == hostname_unknown ||
     (p->p_hostname = strdup(hostname)) == NULL)
  p->p_hostname = hostname_unknown;
- logdebug("Peer hostname %s\n", hostname);
+ log_debug("Peer hostname %s", hostname);
  p->p_peername = peername;
  bufferevent_enable(p->p_bufev, EV_READ);
 
@@ -1212,7 +1212,7 @@ octet_counting(struct evbuffer *evbuf, c
  /* Using atoi() is safe as buf starts with 1 to 5 digits and a space. */
  len = atoi(buf);
  if (drain)
- logdebug(" octet counting %d", len);
+ log_debugadd(" octet counting %d", len);
  if (p + len > end)
  return (0);
  if (drain)
@@ -1243,7 +1243,7 @@ non_transparent_framing(struct evbuffer
  }
  if (p + 1 - buf >= INT_MAX)
  return (-1);
- logdebug(" non transparent framing");
+ log_debugadd(" non transparent framing");
  if (p >= end)
  return (0);
  /*
@@ -1265,19 +1265,19 @@ tcp_readcb(struct bufferevent *bufev, vo
  int len;
 
  while (EVBUFFER_LENGTH(bufev->input) > 0) {
- logdebug("%s logger \"%s\"", p->p_ctx ? "tls" : "tcp",
+ log_debugadd("%s logger \"%s\"", p->p_ctx ? "tls" : "tcp",
     p->p_peername);
  msg = NULL;
  len = octet_counting(bufev->input, &msg, 1);
  if (len < 0)
  len = non_transparent_framing(bufev->input, &msg);
  if (len < 0)
- logdebug("unknown method");
+ log_debugadd("unknown method");
  if (msg == NULL) {
- logdebug(", incomplete frame");
+ log_debugadd(", incomplete frame");
  break;
  }
- logdebug(", use %d bytes\n", len);
+ log_debug(", use %d bytes", len);
  if (len > 0 && msg[len-1] == '\n')
  msg[len-1] = '\0';
  if (len == 0 || msg[len-1] != '\0') {
@@ -1290,11 +1290,11 @@ tcp_readcb(struct bufferevent *bufev, vo
  }
  /* Maximum frame has 5 digits, 1 space, MAXLINE chars, 1 new line. */
  if (EVBUFFER_LENGTH(bufev->input) >= 5 + 1 + MAXLINE + 1) {
- logdebug(", use %zu bytes\n", EVBUFFER_LENGTH(bufev->input));
+ log_debug(", use %zu bytes", EVBUFFER_LENGTH(bufev->input));
  printline(p->p_hostname, EVBUFFER_DATA(bufev->input));
  evbuffer_drain(bufev->input, -1);
  } else if (EVBUFFER_LENGTH(bufev->input) > 0)
- logdebug(", buffer %zu bytes\n", EVBUFFER_LENGTH(bufev->input));
+ log_debug(", buffer %zu bytes", EVBUFFER_LENGTH(bufev->input));
 }
 
 void
@@ -1358,7 +1358,7 @@ tcp_dropcb(struct bufferevent *bufev, vo
  /*
  * Drop data received from the forward log server.
  */
- logdebug("loghost \"%s\" did send %zu bytes back\n",
+ log_debug("loghost \"%s\" did send %zu bytes back",
     f->f_un.f_forw.f_loghost, EVBUFFER_LENGTH(bufev->input));
  evbuffer_drain(bufev->input, -1);
 }
@@ -1372,7 +1372,7 @@ tcp_writecb(struct bufferevent *bufev, v
  /*
  * Successful write, connection to server is good, reset wait time.
  */
- logdebug("loghost \"%s\" successful write\n", f->f_un.f_forw.f_loghost);
+ log_debug("loghost \"%s\" successful write", f->f_un.f_forw.f_loghost);
  f->f_un.f_forw.f_reconnectwait = 0;
 
  if (f->f_un.f_forw.f_dropped > 0 &&
@@ -1404,7 +1404,7 @@ tcp_errorcb(struct bufferevent *bufev, s
     "syslogd: loghost \"%s\" connection error: %s",
     f->f_un.f_forw.f_loghost, f->f_un.f_forw.f_ctx ?
     tls_error(f->f_un.f_forw.f_ctx) : strerror(errno));
- logdebug("%s\n", ebuf);
+ log_debug("%s", ebuf);
 
  /* The SIGHUP handler may also close the socket, so invalidate it. */
  if (f->f_un.f_forw.f_ctx) {
@@ -1433,7 +1433,7 @@ tcp_errorcb(struct bufferevent *bufev, s
  /* Without '\n' discard everything. */
  if (p == end)
  evbuffer_drain(bufev->output, -1);
- logdebug("loghost \"%s\" dropped partial message\n",
+ log_debug("loghost \"%s\" dropped partial message",
     f->f_un.f_forw.f_loghost);
  f->f_un.f_forw.f_dropped++;
  }
@@ -1456,7 +1456,7 @@ tcp_connectcb(int fd, short event, void
  tcp_connect_retry(bufev, f);
  return;
  }
- logdebug("tcp connect callback: socket success, event %#x\n", event);
+ log_debug("tcp connect callback: socket success, event %#x", event);
  f->f_file = s;
 
  bufferevent_setfd(bufev, s);
@@ -1488,7 +1488,7 @@ tcp_connectcb(int fd, short event, void
  logerrorctx(ebuf, f->f_un.f_forw.f_ctx);
  goto error;
  }
- logdebug("tcp connect callback: tls context success\n");
+ log_debug("tcp connect callback: tls context success");
 
  buffertls_set(&f->f_un.f_forw.f_buftls, bufev,
     f->f_un.f_forw.f_ctx, s);
@@ -1521,7 +1521,7 @@ tcp_connect_retry(struct bufferevent *bu
  to.tv_sec = f->f_un.f_forw.f_reconnectwait;
  to.tv_usec = 0;
 
- logdebug("tcp connect retry: wait %d\n",
+ log_debug("tcp connect retry: wait %d",
     f->f_un.f_forw.f_reconnectwait);
  bufferevent_setfd(bufev, -1);
  /* We can reuse the write event as bufferevent is disabled. */
@@ -1677,7 +1677,7 @@ logmsg(int pri, char *msg, char *from, i
  char timestamp[33];
  char prog[NAME_MAX+1];
 
- logdebug("logmsg: pri 0%o, flags 0x%x, from %s, msg %s\n",
+ log_debug("logmsg: pri 0%o, flags 0x%x, from %s, msg %s",
     pri, flags, from, msg);
 
  /*
@@ -1831,7 +1831,7 @@ logmsg(int pri, char *msg, char *from, i
  strlcpy(f->f_lasttime, timestamp,
     sizeof(f->f_lasttime));
  f->f_prevcount++;
- logdebug("msg repeated %d times, %ld sec of %d\n",
+ log_debug("msg repeated %d times, %ld sec of %d",
     f->f_prevcount, (long)(now.tv_sec - f->f_time),
     repeatinterval[f->f_repeatcount]);
  /*
@@ -1939,16 +1939,16 @@ fprintlog(struct filed *f, int flags, ch
  }
  v++;
 
- logdebug("Logging to %s", TypeNames[f->f_type]);
+ log_debugadd("Logging to %s", TypeNames[f->f_type]);
  f->f_time = now.tv_sec;
 
  switch (f->f_type) {
  case F_UNUSED:
- logdebug("\n");
+ log_debug("%s", "");
  break;
 
  case F_FORWUDP:
- logdebug(" %s\n", f->f_un.f_forw.f_loghost);
+ log_debug(" %s", f->f_un.f_forw.f_loghost);
  l = snprintf(line, MINIMUM(MAX_UDPMSG + 1, sizeof(line)),
     "<%d>%.32s %s%s%s", f->f_prevpri, (char *)iov[0].iov_base,
     IncludeHostname ? LocalHostName : "",
@@ -1978,10 +1978,10 @@ fprintlog(struct filed *f, int flags, ch
 
  case F_FORWTCP:
  case F_FORWTLS:
- logdebug(" %s", f->f_un.f_forw.f_loghost);
+ log_debugadd(" %s", f->f_un.f_forw.f_loghost);
  if (EVBUFFER_LENGTH(f->f_un.f_forw.f_bufev->output) >=
     MAX_TCPBUF) {
- logdebug(" (dropped)\n");
+ log_debug(" (dropped)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
@@ -1997,7 +1997,7 @@ fprintlog(struct filed *f, int flags, ch
     IncludeHostname ? LocalHostName : "",
     IncludeHostname ? " " : "");
  if (l < 0) {
- logdebug(" (dropped snprintf)\n");
+ log_debug(" (dropped snprintf)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
@@ -2009,17 +2009,17 @@ fprintlog(struct filed *f, int flags, ch
     IncludeHostname ? " " : "",
     (char *)iov[4].iov_base);
  if (l < 0) {
- logdebug(" (dropped evbuffer_add_printf)\n");
+ log_debug(" (dropped evbuffer_add_printf)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
  bufferevent_enable(f->f_un.f_forw.f_bufev, EV_WRITE);
- logdebug("\n");
+ log_debug("%s", "");
  break;
 
  case F_CONSOLE:
  if (flags & IGN_CONS) {
- logdebug(" (ignored)\n");
+ log_debug(" (ignored)");
  break;
  }
  /* FALLTHROUGH */
@@ -2027,7 +2027,7 @@ fprintlog(struct filed *f, int flags, ch
  case F_TTY:
  case F_FILE:
  case F_PIPE:
- logdebug(" %s\n", f->f_un.f_fname);
+ log_debug(" %s", f->f_un.f_fname);
  if (f->f_type != F_FILE && f->f_type != F_PIPE) {
  v->iov_base = "\r\n";
  v->iov_len = 2;
@@ -2091,14 +2091,14 @@ fprintlog(struct filed *f, int flags, ch
 
  case F_USERS:
  case F_WALL:
- logdebug("\n");
+ log_debug("%s", "");
  v->iov_base = "\r\n";
  v->iov_len = 2;
  wallmsg(f, iov);
  break;
 
  case F_MEMBUF:
- logdebug("\n");
+ log_debug("%s", "");
  snprintf(line, sizeof(line), "%.32s %s %s",
     (char *)iov[0].iov_base, (char *)iov[2].iov_base,
     (char *)iov[4].iov_base);
@@ -2168,16 +2168,16 @@ cvthname(struct sockaddr *f, char *resul
 {
  if (getnameinfo(f, f->sa_len, result, res_len, NULL, 0,
     NI_NUMERICHOST|NI_NUMERICSERV|NI_DGRAM) != 0) {
- logdebug("Malformed from address\n");
+ log_debug("Malformed from address");
  strlcpy(result, hostname_unknown, res_len);
  return;
  }
- logdebug("cvthname(%s)\n", result);
+ log_debug("cvthname(%s)", result);
  if (NoDNS)
  return;
 
  if (priv_getnameinfo(f, f->sa_len, result, res_len) != 0)
- logdebug("Host name for from address (%s) unknown\n", result);
+ log_debug("Host name for from address (%s) unknown", result);
 }
 
 void
@@ -2208,7 +2208,7 @@ init_signalcb(int signum, short event, v
 
  logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: restart",
     LocalHostName, ADDDATE);
- logdebug("syslogd: restarted\n");
+ log_debug("syslogd: restarted");
 
  if (tcpbuf_dropped > 0) {
  snprintf(ebuf, sizeof(ebuf),
@@ -2222,19 +2222,7 @@ init_signalcb(int signum, short event, v
 void
 logevent(int severity, const char *msg)
 {
- logdebug("libevent: [%d] %s\n", severity, msg);
-}
-
-void
-logdebug(const char *fmt, ...)
-{
- va_list ap;
-
- if (Debug) {
- va_start(ap, fmt);
- vprintf(fmt, ap);
- va_end(ap);
- }
+ log_debug("libevent: [%d] %s", severity, msg);
 }
 
 void
@@ -2272,7 +2260,7 @@ logerror_reason(const char *message, con
  else
  (void)snprintf(ebuf, sizeof(ebuf), "syslogd: %s", message);
  errno = 0;
- logdebug("%s\n", ebuf);
+ log_debug("%s", ebuf);
  if (Startup)
  fprintf(stderr, "%s\n", ebuf);
  else
@@ -2308,12 +2296,12 @@ die(int signo)
  }
 
  if (signo) {
- logdebug("syslogd: exiting on signal %d\n", signo);
+ log_debug("syslogd: exiting on signal %d", signo);
  (void)snprintf(ebuf, sizeof(ebuf), "exiting on signal %d",
     signo);
  logerrorx(ebuf);
  }
- logdebug("[unpriv] syslogd child about to exit\n");
+ log_debug("[unpriv] syslogd child about to exit");
  exit(0);
 }
 
@@ -2330,11 +2318,11 @@ init(void)
  int i;
  size_t s;
 
- logdebug("init\n");
+ log_debug("init");
 
  /* If config file has been modified, then just die to restart */
  if (priv_config_modified()) {
- logdebug("config file changed: dying\n");
+ log_debug("config file changed: dying");
  die(0);
  }
 
@@ -2375,7 +2363,7 @@ init(void)
  if (f->f_type == F_MEMBUF) {
  f->f_program = NULL;
  f->f_hostname = NULL;
- logdebug("add %p to mb\n", f);
+ log_debug("add %p to mb", f);
  SIMPLEQ_INSERT_HEAD(&mb, f, f_next);
  } else
  free(f);
@@ -2384,7 +2372,7 @@ init(void)
 
  /* open the configuration file */
  if ((cf = priv_open_config()) == NULL) {
- logdebug("cannot open %s\n", ConfFile);
+ log_debug("cannot open %s", ConfFile);
  SIMPLEQ_INSERT_TAIL(&Files,
     cfline("*.ERR\t/dev/console", "*", "*"), f_next);
  SIMPLEQ_INSERT_TAIL(&Files,
@@ -2451,7 +2439,7 @@ init(void)
  SIMPLEQ_FOREACH(f, &Files, f_next) {
  if (f->f_type != F_MEMBUF)
  continue;
- logdebug("Initialize membuf %s at %p\n",
+ log_debug("Initialize membuf %s at %p",
     f->f_un.f_mb.f_mname, f);
 
  SIMPLEQ_FOREACH(m, &mb, f_next) {
@@ -2462,14 +2450,14 @@ init(void)
  break;
  }
  if (m == NULL) {
- logdebug("Membuf no match\n");
+ log_debug("Membuf no match");
  f->f_un.f_mb.f_rb = ringbuf_init(f->f_un.f_mb.f_len);
  if (f->f_un.f_mb.f_rb == NULL) {
  f->f_type = F_UNUSED;
  logerror("Failed to allocate membuf");
  }
  } else {
- logdebug("Membuf match f:%p, m:%p\n", f, m);
+ log_debug("Membuf match f:%p, m:%p", f, m);
  f->f_un = m->f_un;
  m->f_un.f_mb.f_rb = NULL;
  }
@@ -2483,7 +2471,7 @@ init(void)
  logerrorx("Mismatched membuf");
  ringbuf_free(m->f_un.f_mb.f_rb);
  }
- logdebug("Freeing membuf %p\n", m);
+ log_debug("Freeing membuf %p", m);
 
  free(m);
  }
@@ -2557,7 +2545,7 @@ find_dup(struct filed *f)
  if (strcmp(list->f_un.f_fname, f->f_un.f_fname) == 0 &&
     progmatches(list->f_program, f->f_program) &&
     progmatches(list->f_hostname, f->f_hostname)) {
- logdebug("duplicate %s\n", f->f_un.f_fname);
+ log_debug("duplicate %s", f->f_un.f_fname);
  return (list);
  }
  break;
@@ -2566,7 +2554,7 @@ find_dup(struct filed *f)
     f->f_un.f_mb.f_mname) == 0 &&
     progmatches(list->f_program, f->f_program) &&
     progmatches(list->f_hostname, f->f_hostname)) {
- logdebug("duplicate membuf %s\n",
+ log_debug("duplicate membuf %s",
     f->f_un.f_mb.f_mname);
  return (list);
  }
@@ -2589,7 +2577,7 @@ cfline(char *line, char *progblock, char
  struct filed *xf, *f, *d;
  struct timeval to;
 
- logdebug("cfline(\"%s\", f, \"%s\", \"%s\")\n",
+ log_debug("cfline(\"%s\", f, \"%s\", \"%s\")",
     line, progblock, hostblock);
 
  if ((f = calloc(1, sizeof(*f))) == NULL) {
@@ -2947,7 +2935,7 @@ getmsgbufsize(void)
  mib[1] = KERN_MSGBUFSIZE;
  size = sizeof msgbufsize;
  if (sysctl(mib, 2, &msgbufsize, &size, NULL, 0) == -1) {
- logdebug("couldn't get kern.msgbufsize\n");
+ log_debug("couldn't get kern.msgbufsize");
  return (0);
  }
  return (msgbufsize);
@@ -2991,7 +2979,7 @@ markit(void)
 
  SIMPLEQ_FOREACH(f, &Files, f_next) {
  if (f->f_prevcount && now.tv_sec >= REPEATTIME(f)) {
- logdebug("flush %s: repeated %d times, %d sec.\n",
+ log_debug("flush %s: repeated %d times, %d sec",
     TypeNames[f->f_type], f->f_prevcount,
     repeatinterval[f->f_repeatcount]);
  fprintlog(f, 0, (char *)NULL);
@@ -3125,7 +3113,7 @@ ctlsock_acceptcb(int fd, short event, vo
  logerror("accept ctlsock");
  return;
  }
- logdebug("Accepting control connection\n");
+ log_debug("Accepting control connection");
 
  if (fd_ctlconn != -1)
  ctlconn_cleanup();
@@ -3211,7 +3199,7 @@ ctlconn_readcb(int fd, short event, void
  memset(reply_hdr, '\0', sizeof(*reply_hdr));
 
  ctl_cmd.cmd = ntohl(ctl_cmd.cmd);
- logdebug("ctlcmd %x logname \"%s\"\n", ctl_cmd.cmd, ctl_cmd.logname);
+ log_debug("ctlcmd %x logname \"%s\"", ctl_cmd.cmd, ctl_cmd.logname);
 
  switch (ctl_cmd.cmd) {
  case CMD_READ:
@@ -3276,7 +3264,7 @@ ctlconn_readcb(int fd, short event, void
  reply_hdr->flags = htonl(flags);
 
  ctl_reply_size = CTL_REPLY_SIZE;
- logdebug("ctlcmd reply length %lu\n", (u_long)ctl_reply_size);
+ log_debug("ctlcmd reply length %lu", (u_long)ctl_reply_size);
 
  /* Otherwise, set up to write out reply */
  ctl_state = (ctl_cmd.cmd == CMD_READ_CONT) ?
Index: usr.sbin/syslogd/ttymsg.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/ttymsg.c,v
retrieving revision 1.12
diff -u -p -r1.12 ttymsg.c
--- usr.sbin/syslogd/ttymsg.c 16 Mar 2017 12:14:37 -0000 1.12
+++ usr.sbin/syslogd/ttymsg.c 17 Mar 2017 00:08:48 -0000
@@ -42,6 +42,7 @@
 #include <string.h>
 #include <unistd.h>
 
+#include "log.h"
 #include "syslogd.h"
 
 #ifndef nitems
@@ -139,7 +140,7 @@ ttymsg(struct iovec *iov, int iovcnt, ch
     "%s: too many delayed writes", device);
  goto error;
  }
- logdebug("ttymsg delayed write\n");
+ log_debug("ttymsg delayed write");
  if (iov != localiov) {
  bcopy(iov, localiov,
     iovcnt * sizeof(struct iovec));

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_debug

Alexander Bluhm
On Fri, Mar 17, 2017 at 08:07:38AM +0100, Martin Pieuchot wrote:
> On 17/03/17(Fri) 02:09, Alexander Bluhm wrote:
> > Replace logdebug() with generic log_debug() from log.c.  Implement
> > log_debugadd() to construct debug message incrementally.
>
> FWIW the idea was to keep log.c identical in all daemons and put
> per-daemon log functions into logmsg.c.  I don't know how much this
> is applicable to syslogd(8) :)

syslogd is special, it needs a different implementation:

- It cannot use openlog(3) and syslog(3).  log.c must use syslogd(8)
  internal functions as backend.
- The backend has to be switched from stderr logging to internal
  logging as soon as the latter has been set up.  This gives
  additional functions in the API.
- I want to avoid malloc(3) in the logging path to make global error
  reporting reliable.
- syslogd uses more serverity levels than other daemons as it has
  been written with that in mind.  This API change could be adapted
  by the others.  log_info(LOG_NOTICE, ...)
- syslogd uses incremental debug messages because it can.  I don't
  want to change that now.  Perhaps this could be usefull for others.

I will delay the syslogd logging refactoring after 6.1 tagging.  It
touches too much code.

bluhm

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_debug

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.
>
> Replace logdebug() with generic log_debug() from log.c.  Implement
> log_debugadd() to construct debug message incrementally.

Updated diff after unlock, ok?

bluhm

Index: usr.sbin/syslogd/log.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/log.c,v
retrieving revision 1.1
diff -u -p -r1.1 log.c
--- usr.sbin/syslogd/log.c 16 Mar 2017 23:55:19 -0000 1.1
+++ usr.sbin/syslogd/log.c 4 Apr 2017 23:51:59 -0000
@@ -17,8 +17,10 @@
  * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  */
 
+#include <err.h>
 #include <errno.h>
 #include <stdio.h>
+#include <stdlib.h>
 #include <string.h>
 #include <syslog.h>
 #include <time.h>
@@ -30,6 +32,8 @@ static int debug;
 static int verbose;
 static int facility;
 static const char *log_procname;
+static char *debug_ebuf;
+static size_t debug_length;
 
 void
 log_init(int n_debug, int fac)
@@ -41,6 +45,12 @@ log_init(int n_debug, int fac)
  facility = fac;
  log_procinit(__progname);
 
+ if (debug_ebuf == NULL)
+ if ((debug_ebuf = malloc(ERRBUFSIZE)) == NULL)
+ err(1, "allocate debug buffer");
+ debug_ebuf[0] = '\0';
+ debug_length = 0;
+
  tzset();
 }
 
@@ -150,16 +160,42 @@ log_info(int pri, const char *emsg, ...)
 void
 log_debug(const char *emsg, ...)
 {
- char ebuf[ERRBUFSIZE];
  va_list ap;
  int saved_errno;
 
  if (verbose) {
  saved_errno = errno;
  va_start(ap, emsg);
- vsnprintf(ebuf, sizeof(ebuf), emsg, ap);
- fprintf(stderr, "%s\n", ebuf);
+ if (debug_length < ERRBUFSIZE - 1)
+ vsnprintf(debug_ebuf + debug_length,
+    ERRBUFSIZE - debug_length, emsg, ap);
+ fprintf(stderr, "%s\n", debug_ebuf);
  fflush(stderr);
+ va_end(ap);
+ errno = saved_errno;
+ }
+ debug_ebuf[0] = '\0';
+ debug_length = 0;
+}
+
+void
+log_debugadd(const char *emsg, ...)
+{
+ size_t l;
+ va_list ap;
+ int saved_errno;
+
+ if (verbose) {
+ saved_errno = errno;
+ va_start(ap, emsg);
+ if (debug_length < ERRBUFSIZE - 1) {
+ l = vsnprintf(debug_ebuf + debug_length,
+    ERRBUFSIZE - debug_length, emsg, ap);
+ if (l < ERRBUFSIZE - debug_length)
+ debug_length += l;
+ else
+ debug_length = ERRBUFSIZE - 1;
+ }
  va_end(ap);
  errno = saved_errno;
  }
Index: usr.sbin/syslogd/log.h
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/log.h,v
retrieving revision 1.1
diff -u -p -r1.1 log.h
--- usr.sbin/syslogd/log.h 16 Mar 2017 23:55:19 -0000 1.1
+++ usr.sbin/syslogd/log.h 4 Apr 2017 23:51:59 -0000
@@ -38,6 +38,8 @@ void log_info(int, const char *, ...)
     __attribute__((__format__ (printf, 2, 3)));
 void log_debug(const char *, ...)
     __attribute__((__format__ (printf, 1, 2)));
+void log_debugadd(const char *, ...)
+    __attribute__((__format__ (printf, 1, 2)));
 void logit(int, const char *, ...)
     __attribute__((__format__ (printf, 2, 3)));
 void vlog(int, const char *, va_list)
Index: usr.sbin/syslogd/privsep.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/privsep.c,v
retrieving revision 1.66
diff -u -p -r1.66 privsep.c
--- usr.sbin/syslogd/privsep.c 30 Dec 2016 23:21:26 -0000 1.66
+++ usr.sbin/syslogd/privsep.c 4 Apr 2017 23:51:59 -0000
@@ -35,6 +35,7 @@
 #include <unistd.h>
 #include <utmp.h>
 
+#include "log.h"
 #include "syslogd.h"
 
 /*
@@ -208,7 +209,7 @@ priv_exec(char *conf, int numeric, int c
  sigaction(SIGCHLD, &sa, NULL);
 
  setproctitle("[priv]");
- logdebug("[priv]: fork+exec done\n");
+ log_debug("[priv]: fork+exec done");
 
  sigemptyset(&sigmask);
  if (sigprocmask(SIG_SETMASK, &sigmask, NULL) == -1)
@@ -226,7 +227,7 @@ priv_exec(char *conf, int numeric, int c
  break;
  switch (cmd) {
  case PRIV_OPEN_TTY:
- logdebug("[priv]: msg PRIV_OPEN_TTY received\n");
+ log_debug("[priv]: msg PRIV_OPEN_TTY received");
  /* Expecting: length, path */
  must_read(sock, &path_len, sizeof(size_t));
  if (path_len == 0 || path_len > sizeof(path))
@@ -244,7 +245,7 @@ priv_exec(char *conf, int numeric, int c
 
  case PRIV_OPEN_LOG:
  case PRIV_OPEN_PIPE:
- logdebug("[priv]: msg PRIV_OPEN_%s received\n",
+ log_debug("[priv]: msg PRIV_OPEN_%s received",
     cmd == PRIV_OPEN_PIPE ? "PIPE" : "LOG");
  /* Expecting: length, path */
  must_read(sock, &path_len, sizeof(size_t));
@@ -269,7 +270,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_OPEN_UTMP:
- logdebug("[priv]: msg PRIV_OPEN_UTMP received\n");
+ log_debug("[priv]: msg PRIV_OPEN_UTMP received");
  fd = open(_PATH_UTMP, O_RDONLY|O_NONBLOCK, 0);
  send_fd(sock, fd);
  if (fd < 0)
@@ -279,7 +280,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_OPEN_CONFIG:
- logdebug("[priv]: msg PRIV_OPEN_CONFIG received\n");
+ log_debug("[priv]: msg PRIV_OPEN_CONFIG received");
  stat(conf, &cf_info);
  fd = open(conf, O_RDONLY|O_NONBLOCK, 0);
  send_fd(sock, fd);
@@ -290,12 +291,12 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_CONFIG_MODIFIED:
- logdebug("[priv]: msg PRIV_CONFIG_MODIFIED received\n");
+ log_debug("[priv]: msg PRIV_CONFIG_MODIFIED received");
  if (stat(conf, &cf_stat) < 0 ||
     timespeccmp(&cf_info.st_mtimespec,
     &cf_stat.st_mtimespec, <) ||
     cf_info.st_size != cf_stat.st_size) {
- logdebug("config file modified: restarting\n");
+ log_debug("config file modified: restarting");
  restart = result = 1;
  must_write(sock, &result, sizeof(int));
  } else {
@@ -305,13 +306,13 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_DONE_CONFIG_PARSE:
- logdebug("[priv]: msg PRIV_DONE_CONFIG_PARSE "
-    "received\n");
+ log_debug("[priv]: msg PRIV_DONE_CONFIG_PARSE "
+    "received");
  increase_state(STATE_RUNNING);
  break;
 
  case PRIV_GETADDRINFO:
- logdebug("[priv]: msg PRIV_GETADDRINFO received\n");
+ log_debug("[priv]: msg PRIV_GETADDRINFO received");
  /* Expecting: len, proto, len, host, len, serv */
  must_read(sock, &protoname_len, sizeof(size_t));
  if (protoname_len == 0 ||
@@ -377,7 +378,7 @@ priv_exec(char *conf, int numeric, int c
  break;
 
  case PRIV_GETNAMEINFO:
- logdebug("[priv]: msg PRIV_GETNAMEINFO received\n");
+ log_debug("[priv]: msg PRIV_GETNAMEINFO received");
  if (numeric)
  errx(1, "rejected attempt to getnameinfo");
  /* Expecting: length, sockaddr */
Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.233
diff -u -p -r1.233 syslogd.c
--- usr.sbin/syslogd/syslogd.c 28 Mar 2017 00:04:43 -0000 1.233
+++ usr.sbin/syslogd/syslogd.c 4 Apr 2017 23:51:59 -0000
@@ -553,7 +553,7 @@ main(int argc, char *argv[])
  if (path_ctlsock != NULL) {
  fd_ctlsock = unix_socket(path_ctlsock, SOCK_STREAM, 0600);
  if (fd_ctlsock == -1) {
- logdebug("can't open %s (%d)\n", path_ctlsock, errno);
+ log_debug("can't open %s (%d)", path_ctlsock, errno);
  } else {
  if (listen(fd_ctlsock, 5) == -1) {
  logerror("ctlsock listen");
@@ -564,10 +564,10 @@ main(int argc, char *argv[])
  }
 
  if ((fd_klog = open(_PATH_KLOG, O_RDONLY, 0)) == -1) {
- logdebug("can't open %s (%d)\n", _PATH_KLOG, errno);
+ log_debug("can't open %s (%d)", _PATH_KLOG, errno);
  } else if (fd_sendsys != -1) {
  if (ioctl(fd_klog, LIOCSFD, &pair[1]) == -1)
- logdebug("LIOCSFD errno %d\n", errno);
+ log_debug("LIOCSFD errno %d", errno);
  }
  if (fd_sendsys != -1)
  close(pair[1]);
@@ -599,7 +599,7 @@ main(int argc, char *argv[])
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(client_config, "", 0);
  } else
- logdebug("CAfile %s\n", CAfile);
+ log_debug("CAfile %s", CAfile);
  }
  if (ClientCertfile && ClientKeyfile) {
  if (tls_config_set_cert_file(client_config,
@@ -607,14 +607,14 @@ main(int argc, char *argv[])
  logerrortlsconf("Load client TLS cert failed",
     client_config);
  else
- logdebug("ClientCertfile %s\n", ClientCertfile);
+ log_debug("ClientCertfile %s", ClientCertfile);
 
  if (tls_config_set_key_file(client_config,
     ClientKeyfile) == -1)
  logerrortlsconf("Load client TLS key failed",
     client_config);
  else
- logdebug("ClientKeyfile %s\n", ClientKeyfile);
+ log_debug("ClientKeyfile %s", ClientKeyfile);
  } else if (ClientCertfile || ClientKeyfile) {
  logerrorx("options -c and -k must be used together");
  }
@@ -642,7 +642,7 @@ main(int argc, char *argv[])
  free(p);
  continue;
  }
- logdebug("Keyfile %s\n", p);
+ log_debug("Keyfile %s", p);
  free(p);
  if (asprintf(&p, "/etc/ssl/%s.crt", names[i]) == -1)
  continue;
@@ -652,7 +652,7 @@ main(int argc, char *argv[])
  free(p);
  continue;
  }
- logdebug("Certfile %s\n", p);
+ log_debug("Certfile %s", p);
  free(p);
  break;
  }
@@ -665,7 +665,7 @@ main(int argc, char *argv[])
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(server_config, "", 0);
  } else
- logdebug("Server CAfile %s\n", ServerCAfile);
+ log_debug("Server CAfile %s", ServerCAfile);
  tls_config_verify_client(server_config);
  }
  if (tls_config_set_protocols(server_config,
@@ -684,7 +684,7 @@ main(int argc, char *argv[])
  }
  }
 
- logdebug("off & running....\n");
+ log_debug("off & running....");
 
  if (!Debug && !Foreground) {
  char c;
@@ -844,7 +844,7 @@ main(int argc, char *argv[])
  evtimer_add(ev_mark, &to);
 
  logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: start", LocalHostName, ADDDATE);
- logdebug("syslogd: started\n");
+ log_debug("syslogd: started");
 
  sigemptyset(&sigmask);
  if (sigprocmask(SIG_SETMASK, &sigmask, NULL) == -1)
@@ -929,7 +929,7 @@ socket_bind(const char *proto, const cha
     sizeof(hostname), servname, sizeof(servname),
     NI_NUMERICHOST | NI_NUMERICSERV |
     (res->ai_socktype == SOCK_DGRAM ? NI_DGRAM : 0)) != 0) {
- logdebug("Malformed bind address\n");
+ log_debug("Malformed bind address");
  hostname[0] = servname[0] = '\0';
  }
  if (shutread && shutdown(*fdp, SHUT_RD) == -1) {
@@ -1014,7 +1014,7 @@ udp_readcb(int fd, short event, void *ar
 
  linebuf[n] = '\0';
  cvthname((struct sockaddr *)&sa, resolve, sizeof(resolve));
- logdebug("cvthname res: %s\n", resolve);
+ log_debug("cvthname res: %s", resolve);
  printline(resolve, linebuf);
  } else if (n < 0 && errno != EINTR && errno != EWOULDBLOCK)
  logerror("recvfrom udp");
@@ -1046,7 +1046,7 @@ reserve_accept4(int lfd, int event, stru
  int afd;
 
  if (event & EV_TIMEOUT) {
- logdebug("Listen again\n");
+ log_debug("Listen again");
  /* Enable the listen event, there is no timeout anymore. */
  event_set(ev, lfd, EV_READ|EV_PERSIST, cb, ev);
  event_add(ev, NULL);
@@ -1109,17 +1109,17 @@ acceptcb(int lfd, short event, void *arg
  logerror("accept tcp socket");
  return;
  }
- logdebug("Accepting tcp connection\n");
+ log_debug("Accepting tcp connection");
 
  if (getnameinfo((struct sockaddr *)&ss, sslen, hostname,
     sizeof(hostname), servname, sizeof(servname),
     NI_NUMERICHOST | NI_NUMERICSERV) != 0 ||
     asprintf(&peername, ss.ss_family == AF_INET6 ?
     "[%s]:%s" : "%s:%s", hostname, servname) == -1) {
- logdebug("Malformed accept address\n");
+ log_debug("Malformed accept address");
  peername = hostname_unknown;
  }
- logdebug("Peer addresss and port %s\n", peername);
+ log_debug("Peer addresss and port %s", peername);
  if ((p = malloc(sizeof(*p))) == NULL) {
  snprintf(ebuf, sizeof(ebuf), "malloc \"%s\"", peername);
  logerror(ebuf);
@@ -1148,18 +1148,18 @@ acceptcb(int lfd, short event, void *arg
  }
  buffertls_set(&p->p_buftls, p->p_bufev, p->p_ctx, fd);
  buffertls_accept(&p->p_buftls, fd);
- logdebug("tcp accept callback: tls context success\n");
+ log_debug("tcp accept callback: tls context success");
  }
  if (!NoDNS && peername != hostname_unknown &&
     priv_getnameinfo((struct sockaddr *)&ss, ss.ss_len, hostname,
     sizeof(hostname)) != 0) {
- logdebug("Host name for accept address (%s) unknown\n",
+ log_debug("Host name for accept address (%s) unknown",
     hostname);
  }
  if (peername == hostname_unknown ||
     (p->p_hostname = strdup(hostname)) == NULL)
  p->p_hostname = hostname_unknown;
- logdebug("Peer hostname %s\n", hostname);
+ log_debug("Peer hostname %s", hostname);
  p->p_peername = peername;
  bufferevent_enable(p->p_bufev, EV_READ);
 
@@ -1200,7 +1200,7 @@ octet_counting(struct evbuffer *evbuf, c
  /* Using atoi() is safe as buf starts with 1 to 5 digits and a space. */
  len = atoi(buf);
  if (drain)
- logdebug(" octet counting %d", len);
+ log_debugadd(" octet counting %d", len);
  if (p + len > end)
  return (0);
  if (drain)
@@ -1231,7 +1231,7 @@ non_transparent_framing(struct evbuffer
  }
  if (p + 1 - buf >= INT_MAX)
  return (-1);
- logdebug(" non transparent framing");
+ log_debugadd(" non transparent framing");
  if (p >= end)
  return (0);
  /*
@@ -1253,19 +1253,19 @@ tcp_readcb(struct bufferevent *bufev, vo
  int len;
 
  while (EVBUFFER_LENGTH(bufev->input) > 0) {
- logdebug("%s logger \"%s\"", p->p_ctx ? "tls" : "tcp",
+ log_debugadd("%s logger \"%s\"", p->p_ctx ? "tls" : "tcp",
     p->p_peername);
  msg = NULL;
  len = octet_counting(bufev->input, &msg, 1);
  if (len < 0)
  len = non_transparent_framing(bufev->input, &msg);
  if (len < 0)
- logdebug("unknown method");
+ log_debugadd("unknown method");
  if (msg == NULL) {
- logdebug(", incomplete frame");
+ log_debugadd(", incomplete frame");
  break;
  }
- logdebug(", use %d bytes\n", len);
+ log_debug(", use %d bytes", len);
  if (len > 0 && msg[len-1] == '\n')
  msg[len-1] = '\0';
  if (len == 0 || msg[len-1] != '\0') {
@@ -1278,11 +1278,11 @@ tcp_readcb(struct bufferevent *bufev, vo
  }
  /* Maximum frame has 5 digits, 1 space, MAXLINE chars, 1 new line. */
  if (EVBUFFER_LENGTH(bufev->input) >= 5 + 1 + MAXLINE + 1) {
- logdebug(", use %zu bytes\n", EVBUFFER_LENGTH(bufev->input));
+ log_debug(", use %zu bytes", EVBUFFER_LENGTH(bufev->input));
  printline(p->p_hostname, EVBUFFER_DATA(bufev->input));
  evbuffer_drain(bufev->input, -1);
  } else if (EVBUFFER_LENGTH(bufev->input) > 0)
- logdebug(", buffer %zu bytes\n", EVBUFFER_LENGTH(bufev->input));
+ log_debug(", buffer %zu bytes", EVBUFFER_LENGTH(bufev->input));
 }
 
 void
@@ -1346,7 +1346,7 @@ tcp_dropcb(struct bufferevent *bufev, vo
  /*
  * Drop data received from the forward log server.
  */
- logdebug("loghost \"%s\" did send %zu bytes back\n",
+ log_debug("loghost \"%s\" did send %zu bytes back",
     f->f_un.f_forw.f_loghost, EVBUFFER_LENGTH(bufev->input));
  evbuffer_drain(bufev->input, -1);
 }
@@ -1360,7 +1360,7 @@ tcp_writecb(struct bufferevent *bufev, v
  /*
  * Successful write, connection to server is good, reset wait time.
  */
- logdebug("loghost \"%s\" successful write\n", f->f_un.f_forw.f_loghost);
+ log_debug("loghost \"%s\" successful write", f->f_un.f_forw.f_loghost);
  f->f_un.f_forw.f_reconnectwait = 0;
 
  if (f->f_un.f_forw.f_dropped > 0 &&
@@ -1392,7 +1392,7 @@ tcp_errorcb(struct bufferevent *bufev, s
     "syslogd: loghost \"%s\" connection error: %s",
     f->f_un.f_forw.f_loghost, f->f_un.f_forw.f_ctx ?
     tls_error(f->f_un.f_forw.f_ctx) : strerror(errno));
- logdebug("%s\n", ebuf);
+ log_debug("%s", ebuf);
 
  /* The SIGHUP handler may also close the socket, so invalidate it. */
  if (f->f_un.f_forw.f_ctx) {
@@ -1421,7 +1421,7 @@ tcp_errorcb(struct bufferevent *bufev, s
  /* Without '\n' discard everything. */
  if (p == end)
  evbuffer_drain(bufev->output, -1);
- logdebug("loghost \"%s\" dropped partial message\n",
+ log_debug("loghost \"%s\" dropped partial message",
     f->f_un.f_forw.f_loghost);
  f->f_un.f_forw.f_dropped++;
  }
@@ -1444,7 +1444,7 @@ tcp_connectcb(int fd, short event, void
  tcp_connect_retry(bufev, f);
  return;
  }
- logdebug("tcp connect callback: socket success, event %#x\n", event);
+ log_debug("tcp connect callback: socket success, event %#x", event);
  f->f_file = s;
 
  bufferevent_setfd(bufev, s);
@@ -1476,7 +1476,7 @@ tcp_connectcb(int fd, short event, void
  logerrorctx(ebuf, f->f_un.f_forw.f_ctx);
  goto error;
  }
- logdebug("tcp connect callback: tls context success\n");
+ log_debug("tcp connect callback: tls context success");
 
  buffertls_set(&f->f_un.f_forw.f_buftls, bufev,
     f->f_un.f_forw.f_ctx, s);
@@ -1509,7 +1509,7 @@ tcp_connect_retry(struct bufferevent *bu
  to.tv_sec = f->f_un.f_forw.f_reconnectwait;
  to.tv_usec = 0;
 
- logdebug("tcp connect retry: wait %d\n",
+ log_debug("tcp connect retry: wait %d",
     f->f_un.f_forw.f_reconnectwait);
  bufferevent_setfd(bufev, -1);
  /* We can reuse the write event as bufferevent is disabled. */
@@ -1665,7 +1665,7 @@ logmsg(int pri, char *msg, char *from, i
  char timestamp[33];
  char prog[NAME_MAX+1];
 
- logdebug("logmsg: pri 0%o, flags 0x%x, from %s, msg %s\n",
+ log_debug("logmsg: pri 0%o, flags 0x%x, from %s, msg %s",
     pri, flags, from, msg);
 
  /*
@@ -1819,7 +1819,7 @@ logmsg(int pri, char *msg, char *from, i
  strlcpy(f->f_lasttime, timestamp,
     sizeof(f->f_lasttime));
  f->f_prevcount++;
- logdebug("msg repeated %d times, %ld sec of %d\n",
+ log_debug("msg repeated %d times, %ld sec of %d",
     f->f_prevcount, (long)(now.tv_sec - f->f_time),
     repeatinterval[f->f_repeatcount]);
  /*
@@ -1927,16 +1927,16 @@ fprintlog(struct filed *f, int flags, ch
  }
  v++;
 
- logdebug("Logging to %s", TypeNames[f->f_type]);
+ log_debugadd("Logging to %s", TypeNames[f->f_type]);
  f->f_time = now.tv_sec;
 
  switch (f->f_type) {
  case F_UNUSED:
- logdebug("\n");
+ log_debug("%s", "");
  break;
 
  case F_FORWUDP:
- logdebug(" %s\n", f->f_un.f_forw.f_loghost);
+ log_debug(" %s", f->f_un.f_forw.f_loghost);
  l = snprintf(line, MINIMUM(MAX_UDPMSG + 1, sizeof(line)),
     "<%d>%.32s %s%s%s", f->f_prevpri, (char *)iov[0].iov_base,
     IncludeHostname ? LocalHostName : "",
@@ -1966,10 +1966,10 @@ fprintlog(struct filed *f, int flags, ch
 
  case F_FORWTCP:
  case F_FORWTLS:
- logdebug(" %s", f->f_un.f_forw.f_loghost);
+ log_debugadd(" %s", f->f_un.f_forw.f_loghost);
  if (EVBUFFER_LENGTH(f->f_un.f_forw.f_bufev->output) >=
     MAX_TCPBUF) {
- logdebug(" (dropped)\n");
+ log_debug(" (dropped)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
@@ -1985,7 +1985,7 @@ fprintlog(struct filed *f, int flags, ch
     IncludeHostname ? LocalHostName : "",
     IncludeHostname ? " " : "");
  if (l < 0) {
- logdebug(" (dropped snprintf)\n");
+ log_debug(" (dropped snprintf)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
@@ -1997,17 +1997,17 @@ fprintlog(struct filed *f, int flags, ch
     IncludeHostname ? " " : "",
     (char *)iov[4].iov_base);
  if (l < 0) {
- logdebug(" (dropped evbuffer_add_printf)\n");
+ log_debug(" (dropped evbuffer_add_printf)");
  f->f_un.f_forw.f_dropped++;
  break;
  }
  bufferevent_enable(f->f_un.f_forw.f_bufev, EV_WRITE);
- logdebug("\n");
+ log_debug("%s", "");
  break;
 
  case F_CONSOLE:
  if (flags & IGN_CONS) {
- logdebug(" (ignored)\n");
+ log_debug(" (ignored)");
  break;
  }
  /* FALLTHROUGH */
@@ -2015,7 +2015,7 @@ fprintlog(struct filed *f, int flags, ch
  case F_TTY:
  case F_FILE:
  case F_PIPE:
- logdebug(" %s\n", f->f_un.f_fname);
+ log_debug(" %s", f->f_un.f_fname);
  if (f->f_type != F_FILE && f->f_type != F_PIPE) {
  v->iov_base = "\r\n";
  v->iov_len = 2;
@@ -2079,14 +2079,14 @@ fprintlog(struct filed *f, int flags, ch
 
  case F_USERS:
  case F_WALL:
- logdebug("\n");
+ log_debug("%s", "");
  v->iov_base = "\r\n";
  v->iov_len = 2;
  wallmsg(f, iov);
  break;
 
  case F_MEMBUF:
- logdebug("\n");
+ log_debug("%s", "");
  snprintf(line, sizeof(line), "%.32s %s %s",
     (char *)iov[0].iov_base, (char *)iov[2].iov_base,
     (char *)iov[4].iov_base);
@@ -2156,16 +2156,16 @@ cvthname(struct sockaddr *f, char *resul
 {
  if (getnameinfo(f, f->sa_len, result, res_len, NULL, 0,
     NI_NUMERICHOST|NI_NUMERICSERV|NI_DGRAM) != 0) {
- logdebug("Malformed from address\n");
+ log_debug("Malformed from address");
  strlcpy(result, hostname_unknown, res_len);
  return;
  }
- logdebug("cvthname(%s)\n", result);
+ log_debug("cvthname(%s)", result);
  if (NoDNS)
  return;
 
  if (priv_getnameinfo(f, f->sa_len, result, res_len) != 0)
- logdebug("Host name for from address (%s) unknown\n", result);
+ log_debug("Host name for from address (%s) unknown", result);
 }
 
 void
@@ -2196,7 +2196,7 @@ init_signalcb(int signum, short event, v
 
  logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: restart",
     LocalHostName, ADDDATE);
- logdebug("syslogd: restarted\n");
+ log_debug("syslogd: restarted");
 
  if (tcpbuf_dropped > 0) {
  snprintf(ebuf, sizeof(ebuf),
@@ -2210,19 +2210,7 @@ init_signalcb(int signum, short event, v
 void
 logevent(int severity, const char *msg)
 {
- logdebug("libevent: [%d] %s\n", severity, msg);
-}
-
-void
-logdebug(const char *fmt, ...)
-{
- va_list ap;
-
- if (Debug) {
- va_start(ap, fmt);
- vprintf(fmt, ap);
- va_end(ap);
- }
+ log_debug("libevent: [%d] %s", severity, msg);
 }
 
 void
@@ -2260,7 +2248,7 @@ logerror_reason(const char *message, con
  else
  (void)snprintf(ebuf, sizeof(ebuf), "syslogd: %s", message);
  errno = 0;
- logdebug("%s\n", ebuf);
+ log_debug("%s", ebuf);
  if (Startup)
  fprintf(stderr, "%s\n", ebuf);
  else
@@ -2296,12 +2284,12 @@ die(int signo)
  }
 
  if (signo) {
- logdebug("syslogd: exiting on signal %d\n", signo);
+ log_debug("syslogd: exiting on signal %d", signo);
  (void)snprintf(ebuf, sizeof(ebuf), "exiting on signal %d",
     signo);
  logerrorx(ebuf);
  }
- logdebug("[unpriv] syslogd child about to exit\n");
+ log_debug("[unpriv] syslogd child about to exit");
  exit(0);
 }
 
@@ -2318,11 +2306,11 @@ init(void)
  int i;
  size_t s;
 
- logdebug("init\n");
+ log_debug("init");
 
  /* If config file has been modified, then just die to restart */
  if (priv_config_modified()) {
- logdebug("config file changed: dying\n");
+ log_debug("config file changed: dying");
  die(0);
  }
 
@@ -2363,7 +2351,7 @@ init(void)
  if (f->f_type == F_MEMBUF) {
  f->f_program = NULL;
  f->f_hostname = NULL;
- logdebug("add %p to mb\n", f);
+ log_debug("add %p to mb", f);
  SIMPLEQ_INSERT_HEAD(&mb, f, f_next);
  } else
  free(f);
@@ -2372,7 +2360,7 @@ init(void)
 
  /* open the configuration file */
  if ((cf = priv_open_config()) == NULL) {
- logdebug("cannot open %s\n", ConfFile);
+ log_debug("cannot open %s", ConfFile);
  SIMPLEQ_INSERT_TAIL(&Files,
     cfline("*.ERR\t/dev/console", "*", "*"), f_next);
  SIMPLEQ_INSERT_TAIL(&Files,
@@ -2439,7 +2427,7 @@ init(void)
  SIMPLEQ_FOREACH(f, &Files, f_next) {
  if (f->f_type != F_MEMBUF)
  continue;
- logdebug("Initialize membuf %s at %p\n",
+ log_debug("Initialize membuf %s at %p",
     f->f_un.f_mb.f_mname, f);
 
  SIMPLEQ_FOREACH(m, &mb, f_next) {
@@ -2450,14 +2438,14 @@ init(void)
  break;
  }
  if (m == NULL) {
- logdebug("Membuf no match\n");
+ log_debug("Membuf no match");
  f->f_un.f_mb.f_rb = ringbuf_init(f->f_un.f_mb.f_len);
  if (f->f_un.f_mb.f_rb == NULL) {
  f->f_type = F_UNUSED;
  logerror("Failed to allocate membuf");
  }
  } else {
- logdebug("Membuf match f:%p, m:%p\n", f, m);
+ log_debug("Membuf match f:%p, m:%p", f, m);
  f->f_un = m->f_un;
  m->f_un.f_mb.f_rb = NULL;
  }
@@ -2471,7 +2459,7 @@ init(void)
  logerrorx("Mismatched membuf");
  ringbuf_free(m->f_un.f_mb.f_rb);
  }
- logdebug("Freeing membuf %p\n", m);
+ log_debug("Freeing membuf %p", m);
 
  free(m);
  }
@@ -2545,7 +2533,7 @@ find_dup(struct filed *f)
  if (strcmp(list->f_un.f_fname, f->f_un.f_fname) == 0 &&
     progmatches(list->f_program, f->f_program) &&
     progmatches(list->f_hostname, f->f_hostname)) {
- logdebug("duplicate %s\n", f->f_un.f_fname);
+ log_debug("duplicate %s", f->f_un.f_fname);
  return (list);
  }
  break;
@@ -2554,7 +2542,7 @@ find_dup(struct filed *f)
     f->f_un.f_mb.f_mname) == 0 &&
     progmatches(list->f_program, f->f_program) &&
     progmatches(list->f_hostname, f->f_hostname)) {
- logdebug("duplicate membuf %s\n",
+ log_debug("duplicate membuf %s",
     f->f_un.f_mb.f_mname);
  return (list);
  }
@@ -2577,7 +2565,7 @@ cfline(char *line, char *progblock, char
  struct filed *xf, *f, *d;
  struct timeval to;
 
- logdebug("cfline(\"%s\", f, \"%s\", \"%s\")\n",
+ log_debug("cfline(\"%s\", f, \"%s\", \"%s\")",
     line, progblock, hostblock);
 
  if ((f = calloc(1, sizeof(*f))) == NULL) {
@@ -2935,7 +2923,7 @@ getmsgbufsize(void)
  mib[1] = KERN_MSGBUFSIZE;
  size = sizeof msgbufsize;
  if (sysctl(mib, 2, &msgbufsize, &size, NULL, 0) == -1) {
- logdebug("couldn't get kern.msgbufsize\n");
+ log_debug("couldn't get kern.msgbufsize");
  return (0);
  }
  return (msgbufsize);
@@ -2979,7 +2967,7 @@ markit(void)
 
  SIMPLEQ_FOREACH(f, &Files, f_next) {
  if (f->f_prevcount && now.tv_sec >= REPEATTIME(f)) {
- logdebug("flush %s: repeated %d times, %d sec.\n",
+ log_debug("flush %s: repeated %d times, %d sec",
     TypeNames[f->f_type], f->f_prevcount,
     repeatinterval[f->f_repeatcount]);
  fprintlog(f, 0, (char *)NULL);
@@ -3113,7 +3101,7 @@ ctlsock_acceptcb(int fd, short event, vo
  logerror("accept ctlsock");
  return;
  }
- logdebug("Accepting control connection\n");
+ log_debug("Accepting control connection");
 
  if (fd_ctlconn != -1)
  ctlconn_cleanup();
@@ -3199,7 +3187,7 @@ ctlconn_readcb(int fd, short event, void
  memset(reply_hdr, '\0', sizeof(*reply_hdr));
 
  ctl_cmd.cmd = ntohl(ctl_cmd.cmd);
- logdebug("ctlcmd %x logname \"%s\"\n", ctl_cmd.cmd, ctl_cmd.logname);
+ log_debug("ctlcmd %x logname \"%s\"", ctl_cmd.cmd, ctl_cmd.logname);
 
  switch (ctl_cmd.cmd) {
  case CMD_READ:
@@ -3264,7 +3252,7 @@ ctlconn_readcb(int fd, short event, void
  reply_hdr->flags = htonl(flags);
 
  ctl_reply_size = CTL_REPLY_SIZE;
- logdebug("ctlcmd reply length %lu\n", (u_long)ctl_reply_size);
+ log_debug("ctlcmd reply length %lu", (u_long)ctl_reply_size);
 
  /* Otherwise, set up to write out reply */
  ctl_state = (ctl_cmd.cmd == CMD_READ_CONT) ?
Index: usr.sbin/syslogd/syslogd.h
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/syslogd.h,v
retrieving revision 1.27
diff -u -p -r1.27 syslogd.h
--- usr.sbin/syslogd/syslogd.h 16 Mar 2017 23:55:19 -0000 1.27
+++ usr.sbin/syslogd/syslogd.h 4 Apr 2017 23:51:59 -0000
@@ -50,7 +50,6 @@ extern char *path_ctlsock;
 
 #define MAXLINE 8192 /* maximum line length */
 #define ERRBUFSIZE 256
-void logdebug(const char *, ...) __attribute__((__format__ (printf, 1, 2)));
 void vlogmsg(int pri, const char *, const char *, va_list);
 __dead void die(int);
 extern int Debug;
Index: usr.sbin/syslogd/ttymsg.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/ttymsg.c,v
retrieving revision 1.13
diff -u -p -r1.13 ttymsg.c
--- usr.sbin/syslogd/ttymsg.c 24 Mar 2017 16:24:36 -0000 1.13
+++ usr.sbin/syslogd/ttymsg.c 4 Apr 2017 23:51:59 -0000
@@ -42,6 +42,7 @@
 #include <string.h>
 #include <unistd.h>
 
+#include "log.h"
 #include "syslogd.h"
 
 #ifndef nitems
@@ -139,7 +140,7 @@ ttymsg(struct iovec *iov, int iovcnt, ch
     "%s: too many delayed writes", device);
  goto error;
  }
- logdebug("ttymsg delayed write\n");
+ log_debug("ttymsg delayed write");
  if (iov != localiov) {
  memmove(localiov, iov,
     iovcnt * sizeof(struct iovec));

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log fatal

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.

Replace all combinations of logerror() and die() with log.c fatal().
Also all err(3) after log_init() are replaced.

ok?

bluhm

Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.235
diff -u -p -r1.235 syslogd.c
--- usr.sbin/syslogd/syslogd.c 5 Apr 2017 11:31:45 -0000 1.235
+++ usr.sbin/syslogd/syslogd.c 5 Apr 2017 11:50:40 -0000
@@ -470,16 +470,12 @@ main(int argc, char *argv[])
  if (Debug)
  setvbuf(stdout, NULL, _IOLBF, 0);
 
- if ((nullfd = open(_PATH_DEVNULL, O_RDWR)) == -1) {
- logerror("Couldn't open /dev/null");
- die(0);
- }
+ if ((nullfd = open(_PATH_DEVNULL, O_RDWR)) == -1)
+ fatal("open %s", _PATH_DEVNULL);
  for (fd = nullfd + 1; fd <= STDERR_FILENO; fd++) {
  if (fcntl(fd, F_GETFL) == -1 && errno == EBADF)
- if (dup2(nullfd, fd) == -1) {
- logerror("dup2");
- die(0);
- }
+ if (dup2(nullfd, fd) == -1)
+ fatal("dup2 null");
  }
 
  if (PrivChild > 1)
@@ -500,16 +496,14 @@ main(int argc, char *argv[])
  if (linesize < MAXLINE)
  linesize = MAXLINE;
  linesize++;
- if ((linebuf = malloc(linesize)) == NULL) {
- logerror("Couldn't allocate line buffer");
- die(0);
- }
+ if ((linebuf = malloc(linesize)) == NULL)
+ fatal("allocate line buffer");
 
  if (socket_bind("udp", NULL, "syslog", SecureMode,
     &fd_udp, &fd_udp6) == -1)
  logerrorx("socket bind *");
  if ((fd_bind = reallocarray(NULL, nbind, sizeof(*fd_bind))) == NULL)
- err(1, "bind fd");
+ fatal("allocate bind fd");
  for (i = 0; i < nbind; i++) {
  if (socket_bind("udp", bind_host[i], bind_port[i], 0,
     &fd_bind[i], &fd_bind[i]) == -1)
@@ -517,7 +511,7 @@ main(int argc, char *argv[])
  }
  if ((fd_listen = reallocarray(NULL, nlisten, sizeof(*fd_listen)))
     == NULL)
- err(1, "listen fd");
+ fatal("allocate listen fd");
  for (i = 0; i < nlisten; i++) {
  if (socket_bind("tcp", listen_host[i], listen_port[i], 0,
     &fd_listen[i], &fd_listen[i]) == -1)
@@ -529,7 +523,7 @@ main(int argc, char *argv[])
  logerrorx("socket listen tls");
 
  if ((fd_unix = reallocarray(NULL, nunix, sizeof(*fd_unix))) == NULL)
- err(1, "malloc unix");
+ fatal("allocate unix fd");
  for (i = 0; i < nunix; i++) {
  fd_unix[i] = unix_socket(path_unix[i], SOCK_DGRAM, 0666);
  if (fd_unix[i] == -1) {
@@ -782,10 +776,8 @@ main(int argc, char *argv[])
 
  /* Allocate ctl socket reply buffer if we have a ctl socket */
  if (fd_ctlsock != -1 &&
-    (ctl_reply = malloc(CTL_REPLY_MAXSIZE)) == NULL) {
- logerror("Couldn't allocate ctlsock reply buffer");
- die(0);
- }
+    (ctl_reply = malloc(CTL_REPLY_MAXSIZE)) == NULL)
+ fatal("allocate control socket reply buffer");
  reply_text = ctl_reply + CTL_HDR_LEN;
 
  if (!Debug) {
@@ -2418,10 +2410,8 @@ init(void)
  SIMPLEQ_INSERT_TAIL(&Files, f, f_next);
  }
  free(cline);
- if (!feof(cf)) {
- logerror("Unable to read config file");
- die(0);
- }
+ if (!feof(cf))
+ fatal("read config file");
 
  /* Match and initialize the memory buffers */
  SIMPLEQ_FOREACH(f, &Files, f_next) {
@@ -2568,10 +2558,8 @@ cfline(char *line, char *progblock, char
  log_debug("cfline(\"%s\", f, \"%s\", \"%s\")",
     line, progblock, hostblock);
 
- if ((f = calloc(1, sizeof(*f))) == NULL) {
- logerror("Couldn't allocate struct filed");
- die(0);
- }
+ if ((f = calloc(1, sizeof(*f))) == NULL)
+ fatal("allocate struct filed");
  for (i = 0; i <= LOG_NFACILITIES; i++)
  f->f_pmask[i] = INTERNAL_NOPRI;
 

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_debug

Todd C. Miller
In reply to this post by Alexander Bluhm
On Wed, 05 Apr 2017 02:10:44 +0200, Alexander Bluhm wrote:

> Updated diff after unlock, ok?

Looks correct. OK millert@

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log fatal

Todd C. Miller
In reply to this post by Alexander Bluhm
On Wed, 05 Apr 2017 13:58:12 +0200, Alexander Bluhm wrote:

> On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> > This is the next step for refactoring internal syslogd(8) logging.
>
> Replace all combinations of logerror() and die() with log.c fatal().
> Also all err(3) after log_init() are replaced.

This is before we start accepting log messages so no need to call die().
OK millert@

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log fatal

Alexander Bluhm
On Wed, Apr 05, 2017 at 08:18:03AM -0600, Todd C. Miller wrote:
> On Wed, 05 Apr 2017 13:58:12 +0200, Alexander Bluhm wrote:
> > Replace all combinations of logerror() and die() with log.c fatal().
> > Also all err(3) after log_init() are replaced.
>
> This is before we start accepting log messages so no need to call die().

Syslogd's fatal() calls die() internally, so there is no change in
behavior.  The idea is that you may call fatal() anywhere and die()
will do cleanup if necessary.

But you are right, calls to fatal() have been reduced to a few early
locations.  So this cleanup is never necessary.

bluhm

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log fatal

Todd C. Miller
On Wed, 05 Apr 2017 16:51:13 +0200, Alexander Bluhm wrote:

> Syslogd's fatal() calls die() internally, so there is no change in
> behavior.  The idea is that you may call fatal() anywhere and die()
> will do cleanup if necessary.

Ah, right, I missed that.

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_warn

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.

Replace logerror() functions with generic log_warn() from log.c.
Make messages a bit more consistent.  Note that the new function
supports format strings.  Replace some log_debug() with log_warn().

ok?

bluhm

Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.236
diff -u -p -r1.236 syslogd.c
--- usr.sbin/syslogd/syslogd.c 5 Apr 2017 15:16:12 -0000 1.236
+++ usr.sbin/syslogd/syslogd.c 5 Apr 2017 16:07:14 -0000
@@ -321,11 +321,6 @@ void markit(void);
 void fprintlog(struct filed *, int, char *);
 void init(void);
 void logevent(int, const char *);
-void logerror(const char *);
-void logerrorx(const char *);
-void logerrorctx(const char *, struct tls *);
-void logerrortlsconf(const char *, struct tls_config *);
-void logerror_reason(const char *, const char *);
 void logmsg(int, char *, char *, int);
 struct filed *find_dup(struct filed *);
 size_t parsepriority(const char *, int *);
@@ -501,13 +496,13 @@ main(int argc, char *argv[])
 
  if (socket_bind("udp", NULL, "syslog", SecureMode,
     &fd_udp, &fd_udp6) == -1)
- logerrorx("socket bind *");
+ log_warnx("socket bind * failed");
  if ((fd_bind = reallocarray(NULL, nbind, sizeof(*fd_bind))) == NULL)
  fatal("allocate bind fd");
  for (i = 0; i < nbind; i++) {
  if (socket_bind("udp", bind_host[i], bind_port[i], 0,
     &fd_bind[i], &fd_bind[i]) == -1)
- logerrorx("socket bind udp");
+ log_warnx("socket bind udp failed");
  }
  if ((fd_listen = reallocarray(NULL, nlisten, sizeof(*fd_listen)))
     == NULL)
@@ -515,12 +510,12 @@ main(int argc, char *argv[])
  for (i = 0; i < nlisten; i++) {
  if (socket_bind("tcp", listen_host[i], listen_port[i], 0,
     &fd_listen[i], &fd_listen[i]) == -1)
- logerrorx("socket listen tcp");
+ log_warnx("socket listen tcp failed");
  }
  fd_tls = -1;
  if (tls_host && socket_bind("tls", tls_host, tls_port, 0,
     &fd_tls, &fd_tls) == -1)
- logerrorx("socket listen tls");
+ log_warnx("socket listen tls failed");
 
  if ((fd_unix = reallocarray(NULL, nunix, sizeof(*fd_unix))) == NULL)
  fatal("allocate unix fd");
@@ -528,14 +523,14 @@ main(int argc, char *argv[])
  fd_unix[i] = unix_socket(path_unix[i], SOCK_DGRAM, 0666);
  if (fd_unix[i] == -1) {
  if (i == 0)
- logerrorx("log socket failed");
+ log_warnx("log socket %s failed", path_unix[i]);
  continue;
  }
  double_sockbuf(fd_unix[i], SO_RCVBUF);
  }
 
  if (socketpair(AF_UNIX, SOCK_DGRAM, PF_UNSPEC, pair) == -1) {
- logerror("socketpair");
+ log_warn("socketpair sendsyslog");
  fd_sendsys = -1;
  } else {
  double_sockbuf(pair[0], SO_RCVBUF);
@@ -547,10 +542,10 @@ main(int argc, char *argv[])
  if (path_ctlsock != NULL) {
  fd_ctlsock = unix_socket(path_ctlsock, SOCK_STREAM, 0600);
  if (fd_ctlsock == -1) {
- log_debug("can't open %s (%d)", path_ctlsock, errno);
+ log_warnx("control socket %s failed", path_ctlsock);
  } else {
  if (listen(fd_ctlsock, 5) == -1) {
- logerror("ctlsock listen");
+ log_warn("listen control socket");
  close(fd_ctlsock);
  fd_ctlsock = -1;
  }
@@ -558,24 +553,24 @@ main(int argc, char *argv[])
  }
 
  if ((fd_klog = open(_PATH_KLOG, O_RDONLY, 0)) == -1) {
- log_debug("can't open %s (%d)", _PATH_KLOG, errno);
+ log_warn("open %s", _PATH_KLOG);
  } else if (fd_sendsys != -1) {
  if (ioctl(fd_klog, LIOCSFD, &pair[1]) == -1)
- log_debug("LIOCSFD errno %d", errno);
+ log_warn("ioctl klog LIOCSFD sendsyslog");
  }
  if (fd_sendsys != -1)
  close(pair[1]);
 
  if (tls_init() == -1) {
- logerrorx("tls_init");
+ log_warn("tls_init");
  } else {
  if ((client_config = tls_config_new()) == NULL)
- logerror("tls_config_new client");
+ log_warn("tls_config_new client");
  if (tls_hostport) {
  if ((server_config = tls_config_new()) == NULL)
- logerror("tls_config_new server");
+ log_warn("tls_config_new server");
  if ((server_ctx = tls_server()) == NULL) {
- logerror("tls_server");
+ log_warn("tls_server");
  close(fd_tls);
  fd_tls = -1;
  }
@@ -588,8 +583,8 @@ main(int argc, char *argv[])
  } else {
  if (tls_config_set_ca_file(client_config,
     CAfile) == -1) {
- logerrortlsconf("Load client TLS CA failed",
-    client_config);
+ log_warnx("load client TLS CA: %s",
+    tls_config_error(client_config));
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(client_config, "", 0);
  } else
@@ -598,27 +593,27 @@ main(int argc, char *argv[])
  if (ClientCertfile && ClientKeyfile) {
  if (tls_config_set_cert_file(client_config,
     ClientCertfile) == -1)
- logerrortlsconf("Load client TLS cert failed",
-    client_config);
+ log_warnx("load client TLS cert: %s",
+    tls_config_error(client_config));
  else
  log_debug("ClientCertfile %s", ClientCertfile);
 
  if (tls_config_set_key_file(client_config,
     ClientKeyfile) == -1)
- logerrortlsconf("Load client TLS key failed",
-    client_config);
+ log_warnx("load client TLS key: %s",
+    tls_config_error(client_config));
  else
  log_debug("ClientKeyfile %s", ClientKeyfile);
  } else if (ClientCertfile || ClientKeyfile) {
- logerrorx("options -c and -k must be used together");
+ log_warnx("options -c and -k must be used together");
  }
  if (tls_config_set_protocols(client_config,
     TLS_PROTOCOLS_ALL) != 0)
- logerrortlsconf("Set client TLS protocols failed",
-    client_config);
+ log_warnx("set client TLS protocols: %s",
+    tls_config_error(client_config));
  if (tls_config_set_ciphers(client_config, "all") != 0)
- logerrortlsconf("Set client TLS ciphers failed",
-    client_config);
+ log_warnx("set client TLS ciphers: %s",
+    tls_config_error(client_config));
  }
  if (server_config && server_ctx) {
  const char *names[2];
@@ -631,8 +626,8 @@ main(int argc, char *argv[])
     == -1)
  continue;
  if (tls_config_set_key_file(server_config, p) == -1) {
- logerrortlsconf("Load server TLS key failed",
-    server_config);
+ log_warnx("load server TLS key: %s",
+    tls_config_error(server_config));
  free(p);
  continue;
  }
@@ -641,8 +636,8 @@ main(int argc, char *argv[])
  if (asprintf(&p, "/etc/ssl/%s.crt", names[i]) == -1)
  continue;
  if (tls_config_set_cert_file(server_config, p) == -1) {
- logerrortlsconf("Load server TLS cert failed",
-    server_config);
+ log_warnx("load server TLS cert: %s",
+    tls_config_error(server_config));
  free(p);
  continue;
  }
@@ -654,8 +649,8 @@ main(int argc, char *argv[])
  if (ServerCAfile) {
  if (tls_config_set_ca_file(server_config,
     ServerCAfile) == -1) {
- logerrortlsconf("Load server TLS CA failed",
-    server_config);
+ log_warnx("load server TLS CA: %s",
+    tls_config_error(server_config));
  /* avoid reading default certs in chroot */
  tls_config_set_ca_mem(server_config, "", 0);
  } else
@@ -664,13 +659,14 @@ main(int argc, char *argv[])
  }
  if (tls_config_set_protocols(server_config,
     TLS_PROTOCOLS_ALL) != 0)
- logerrortlsconf("Set server TLS protocols failed",
-    server_config);
+ log_warnx("set server TLS protocols: %s",
+    tls_config_error(server_config));
  if (tls_config_set_ciphers(server_config, "compat") != 0)
- logerrortlsconf("Set server TLS ciphers failed",
-    server_config);
+ log_warnx("Set server TLS ciphers: %s",
+    tls_config_error(server_config));
  if (tls_configure(server_ctx, server_config) != 0) {
- logerrorctx("tls_configure server", server_ctx);
+ log_warnx("tls_configure server: %s",
+    tls_error(server_ctx));
  tls_free(server_ctx);
  server_ctx = NULL;
  close(fd_tls);
@@ -871,7 +867,6 @@ socket_bind(const char *proto, const cha
 {
  struct addrinfo hints, *res, *res0;
  char hostname[NI_MAXHOST], servname[NI_MAXSERV];
- char ebuf[ERRBUFSIZE];
  int *fdp, error, reuseaddr;
 
  *fd = *fd6 = -1;
@@ -892,10 +887,8 @@ socket_bind(const char *proto, const cha
  hints.ai_flags = AI_PASSIVE;
 
  if ((error = getaddrinfo(host, port, &hints, &res0))) {
- snprintf(ebuf, sizeof(ebuf), "getaddrinfo "
-    "proto %s, host %s, port %s: %s",
+ log_warnx("getaddrinfo proto %s, host %s, port %s: %s",
     proto, host ? host : "*", port, gai_strerror(error));
- logerrorx(ebuf);
  return (-1);
  }
 
@@ -925,10 +918,9 @@ socket_bind(const char *proto, const cha
  hostname[0] = servname[0] = '\0';
  }
  if (shutread && shutdown(*fdp, SHUT_RD) == -1) {
- snprintf(ebuf, sizeof(ebuf), "shutdown SHUT_RD "
+ log_warn("shutdown SHUT_RD "
     "protocol %d, address %s, portnum %s",
     res->ai_protocol, hostname, servname);
- logerror(ebuf);
  close(*fdp);
  *fdp = -1;
  continue;
@@ -940,29 +932,24 @@ socket_bind(const char *proto, const cha
  reuseaddr = 1;
  if (setsockopt(*fdp, SOL_SOCKET, SO_REUSEADDR, &reuseaddr,
     sizeof(reuseaddr)) == -1) {
- snprintf(ebuf, sizeof(ebuf), "setsockopt SO_REUSEADDR "
+ log_warn("setsockopt SO_REUSEADDR "
     "protocol %d, address %s, portnum %s",
     res->ai_protocol, hostname, servname);
- logerror(ebuf);
  close(*fdp);
  *fdp = -1;
  continue;
  }
  if (bind(*fdp, res->ai_addr, res->ai_addrlen) == -1) {
- snprintf(ebuf, sizeof(ebuf), "bind "
-    "protocol %d, address %s, portnum %s",
+ log_warn("bind protocol %d, address %s, portnum %s",
     res->ai_protocol, hostname, servname);
- logerror(ebuf);
  close(*fdp);
  *fdp = -1;
  continue;
  }
  if (!shutread && res->ai_protocol == IPPROTO_TCP &&
     listen(*fdp, 10) == -1) {
- snprintf(ebuf, sizeof(ebuf), "listen "
-    "protocol %d, address %s, portnum %s",
+ log_warn("listen protocol %d, address %s, portnum %s",
     res->ai_protocol, hostname, servname);
- logerror(ebuf);
  close(*fdp);
  *fdp = -1;
  continue;
@@ -987,7 +974,7 @@ klog_readcb(int fd, short event, void *a
  linebuf[n] = '\0';
  printsys(linebuf);
  } else if (n < 0 && errno != EINTR) {
- logerror("klog");
+ log_warn("read klog");
  event_del(ev);
  }
 }
@@ -1009,7 +996,7 @@ udp_readcb(int fd, short event, void *ar
  log_debug("cvthname res: %s", resolve);
  printline(resolve, linebuf);
  } else if (n < 0 && errno != EINTR && errno != EWOULDBLOCK)
- logerror("recvfrom udp");
+ log_warn("recvfrom udp");
 }
 
 void
@@ -1025,7 +1012,7 @@ unix_readcb(int fd, short event, void *a
  linebuf[n] = '\0';
  printline(LocalHostName, linebuf);
  } else if (n < 0 && errno != EINTR && errno != EWOULDBLOCK)
- logerror("recvfrom unix");
+ log_warn("recvfrom unix");
 }
 
 int
@@ -1098,7 +1085,7 @@ acceptcb(int lfd, short event, void *arg
  if (errno != ENFILE && errno != EMFILE &&
     errno != EINTR && errno != EWOULDBLOCK &&
     errno != ECONNABORTED)
- logerror("accept tcp socket");
+ log_warn("accept tcp socket");
  return;
  }
  log_debug("Accepting tcp connection");
@@ -1113,16 +1100,14 @@ acceptcb(int lfd, short event, void *arg
  }
  log_debug("Peer addresss and port %s", peername);
  if ((p = malloc(sizeof(*p))) == NULL) {
- snprintf(ebuf, sizeof(ebuf), "malloc \"%s\"", peername);
- logerror(ebuf);
+ log_warn("allocate \"%s\"", peername);
  close(fd);
  return;
  }
  p->p_fd = fd;
  if ((p->p_bufev = bufferevent_new(fd, tcp_readcb, NULL, tcp_closecb,
     p)) == NULL) {
- snprintf(ebuf, sizeof(ebuf), "bufferevent \"%s\"", peername);
- logerror(ebuf);
+ log_warn("bufferevent \"%s\"", peername);
  free(p);
  close(fd);
  return;
@@ -1130,9 +1115,8 @@ acceptcb(int lfd, short event, void *arg
  p->p_ctx = NULL;
  if (usetls) {
  if (tls_accept_socket(server_ctx, &p->p_ctx, fd) < 0) {
- snprintf(ebuf, sizeof(ebuf), "tls_accept_socket \"%s\"",
-    peername);
- logerrorctx(ebuf, server_ctx);
+ log_warnx("tls_accept_socket \"%s\": %s",
+    peername, tls_error(server_ctx));
  bufferevent_free(p->p_bufev);
  free(p);
  close(fd);
@@ -1309,21 +1293,16 @@ int
 tcp_socket(struct filed *f)
 {
  int s;
- char ebuf[ERRBUFSIZE];
 
  if ((s = socket(f->f_un.f_forw.f_addr.ss_family,
     SOCK_STREAM | SOCK_NONBLOCK, IPPROTO_TCP)) == -1) {
- snprintf(ebuf, sizeof(ebuf), "socket \"%s\"",
-    f->f_un.f_forw.f_loghost);
- logerror(ebuf);
+ log_warn("socket \"%s\"", f->f_un.f_forw.f_loghost);
  return (-1);
  }
  set_sockbuf(s);
  if (connect(s, (struct sockaddr *)&f->f_un.f_forw.f_addr,
     f->f_un.f_forw.f_addr.ss_len) == -1 && errno != EINPROGRESS) {
- snprintf(ebuf, sizeof(ebuf), "connect \"%s\"",
-    f->f_un.f_forw.f_loghost);
- logerror(ebuf);
+ log_warn("connect \"%s\"", f->f_un.f_forw.f_loghost);
  close(s);
  return (-1);
  }
@@ -1429,7 +1408,6 @@ tcp_connectcb(int fd, short event, void
 {
  struct filed *f = arg;
  struct bufferevent *bufev = f->f_un.f_forw.f_bufev;
- char ebuf[ERRBUFSIZE];
  int s;
 
  if ((s = tcp_socket(f)) == -1) {
@@ -1449,23 +1427,21 @@ tcp_connectcb(int fd, short event, void
 
  if (f->f_type == F_FORWTLS) {
  if ((f->f_un.f_forw.f_ctx = tls_client()) == NULL) {
- snprintf(ebuf, sizeof(ebuf), "tls_client \"%s\"",
-    f->f_un.f_forw.f_loghost);
- logerror(ebuf);
+ log_warn("tls_client \"%s\"", f->f_un.f_forw.f_loghost);
  goto error;
  }
  if (client_config &&
     tls_configure(f->f_un.f_forw.f_ctx, client_config) == -1) {
- snprintf(ebuf, sizeof(ebuf), "tls_configure \"%s\"",
-    f->f_un.f_forw.f_loghost);
- logerrorctx(ebuf, f->f_un.f_forw.f_ctx);
+ log_warnx("tls_configure \"%s\": %s",
+    f->f_un.f_forw.f_loghost,
+    tls_error(f->f_un.f_forw.f_ctx));
  goto error;
  }
  if (tls_connect_socket(f->f_un.f_forw.f_ctx, s,
     f->f_un.f_forw.f_host) == -1) {
- snprintf(ebuf, sizeof(ebuf), "tls_connect_socket "
-    "\"%s\"", f->f_un.f_forw.f_loghost);
- logerrorctx(ebuf, f->f_un.f_forw.f_ctx);
+ log_warnx("tls_connect_socket \"%s\": %s",
+    f->f_un.f_forw.f_loghost,
+    tls_error(f->f_un.f_forw.f_ctx));
  goto error;
  }
  log_debug("tcp connect callback: tls context success");
@@ -1950,7 +1926,8 @@ fprintlog(struct filed *f, int flags, ch
  break;
  default:
  f->f_type = F_UNUSED;
- logerror("sendto");
+ log_warn("sendto \"%s\"",
+    f->f_un.f_forw.f_loghost);
  break;
  }
  }
@@ -2024,7 +2001,8 @@ fprintlog(struct filed *f, int flags, ch
  if (e == EAGAIN && f->f_type == F_PIPE) {
  if (now.tv_sec - f->f_lasterrtime > 120) {
  f->f_lasterrtime = now.tv_sec;
- logerror(f->f_un.f_fname);
+ log_warn("writev \"%s\"",
+    f->f_un.f_fname);
  }
  break;
  }
@@ -2047,7 +2025,8 @@ fprintlog(struct filed *f, int flags, ch
  retryonce = 1;
  if (f->f_file < 0) {
  f->f_type = F_UNUSED;
- logerror(f->f_un.f_fname);
+ log_warn("priv_open_tty \"%s\"",
+    f->f_un.f_fname);
  } else
  goto again;
  } else if ((e == EPIPE || e == EBADF) &&
@@ -2056,14 +2035,15 @@ fprintlog(struct filed *f, int flags, ch
  retryonce = 1;
  if (f->f_file < 0) {
  f->f_type = F_UNUSED;
- logerror(f->f_un.f_fname);
+ log_warn("priv_open_log \"%s\"",
+    f->f_un.f_fname);
  } else
  goto again;
  } else {
  f->f_type = F_UNUSED;
  f->f_file = -1;
  errno = e;
- logerror(f->f_un.f_fname);
+ log_warn("writev \"%s\"", f->f_un.f_fname);
  }
  } else if (flags & SYNC_FILE)
  (void)fsync(f->f_file);
@@ -2109,7 +2089,7 @@ wallmsg(struct filed *f, struct iovec *i
  if (reenter++)
  return;
  if ((uf = priv_open_utmp()) == NULL) {
- logerror(_PATH_UTMP);
+ log_warn("priv_open_utmp");
  reenter = 0;
  return;
  }
@@ -2121,7 +2101,7 @@ wallmsg(struct filed *f, struct iovec *i
  utline[sizeof(utline) - 1] = '\0';
  if (f->f_type == F_WALL) {
  if ((p = ttymsg(iov, 6, utline)) != NULL)
- logerrorx(p);
+ log_warnx("%s", p);
  continue;
  }
  /* should we send the message to this user? */
@@ -2131,7 +2111,7 @@ wallmsg(struct filed *f, struct iovec *i
  if (!strncmp(f->f_un.f_uname[i], ut.ut_name,
     UT_NAMESIZE)) {
  if ((p = ttymsg(iov, 6, utline)) != NULL)
- logerrorx(p);
+ log_warnx("%s", p);
  break;
  }
  }
@@ -2205,48 +2185,6 @@ logevent(int severity, const char *msg)
  log_debug("libevent: [%d] %s", severity, msg);
 }
 
-void
-logerror(const char *message)
-{
- logerror_reason(message, errno ? strerror(errno) : NULL);
-}
-
-void
-logerrorx(const char *message)
-{
- logerror_reason(message, NULL);
-}
-
-void
-logerrorctx(const char *message, struct tls *ctx)
-{
- logerror_reason(message, ctx ? tls_error(ctx) : NULL);
-}
-
-void
-logerrortlsconf(const char *message, struct tls_config *config)
-{
- logerror_reason(message, config ? tls_config_error(config) : NULL);
-}
-
-void
-logerror_reason(const char *message, const char *reason)
-{
- char ebuf[ERRBUFSIZE];
-
- if (reason)
- (void)snprintf(ebuf, sizeof(ebuf), "syslogd: %s: %s",
-    message, reason);
- else
- (void)snprintf(ebuf, sizeof(ebuf), "syslogd: %s", message);
- errno = 0;
- log_debug("%s", ebuf);
- if (Startup)
- fprintf(stderr, "%s\n", ebuf);
- else
- logmsg(LOG_SYSLOG|LOG_ERR, ebuf, LocalHostName, ADDDATE);
-}
-
 __dead void
 die(int signo)
 {
@@ -2275,13 +2213,9 @@ die(int signo)
  logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
  }
 
- if (signo) {
- log_debug("syslogd: exiting on signal %d", signo);
- (void)snprintf(ebuf, sizeof(ebuf), "exiting on signal %d",
-    signo);
- logerrorx(ebuf);
- }
- log_debug("[unpriv] syslogd child about to exit");
+ if (signo)
+ log_warnx("exiting on signal %d", signo);
+ log_debug("syslogd: exited");
  exit(0);
 }
 
@@ -2432,7 +2366,7 @@ init(void)
  f->f_un.f_mb.f_rb = ringbuf_init(f->f_un.f_mb.f_len);
  if (f->f_un.f_mb.f_rb == NULL) {
  f->f_type = F_UNUSED;
- logerror("Failed to allocate membuf");
+ log_warn("allocate membuf");
  }
  } else {
  log_debug("Membuf match f:%p, m:%p", f, m);
@@ -2446,7 +2380,7 @@ init(void)
  m = SIMPLEQ_FIRST(&mb);
  SIMPLEQ_REMOVE_HEAD(&mb, f_next);
  if (m->f_un.f_mb.f_rb != NULL) {
- logerrorx("Mismatched membuf");
+ log_warnx("mismatched membuf");
  ringbuf_free(m->f_un.f_mb.f_rb);
  }
  log_debug("Freeing membuf %p", m);
@@ -2551,7 +2485,7 @@ cfline(char *line, char *progblock, char
  int i, pri;
  size_t rb_len;
  char *bp, *p, *q, *proto, *host, *port, *ipproto;
- char buf[MAXLINE], ebuf[ERRBUFSIZE];
+ char buf[MAXLINE];
  struct filed *xf, *f, *d;
  struct timeval to;
 
@@ -2605,9 +2539,7 @@ cfline(char *line, char *progblock, char
 
  pri = decode(buf, prioritynames);
  if (pri < 0) {
- (void)snprintf(ebuf, sizeof ebuf,
-    "unknown priority name \"%s\"", buf);
- logerrorx(ebuf);
+ log_warnx("unknown priority name \"%s\"", buf);
  free(f);
  return (NULL);
  }
@@ -2624,10 +2556,8 @@ cfline(char *line, char *progblock, char
  else {
  i = decode(buf, facilitynames);
  if (i < 0) {
- (void)snprintf(ebuf, sizeof(ebuf),
-    "unknown facility name \"%s\"",
-    buf);
- logerrorx(ebuf);
+ log_warnx("unknown facility name "
+    "\"%s\"", buf);
  free(f);
  return (NULL);
  }
@@ -2649,15 +2579,12 @@ cfline(char *line, char *progblock, char
  if ((strlcpy(f->f_un.f_forw.f_loghost, p,
     sizeof(f->f_un.f_forw.f_loghost)) >=
     sizeof(f->f_un.f_forw.f_loghost))) {
- snprintf(ebuf, sizeof(ebuf), "loghost too long \"%s\"",
-    p);
- logerrorx(ebuf);
+ log_warnx("loghost too long \"%s\"", p);
  break;
  }
  if (loghost_parse(++p, &proto, &host, &port) == -1) {
- snprintf(ebuf, sizeof(ebuf), "bad loghost \"%s\"",
+ log_warnx("bad loghost \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  if (proto == NULL)
@@ -2671,16 +2598,14 @@ cfline(char *line, char *progblock, char
  ipproto = proto;
  } else if (strcmp(proto, "udp4") == 0) {
  if (fd_udp == -1) {
- snprintf(ebuf, sizeof(ebuf), "no udp4 \"%s\"",
+ log_warnx("no udp4 \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  } else if (strcmp(proto, "udp6") == 0) {
  if (fd_udp6 == -1) {
- snprintf(ebuf, sizeof(ebuf), "no udp6 \"%s\"",
+ log_warnx("no udp6 \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  } else if (strcmp(proto, "tcp") == 0 ||
@@ -2693,32 +2618,28 @@ cfline(char *line, char *progblock, char
  } else if (strcmp(proto, "tls6") == 0) {
  ipproto = "tcp6";
  } else {
- snprintf(ebuf, sizeof(ebuf), "bad protocol \"%s\"",
+ log_warnx("bad protocol \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  if (strlen(host) >= NI_MAXHOST) {
- snprintf(ebuf, sizeof(ebuf), "host too long \"%s\"",
+ log_warnx("host too long \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  if (port == NULL)
  port = strncmp(proto, "tls", 3) == 0 ?
     "syslog-tls" : "syslog";
  if (strlen(port) >= NI_MAXSERV) {
- snprintf(ebuf, sizeof(ebuf), "port too long \"%s\"",
+ log_warnx("port too long \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  if (priv_getaddrinfo(ipproto, host, port,
     (struct sockaddr*)&f->f_un.f_forw.f_addr,
     sizeof(f->f_un.f_forw.f_addr)) != 0) {
- snprintf(ebuf, sizeof(ebuf), "bad hostname \"%s\"",
+ log_warnx("bad hostname \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerrorx(ebuf);
  break;
  }
  f->f_file = -1;
@@ -2735,10 +2656,8 @@ cfline(char *line, char *progblock, char
  } else if (strncmp(ipproto, "tcp", 3) == 0) {
  if ((f->f_un.f_forw.f_bufev = bufferevent_new(-1,
     tcp_dropcb, tcp_writecb, tcp_errorcb, f)) == NULL) {
- snprintf(ebuf, sizeof(ebuf),
-    "bufferevent \"%s\"",
+ log_warn("bufferevent \"%s\"",
     f->f_un.f_forw.f_loghost);
- logerror(ebuf);
  break;
  }
  if (strncmp(proto, "tls", 3) == 0) {
@@ -2773,13 +2692,17 @@ cfline(char *line, char *progblock, char
  free(f);
  return (NULL);
  }
- if (strcmp(p, ctty) == 0)
+ if (strcmp(p, ctty) == 0) {
  f->f_file = priv_open_tty(p);
- else
+ if (f->f_file < 0)
+ log_warn("priv_open_tty \"%s\"", p);
+ } else {
  f->f_file = priv_open_log(p);
+ if (f->f_file < 0)
+ log_warn("priv_open_log \"%s\"", p);
+ }
  if (f->f_file < 0) {
  f->f_type = F_UNUSED;
- logerror(p);
  break;
  }
  if (isatty(f->f_file)) {
@@ -2815,7 +2738,7 @@ cfline(char *line, char *progblock, char
  if (*p == '\0' || (errno == ERANGE && rb_len == ULONG_MAX) ||
     *q != ':' || rb_len == 0) {
  f->f_type = F_UNUSED;
- logerror(p);
+ log_warnx("strtoul \"%s\"", p);
  break;
  }
  q++;
@@ -2834,7 +2757,7 @@ cfline(char *line, char *progblock, char
  /* Error on missing or non-unique name, or bad buffer length */
  if (i == 0 || rb_len > MAX_MEMBUF || xf != NULL) {
  f->f_type = F_UNUSED;
- logerrorx(p);
+ log_warnx("find_dup \"%s\"", p);
  break;
  }
 
@@ -2968,7 +2891,6 @@ int
 unix_socket(char *path, int type, mode_t mode)
 {
  struct sockaddr_un s_un;
- char ebuf[512];
  int fd, optval;
  mode_t old_umask;
 
@@ -2976,13 +2898,12 @@ unix_socket(char *path, int type, mode_t
  s_un.sun_family = AF_UNIX;
  if (strlcpy(s_un.sun_path, path, sizeof(s_un.sun_path)) >=
     sizeof(s_un.sun_path)) {
- snprintf(ebuf, sizeof(ebuf), "socket path too long: %s", path);
- logerrorx(ebuf);
+ log_warnx("socket path too long \"%s\"", path);
  return (-1);
  }
 
  if ((fd = socket(AF_UNIX, type, 0)) == -1) {
- logerror("socket");
+ log_warn("socket unix \"%s\"", path);
  return (-1);
  }
 
@@ -2991,7 +2912,7 @@ unix_socket(char *path, int type, mode_t
     errno == EPROTOTYPE) {
  close(fd);
  errno = EISCONN;
- logerror("connect");
+ log_warn("connect unix \"%s\"", path);
  return (-1);
  }
  }
@@ -3000,8 +2921,7 @@ unix_socket(char *path, int type, mode_t
 
  unlink(path);
  if (bind(fd, (struct sockaddr *)&s_un, sizeof(s_un)) == -1) {
- snprintf(ebuf, sizeof(ebuf), "cannot bind %s", path);
- logerror(ebuf);
+ log_warn("bind unix \"%s\"", path);
  umask(old_umask);
  close(fd);
  return (-1);
@@ -3010,8 +2930,7 @@ unix_socket(char *path, int type, mode_t
  umask(old_umask);
 
  if (chmod(path, mode) == -1) {
- snprintf(ebuf, sizeof(ebuf), "cannot chmod %s", path);
- logerror(ebuf);
+ log_warn("chmod unix \"%s\"", path);
  close(fd);
  unlink(path);
  return (-1);
@@ -3020,7 +2939,7 @@ unix_socket(char *path, int type, mode_t
  optval = MAXLINE + PATH_MAX;
  if (setsockopt(fd, SOL_SOCKET, SO_RCVBUF, &optval, sizeof(optval))
     == -1)
- logerror("setsockopt unix");
+ log_warn("setsockopt unix \"%s\"", path);
 
  return (fd);
 }
@@ -3033,7 +2952,7 @@ double_sockbuf(int fd, int optname)
 
  len = sizeof(oldsize);
  if (getsockopt(fd, SOL_SOCKET, optname, &oldsize, &len) == -1)
- logerror("getsockopt bufsize");
+ log_warn("getsockopt bufsize");
  len = sizeof(newsize);
  newsize =  MAXLINE + 128;  /* data + control */
  /* allow 8 full length messages */
@@ -3041,7 +2960,7 @@ double_sockbuf(int fd, int optname)
  if (newsize <= oldsize)
  continue;
  if (setsockopt(fd, SOL_SOCKET, optname, &newsize, len) == -1)
- logerror("setsockopt bufsize");
+ log_warn("setsockopt bufsize %d", newsize);
  }
 }
 
@@ -3051,9 +2970,9 @@ set_sockbuf(int fd)
  int size = 65536;
 
  if (setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &size, sizeof(size)) == -1)
- logerror("setsockopt sndbufsize");
+ log_warn("setsockopt sndbufsize %d", size);
  if (setsockopt(fd, SOL_SOCKET, SO_RCVBUF, &size, sizeof(size)) == -1)
- logerror("setsockopt rcvbufsize");
+ log_warn("setsockopt rcvbufsize %d", size);
 }
 
 void
@@ -3085,7 +3004,7 @@ ctlsock_acceptcb(int fd, short event, vo
  if (errno != ENFILE && errno != EMFILE &&
     errno != EINTR && errno != EWOULDBLOCK &&
     errno != ECONNABORTED)
- logerror("accept ctlsock");
+ log_warn("accept control socket");
  return;
  }
  log_debug("Accepting control connection");
@@ -3144,7 +3063,7 @@ ctlconn_readcb(int fd, short event, void
  goto retry;
  if (errno == EWOULDBLOCK)
  return;
- logerror("ctlconn read");
+ log_warn("read control socket");
  /* FALLTHROUGH */
  case 0:
  ctlconn_cleanup();
@@ -3156,14 +3075,14 @@ ctlconn_readcb(int fd, short event, void
  return;
 
  if (ntohl(ctl_cmd.version) != CTL_VERSION) {
- logerrorx("Unknown client protocol version");
+ log_warnx("unknown client protocol version");
  ctlconn_cleanup();
  return;
  }
 
  /* Ensure that logname is \0 terminated */
  if (memchr(ctl_cmd.logname, '\0', sizeof(ctl_cmd.logname)) == NULL) {
- logerrorx("Corrupt ctlsock command");
+ log_warnx("corrupt control socket command");
  ctlconn_cleanup();
  return;
  }
@@ -3231,7 +3150,7 @@ ctlconn_readcb(int fd, short event, void
  strlcat(reply_text, "\n", MAX_MEMBUF);
  break;
  default:
- logerrorx("Unsupported ctlsock command");
+ log_warnx("unsupported control socket command");
  ctlconn_cleanup();
  return;
  }
@@ -3261,7 +3180,7 @@ ctlconn_writecb(int fd, short event, voi
  if (!(ctl_state == CTL_WRITING_REPLY ||
     ctl_state == CTL_WRITING_CONT_REPLY)) {
  /* Shouldn't be here! */
- logerrorx("ctlconn_write with bad ctl_state");
+ log_warnx("control socket write with bad state");
  ctlconn_cleanup();
  return;
  }
@@ -3276,7 +3195,7 @@ ctlconn_writecb(int fd, short event, voi
  if (errno == EWOULDBLOCK)
  return;
  if (errno != EPIPE)
- logerror("ctlconn write");
+ log_warn("write control socket");
  /* FALLTHROUGH */
  case 0:
  ctlconn_cleanup();

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_warn

Todd C. Miller
On Wed, 05 Apr 2017 18:17:38 +0200, Alexander Bluhm wrote:

> Replace logerror() functions with generic log_warn() from log.c.
> Make messages a bit more consistent.  Note that the new function
> supports format strings.  Replace some log_debug() with log_warn().

OK millert@

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_info

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.

The function logmsg() was used to generate local messages and to
process incomming messages.  Split this functionality into log_info()
and logline().  Sort the parameters like they appear in the syslog
line.

ok?

bluhm

Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.237
diff -u -p -r1.237 syslogd.c
--- usr.sbin/syslogd/syslogd.c 5 Apr 2017 19:34:49 -0000 1.237
+++ usr.sbin/syslogd/syslogd.c 5 Apr 2017 20:01:35 -0000
@@ -110,7 +110,7 @@ const char ctty[] = _PATH_CONSOLE;
 
 
 /*
- * Flags to logmsg().
+ * Flags to logline().
  */
 
 #define IGN_CONS 0x001 /* don't print on console */
@@ -321,7 +321,7 @@ void markit(void);
 void fprintlog(struct filed *, int, char *);
 void init(void);
 void logevent(int, const char *);
-void logmsg(int, char *, char *, int);
+void logline(int, int, char *, char *);
 struct filed *find_dup(struct filed *);
 size_t parsepriority(const char *, int *);
 void printline(char *, char *);
@@ -831,7 +831,7 @@ main(int argc, char *argv[])
  to.tv_usec = 0;
  evtimer_add(ev_mark, &to);
 
- logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: start", LocalHostName, ADDDATE);
+ log_info(LOG_INFO, "start");
  log_debug("syslogd: started");
 
  sigemptyset(&sigmask);
@@ -1021,7 +1021,6 @@ reserve_accept4(int lfd, int event, stru
     struct sockaddr *sa, socklen_t *salen, int flags)
 {
  struct timeval to = { 1, 0 };
- char ebuf[ERRBUFSIZE];
  int afd;
 
  if (event & EV_TIMEOUT) {
@@ -1040,9 +1039,7 @@ reserve_accept4(int lfd, int event, stru
  afd = accept4(lfd, sa, salen, flags);
 
  if (afd == -1 && (errno == ENFILE || errno == EMFILE)) {
- snprintf(ebuf, sizeof(ebuf), "syslogd: accept deferred: %s",
-    strerror(errno));
- logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
+ log_info(LOG_WARNING, "accept deferred: %s", strerror(errno));
  /*
  * Disable the listen event and convert it to a timeout.
  * Pass the listen file descriptor to the callback.
@@ -1076,7 +1073,7 @@ acceptcb(int lfd, short event, void *arg
  struct sockaddr_storage ss;
  socklen_t sslen;
  char hostname[NI_MAXHOST], servname[NI_MAXSERV];
- char *peername, ebuf[ERRBUFSIZE];
+ char *peername;
  int fd;
 
  sslen = sizeof(ss);
@@ -1139,9 +1136,8 @@ acceptcb(int lfd, short event, void *arg
  p->p_peername = peername;
  bufferevent_enable(p->p_bufev, EV_READ);
 
- snprintf(ebuf, sizeof(ebuf), "syslogd: %s logger \"%s\" accepted",
+ log_info(LOG_INFO, "%s logger \"%s\" accepted",
     p->p_ctx ? "tls" : "tcp", peername);
- logmsg(LOG_SYSLOG|LOG_INFO, ebuf, LocalHostName, ADDDATE);
 }
 
 /*
@@ -1265,19 +1261,14 @@ void
 tcp_closecb(struct bufferevent *bufev, short event, void *arg)
 {
  struct peer *p = arg;
- char ebuf[ERRBUFSIZE];
 
  if (event & EVBUFFER_EOF) {
- snprintf(ebuf, sizeof(ebuf), "syslogd: %s logger \"%s\" "
-    "connection close", p->p_ctx ? "tls" : "tcp",
-    p->p_peername);
- logmsg(LOG_SYSLOG|LOG_INFO, ebuf, LocalHostName, ADDDATE);
+ log_info(LOG_INFO, "%s logger \"%s\" connection close",
+    p->p_ctx ? "tls" : "tcp", p->p_peername);
  } else {
- snprintf(ebuf, sizeof(ebuf), "syslogd: %s logger \"%s\" "
-    "connection error: %s", p->p_ctx ? "tls" : "tcp",
-    p->p_peername,
+ log_info(LOG_NOTICE, "%s logger \"%s\" connection error: %s",
+    p->p_ctx ? "tls" : "tcp", p->p_peername,
     p->p_ctx ? tls_error(p->p_ctx) : strerror(errno));
- logmsg(LOG_SYSLOG|LOG_NOTICE, ebuf, LocalHostName, ADDDATE);
  }
 
  if (p->p_peername != hostname_unknown)
@@ -1326,7 +1317,6 @@ void
 tcp_writecb(struct bufferevent *bufev, void *arg)
 {
  struct filed *f = arg;
- char ebuf[ERRBUFSIZE];
 
  /*
  * Successful write, connection to server is good, reset wait time.
@@ -1336,13 +1326,11 @@ tcp_writecb(struct bufferevent *bufev, v
 
  if (f->f_un.f_forw.f_dropped > 0 &&
     EVBUFFER_LENGTH(f->f_un.f_forw.f_bufev->output) < MAX_TCPBUF) {
- snprintf(ebuf, sizeof(ebuf),
-    "syslogd: dropped %d message%s to loghost \"%s\"",
+ log_info(LOG_WARNING, "dropped %d message%s to loghost \"%s\"",
     f->f_un.f_forw.f_dropped,
     f->f_un.f_forw.f_dropped == 1 ? "" : "s",
     f->f_un.f_forw.f_loghost);
  f->f_un.f_forw.f_dropped = 0;
- logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
  }
 }
 
@@ -1355,12 +1343,11 @@ tcp_errorcb(struct bufferevent *bufev, s
  char ebuf[ERRBUFSIZE];
 
  if (event & EVBUFFER_EOF)
- snprintf(ebuf, sizeof(ebuf),
-    "syslogd: loghost \"%s\" connection close",
+ snprintf(ebuf, sizeof(ebuf), "loghost \"%s\" connection close",
     f->f_un.f_forw.f_loghost);
  else
  snprintf(ebuf, sizeof(ebuf),
-    "syslogd: loghost \"%s\" connection error: %s",
+    "loghost \"%s\" connection error: %s",
     f->f_un.f_forw.f_loghost, f->f_un.f_forw.f_ctx ?
     tls_error(f->f_un.f_forw.f_ctx) : strerror(errno));
  log_debug("%s", ebuf);
@@ -1400,7 +1387,7 @@ tcp_errorcb(struct bufferevent *bufev, s
  tcp_connect_retry(bufev, f);
 
  /* Log the connection error to the fresh buffer after reconnecting. */
- logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
+ log_info(LOG_WARNING, "%s", ebuf);
 }
 
 void
@@ -1572,7 +1559,7 @@ printline(char *hname, char *msg)
  }
  line[MAXLINE] = *q = '\0';
 
- logmsg(pri, line, hname, 0);
+ logline(pri, 0, hname, line);
 }
 
 /*
@@ -1603,7 +1590,7 @@ printsys(char *msg)
  while (*p && (c = *p++) != '\n' && q < &line[sizeof(line) - 4])
  q = vis(q, c, 0, 0);
 
- logmsg(pri, line, LocalHostName, flags);
+ logline(pri, flags, LocalHostName, line);
  }
 }
 
@@ -1616,7 +1603,7 @@ vlogmsg(int pri, const char *proc, const
  l = snprintf(msg, sizeof(msg), "%s[%d]: ", proc, getpid());
  if (l < sizeof(msg))
  vsnprintf(msg + l, sizeof(msg) - l, fmt, ap);
- logmsg(pri, msg, LocalHostName, ADDDATE);
+ logline(pri, ADDDATE, LocalHostName, msg);
 }
 
 struct timeval now;
@@ -1626,14 +1613,14 @@ struct timeval now;
  * the priority.
  */
 void
-logmsg(int pri, char *msg, char *from, int flags)
+logline(int pri, int flags, char *from, char *msg)
 {
  struct filed *f;
  int fac, msglen, prilev, i;
  char timestamp[33];
  char prog[NAME_MAX+1];
 
- log_debug("logmsg: pri 0%o, flags 0x%x, from %s, msg %s",
+ log_debug("logline: pri 0%o, flags 0x%x, from %s, msg %s",
     pri, flags, from, msg);
 
  /*
@@ -2162,20 +2149,15 @@ mark_timercb(int unused, short event, vo
 void
 init_signalcb(int signum, short event, void *arg)
 {
- char ebuf[ERRBUFSIZE];
-
  init();
 
- logmsg(LOG_SYSLOG|LOG_INFO, "syslogd: restart",
-    LocalHostName, ADDDATE);
+ log_info(LOG_INFO, "restart");
  log_debug("syslogd: restarted");
 
  if (tcpbuf_dropped > 0) {
- snprintf(ebuf, sizeof(ebuf),
-    "syslogd: dropped %d message%s to remote loghost",
+ log_info(LOG_WARNING, "dropped %d message%s to remote loghost",
     tcpbuf_dropped, tcpbuf_dropped == 1 ? "" : "s");
  tcpbuf_dropped = 0;
- logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
  }
 }
 
@@ -2190,7 +2172,6 @@ die(int signo)
 {
  struct filed *f;
  int was_initialized = Initialized;
- char ebuf[ERRBUFSIZE];
 
  Initialized = 0; /* Don't log SIGCHLDs */
  SIMPLEQ_FOREACH(f, &Files, f_next) {
@@ -2206,11 +2187,9 @@ die(int signo)
  Initialized = was_initialized;
 
  if (tcpbuf_dropped > 0) {
- snprintf(ebuf, sizeof(ebuf),
-    "syslogd: dropped %d message%s to remote loghost",
+ log_info(LOG_WARNING, "dropped %d message%s to remote loghost",
     tcpbuf_dropped, tcpbuf_dropped == 1 ? "" : "s");
  tcpbuf_dropped = 0;
- logmsg(LOG_SYSLOG|LOG_WARNING, ebuf, LocalHostName, ADDDATE);
  }
 
  if (signo)
@@ -2871,8 +2850,7 @@ markit(void)
  (void)gettimeofday(&now, NULL);
  MarkSeq += TIMERINTVL;
  if (MarkSeq >= MarkInterval) {
- logmsg(LOG_INFO, "-- MARK --",
-    LocalHostName, ADDDATE|MARK);
+ logline(LOG_INFO, ADDDATE|MARK, LocalHostName, "-- MARK --");
  MarkSeq = 0;
  }
 

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_info

Todd C. Miller
On Wed, 05 Apr 2017 22:23:58 +0200, Alexander Bluhm wrote:

> The function logmsg() was used to generate local messages and to
> process incomming messages.  Split this functionality into log_info()
> and logline().  Sort the parameters like they appear in the syslog
> line.

Shouldn't vlogmsg() be renamed to vlogline() too?

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_info

Alexander Bluhm
On Wed, Apr 05, 2017 at 02:29:46PM -0600, Todd C. Miller wrote:
> On Wed, 05 Apr 2017 22:23:58 +0200, Alexander Bluhm wrote:
>
> > The function logmsg() was used to generate local messages and to
> > process incomming messages.  Split this functionality into log_info()
> > and logline().  Sort the parameters like they appear in the syslog
> > line.
>
> Shouldn't vlogmsg() be renamed to vlogline() too?

My idea was that vlogmsg() takes a locally generated log message
and converts it to a line, that can be processed by logline().

bluhm

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log_info

Todd C. Miller
On Wed, 05 Apr 2017 22:36:36 +0200, Alexander Bluhm wrote:

> On Wed, Apr 05, 2017 at 02:29:46PM -0600, Todd C. Miller wrote:
> > On Wed, 05 Apr 2017 22:23:58 +0200, Alexander Bluhm wrote:
> >
> > > The function logmsg() was used to generate local messages and to
> > > process incomming messages.  Split this functionality into log_info()
> > > and logline().  Sort the parameters like they appear in the syslog
> > > line.
> >
> > Shouldn't vlogmsg() be renamed to vlogline() too?
>
> My idea was that vlogmsg() takes a locally generated log message
> and converts it to a line, that can be processed by logline().

I think vlogmsg() could probably just be inlined in vlog() (its
only caller) but that can be done later, if at all.

OK millert@ for the current diff.

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log ttymsg

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.

As we did not have nice log functions before, ttymsg() had to return
the error string.  Log the message where the error happens and make
the function void.

ok?

bluhm

Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.238
diff -u -p -r1.238 syslogd.c
--- usr.sbin/syslogd/syslogd.c 5 Apr 2017 21:30:04 -0000 1.238
+++ usr.sbin/syslogd/syslogd.c 5 Apr 2017 21:41:31 -0000
@@ -2068,7 +2068,7 @@ void
 wallmsg(struct filed *f, struct iovec *iov)
 {
  struct utmp ut;
- char utline[sizeof(ut.ut_line) + 1], *p;
+ char utline[sizeof(ut.ut_line) + 1];
  static int reenter; /* avoid calling ourselves */
  FILE *uf;
  int i;
@@ -2087,8 +2087,7 @@ wallmsg(struct filed *f, struct iovec *i
  strncpy(utline, ut.ut_line, sizeof(utline) - 1);
  utline[sizeof(utline) - 1] = '\0';
  if (f->f_type == F_WALL) {
- if ((p = ttymsg(iov, 6, utline)) != NULL)
- log_warnx("%s", p);
+ ttymsg(iov, 6, utline);
  continue;
  }
  /* should we send the message to this user? */
@@ -2097,8 +2096,7 @@ wallmsg(struct filed *f, struct iovec *i
  break;
  if (!strncmp(f->f_un.f_uname[i], ut.ut_name,
     UT_NAMESIZE)) {
- if ((p = ttymsg(iov, 6, utline)) != NULL)
- log_warnx("%s", p);
+ ttymsg(iov, 6, utline);
  break;
  }
  }
Index: usr.sbin/syslogd/syslogd.h
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.h,v
retrieving revision 1.28
diff -u -p -r1.28 syslogd.h
--- usr.sbin/syslogd/syslogd.h 5 Apr 2017 11:31:45 -0000 1.28
+++ usr.sbin/syslogd/syslogd.h 5 Apr 2017 21:41:31 -0000
@@ -37,7 +37,7 @@ int   priv_getnameinfo(struct sockaddr *
 /* Terminal message */
 #define TTYMSGTIME 1 /* timeout used by ttymsg */
 #define TTYMAXDELAY 256 /* max events in ttymsg */
-char *ttymsg(struct iovec *, int, char *);
+void ttymsg(struct iovec *, int, char *);
 
 /* File descriptor send/recv */
 void send_fd(int, int);
Index: usr.sbin/syslogd/ttymsg.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/ttymsg.c,v
retrieving revision 1.14
diff -u -p -r1.14 ttymsg.c
--- usr.sbin/syslogd/ttymsg.c 5 Apr 2017 11:31:45 -0000 1.14
+++ usr.sbin/syslogd/ttymsg.c 5 Apr 2017 21:41:31 -0000
@@ -60,37 +60,35 @@ void ttycb(int, short, void *);
 /*
  * Display the contents of a uio structure on a terminal.
  * Schedules an event if write would block, waiting up to TTYMSGTIME
- * seconds.  Returns pointer to error string on unexpected error;
- * string is not newline-terminated.  Various "normal" errors are ignored
- * (exclusive-use, lack of permission, etc.).
+ * seconds.
  */
-char *
+void
 ttymsg(struct iovec *iov, int iovcnt, char *utline)
 {
  static char device[MAXNAMLEN] = _PATH_DEV;
- static char ebuf[ERRBUFSIZE];
  int cnt, fd;
  size_t left;
  ssize_t wret;
  struct iovec localiov[6];
 
- if (iovcnt < 0 || (size_t)iovcnt > nitems(localiov))
- return ("too many iov's (change code in syslogd/ttymsg.c)");
+ if (iovcnt < 0 || (size_t)iovcnt > nitems(localiov)) {
+ log_warnx("too many iov's (change code in syslogd/ttymsg.c)");
+ return;
+ }
 
  /*
  * Ignore lines that start with "ftp" or "uucp".
  */
  if ((strncmp(utline, "ftp", 3) == 0) ||
     (strncmp(utline, "uucp", 4) == 0))
- return (NULL);
+ return;
 
  (void) strlcpy(device + sizeof(_PATH_DEV) - 1, utline,
     sizeof(device) - (sizeof(_PATH_DEV) - 1));
  if (strchr(device + sizeof(_PATH_DEV) - 1, '/')) {
  /* A slash is an attempt to break security... */
- (void) snprintf(ebuf, sizeof(ebuf), "'/' in \"%s\"",
-    device);
- return (ebuf);
+ log_warnx("'/' in tty device \"%s\"", device);
+ return;
  }
 
  /*
@@ -98,11 +96,9 @@ ttymsg(struct iovec *iov, int iovcnt, ch
  * if not running as root; not an error.
  */
  if ((fd = priv_open_tty(device)) < 0) {
- if (errno == EBUSY || errno == EACCES)
- return (NULL);
- (void) snprintf(ebuf, sizeof(ebuf),
-    "%s: %s", device, strerror(errno));
- return (ebuf);
+ if (errno != EBUSY && errno != EACCES)
+ log_warn("priv_open_tty device \"%s\"", device);
+ return;
  }
 
  left = 0;
@@ -136,9 +132,9 @@ ttymsg(struct iovec *iov, int iovcnt, ch
  struct timeval to;
 
  if (tty_delayed >= TTYMAXDELAY) {
- (void) snprintf(ebuf, sizeof(ebuf),
-    "%s: too many delayed writes", device);
- goto error;
+ log_warnx("tty device \"%s\": %s",
+    device, "too many delayed writes");
+ break;
  }
  log_debug("ttymsg delayed write");
  if (iov != localiov) {
@@ -147,9 +143,9 @@ ttymsg(struct iovec *iov, int iovcnt, ch
  iov = localiov;
  }
  if ((td = malloc(sizeof(*td))) == NULL) {
- (void) snprintf(ebuf, sizeof(ebuf),
-    "%s: malloc: %s", device, strerror(errno));
- goto error;
+ log_warn("allocate delay tty device \"%s\"",
+    device);
+ break;
  }
  td->td_length = 0;
  if (left > MAXLINE)
@@ -169,23 +165,19 @@ ttymsg(struct iovec *iov, int iovcnt, ch
  to.tv_sec = TTYMSGTIME;
  to.tv_usec = 0;
  event_add(&td->td_event, &to);
- return (NULL);
+ return;
  }
  /*
  * We get ENODEV on a slip line if we're running as root,
  * and EIO if the line just went away.
  */
- if (errno == ENODEV || errno == EIO)
- break;
- (void) snprintf(ebuf, sizeof(ebuf),
-    "%s: %s", device, strerror(errno));
- error:
- (void) close(fd);
- return (ebuf);
+ if (errno != ENODEV && errno != EIO)
+ log_warn("writev tty device \"%s\"", device);
+ break;
  }
 
  (void) close(fd);
- return (NULL);
+ return;
 }
 
 void

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log ttymsg

Todd C. Miller
On Wed, 05 Apr 2017 23:46:45 +0200, Alexander Bluhm wrote:

> On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> > This is the next step for refactoring internal syslogd(8) logging.
>
> As we did not have nice log functions before, ttymsg() had to return
> the error string.  Log the message where the error happens and make
> the function void.

OK millert@

 - todd

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log startup

Alexander Bluhm
In reply to this post by Alexander Bluhm
On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> This is the next step for refactoring internal syslogd(8) logging.

Here is my final diff for now, thanks for all the reviews.

The variable Startup is not used anymore and can be deleted.  The
functionality has moved into log_setdebug().

ok?

bluhm

Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.239
diff -u -p -r1.239 syslogd.c
--- usr.sbin/syslogd/syslogd.c 5 Apr 2017 21:55:31 -0000 1.239
+++ usr.sbin/syslogd/syslogd.c 5 Apr 2017 21:59:46 -0000
@@ -202,7 +202,6 @@ int nunix; /* Number of Unix domain so
 char **path_unix; /* Paths to Unix domain sockets */
 int Debug; /* debug flag */
 int Foreground; /* run in foreground, instead of daemonizing */
-int Startup = 1; /* startup flag */
 char LocalHostName[HOST_NAME_MAX+1]; /* our hostname */
 char *LocalDomain; /* our local domain name */
 int Initialized = 0; /* set when we have initialized ourselves */
@@ -768,7 +767,6 @@ main(int argc, char *argv[])
  init();
 
  log_setdebug(0);
- Startup = 0;
 
  /* Allocate ctl socket reply buffer if we have a ctl socket */
  if (fd_ctlsock != -1 &&
Index: usr.sbin/syslogd/syslogd.h
===================================================================
RCS file: /cvs/src/usr.sbin/syslogd/syslogd.h,v
retrieving revision 1.29
diff -u -p -r1.29 syslogd.h
--- usr.sbin/syslogd/syslogd.h 5 Apr 2017 21:55:31 -0000 1.29
+++ usr.sbin/syslogd/syslogd.h 5 Apr 2017 21:59:46 -0000
@@ -53,7 +53,6 @@ extern char *path_ctlsock;
 void vlogmsg(int pri, const char *, const char *, va_list);
 __dead void die(int);
 extern int Debug;
-extern int Startup;
 
 struct ringbuf {
  char *buf;

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: syslogd log startup

Todd C. Miller
On Thu, 06 Apr 2017 00:03:34 +0200, Alexander Bluhm wrote:

> On Fri, Mar 17, 2017 at 02:09:35AM +0100, Alexander Bluhm wrote:
> > This is the next step for refactoring internal syslogd(8) logging.
>
> Here is my final diff for now, thanks for all the reviews.
>
> The variable Startup is not used anymore and can be deleted.  The
> functionality has moved into log_setdebug().

Sure, OK millert@

 - todd

Loading...