Quantcast

syslogd log_debug

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
2 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

Loading...