Logging: Cleanup of log.c

   o  log_progname[] moved to log_init()
   o  Both vmsg() and log_pass_msg() now allocate the buffer on the stack
      if the message is smaller than 256 bytes.
   o  log_pid is used instead of repeated calls to getpid()
   o  sizeof(array) always preferred over repeated constants
   o  Many coding style cleanups to make the old and new code fit together.
   o  Namespace cleanups
   o  Updated comments

diff --git a/ucw/log.c b/ucw/log.c
index 44be63023fe36da9964725f0e14bec6d737cd711..8c53d0f5e039215dce05cc869087098fbcc82e1a 100644 (file)
--- a/ucw/log.c
+++ b/ucw/log.c
@@ -21,61 +21,54 @@
 #include <alloca.h>
 #include <errno.h>
 
-static char log_progname[32];
 char *log_title;
 int log_pid;
 void (*log_die_hook)(void);
 
-// FIXME: duplicate?
-static int ls_default_handler(struct log_stream* ls, const char *m, u32 cat UNUSED)
+/*** The default log stream, which logs to stderr ***/
+
+static int default_log_handler(struct log_stream *ls, const char *m, uns cat UNUSED)
 {
-  int len = strlen(m);
-  int r = write(ls->idata, m, len);
-  /* TODO: check the errors here? */
-  if (r!=len)
-    return errno;
+  // This is a completely bare version of the log-file module. Errors are ignored.
+  write(ls->idata, m, strlen(m));
   return 0;
 }
 
-/* the default logger */
-const struct log_stream ls_default_log={
-  .name = "fd2", .idata = 2, .pdata = NULL, .regnum = 0,
-  .handler = ls_default_handler,
+const struct log_stream log_stream_default = {
+  .name = "stderr",
+  .idata = 2,
+  .handler = default_log_handler,
   .levels = LS_ALL_LEVELS,
   .msgfmt = LSFMT_DEFAULT,
-  // empty clist
-  .substreams.head.next = (cnode *) &ls_default_log.substreams.head,
-  .substreams.head.prev = (cnode *) &ls_default_log.substreams.head,
+  // an empty clist
+  .substreams.head.next = (cnode *) &log_stream_default.substreams.head,
+  .substreams.head.prev = (cnode *) &log_stream_default.substreams.head,
 };
 
 /*** Registry of streams and their identifiers ***/
 
-/* The growing array of pointers to log_streams. */
-struct lsbuf_t log_streams;
+struct lsbuf_t log_streams;            /* A growing array of pointers to log_streams */
+int log_streams_after = 0;             /* The first never-used index in log_streams.ptr */
 
-/* the first never-used index in ls_streams.ptr */
-int log_streams_after = 0;
+/*
+ *  Find a stream by its identifier given as LS_SET_STRNUM(flags).
+ *  Returns NULL if the stream doesn't exist or it's invalid.
+ *  When stream #0 is requested, fall back to log_stream_default.
+ */
 
-/* get a stream by its LS_SET_STRNUM() */
-/* returns NULL for free/invalid numbers */
-/* defaults to ls_default_stream when stream number 0 closed */
-struct log_stream *log_stream_by_flags(uns flags)
+struct log_stream *
+log_stream_by_flags(uns flags)
 {
-  /* get the real number */
   int n = LS_GET_STRNUM(flags);
-  if ((n<0) || (n>=log_streams_after) || (log_streams.ptr[n]->regnum==-1) )
-  {
-    if (n==0)
-      return (struct log_stream *)&ls_default_log;
-    else
-      return NULL;
-  }
+  if (n < 0 || n >= log_streams_after || log_streams.ptr[n]->regnum == -1)
+    return (n ? NULL : (struct log_stream *) &log_stream_default);
   return log_streams.ptr[n];
 }
 
 /*** Logging ***/
 
-void vmsg(unsigned int cat, const char *fmt, va_list args)
+void
+vmsg(uns cat, const char *fmt, va_list args)
 {
   struct timeval tv;
   int have_tm = 0;
@@ -83,20 +76,20 @@ void vmsg(unsigned int cat, const char *fmt, va_list args)
   va_list args2;
   char stime[24];
   char sutime[12];
-  char *buf,*p;
+  char msgbuf[256];
+  char *m, *p;
   int len;
-  struct log_stream *ls=log_stream_by_flags(cat);
+  struct log_stream *ls = log_stream_by_flags(cat);
 
   /* Check the stream existence */
-  if(!ls)
+  if (!ls)
     {
-      msg((LS_INTERNAL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.",
-       LS_GET_STRNUM(cat));
-      ls=(struct log_stream *)&ls_default_log;
+      msg((LS_INTERNAL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.", LS_GET_STRNUM(cat));
+      ls = (struct log_stream *) &log_stream_default;
     }
 
-  /* get the time */
-  if (!(cat&LSFLAG_SIGHANDLER))
+  /* Get the current time */
+  if (!(cat & LSFLAG_SIGHANDLER))
     {
       /* CAVEAT: These calls are not safe in signal handlers. */
       gettimeofday(&tv, NULL);
@@ -104,28 +97,32 @@ void vmsg(unsigned int cat, const char *fmt, va_list args)
        have_tm = 1;
     }
 
-  /* generate time strings */
+  /* Generate time strings */
   if (have_tm)
     {
-      strftime(stime, 24, "%Y-%m-%d %H:%M:%S", &tm);
-      snprintf(sutime, 12, ".%06d", (int)tv.tv_usec);
+      strftime(stime, sizeof(stime), "%Y-%m-%d %H:%M:%S", &tm);
+      snprintf(sutime, sizeof(sutime), ".%06d", (int)tv.tv_usec);
     }
   else
     {
-      snprintf(stime, 24, "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?");
-      snprintf(sutime, 12, ".\?\?\?\?\?\?");
+      snprintf(stime, sizeof(stime), "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?");
+      snprintf(sutime, sizeof(sutime), ".\?\?\?\?\?\?");
     }
 
-  /* generate the message string */
+  /* Generate the message string */
   va_copy(args2, args);
-  /* WARN: this may be C99 specefic */
-  len = vsnprintf(NULL, 0, fmt, args2);
+  len = vsnprintf(msgbuf, sizeof(msgbuf), fmt, args2);
   va_end(args2);
-  buf = xmalloc(len+2);
-  vsnprintf(buf, len+1, fmt, args);
+  if (len < (int) sizeof(msgbuf))
+    m = msgbuf;
+  else
+    {
+      m = xmalloc(len+1);
+      vsnprintf(m, len+1, fmt, args);
+    }
 
-  /* remove non-printable characters and newlines */
-  p=buf;
+  /* Remove non-printable characters and newlines */
+  p = m;
   while (*p)
     {
       if (*p < 0x20 && *p != '\t')
@@ -133,115 +130,123 @@ void vmsg(unsigned int cat, const char *fmt, va_list args)
       p++;
     }
 
-  /* pass the message to the log_stream */
-  if(ls_passmsg(0, ls, stime, sutime, buf, cat))
+  /* Pass the message to the log_stream */
+  if (log_pass_msg(0, ls, stime, sutime, m, cat))
     {
-      /* error (such as looping) occured */
-      ls_passmsg(0, (struct log_stream *)&ls_default_log, stime, sutime, buf, cat);
+      /* Error (such as infinite loop) occurred */
+      log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime, m, cat);
     }
 
-  xfree(buf);
+  if (m != msgbuf)
+    xfree(m);
 }
 
-/* process a message (string) */
-/* depth prevents undetected looping */
-/* returns 1 in case of loop detection or other fatal error
- *         0 otherwise */
-int ls_passmsg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, u32 cat)
+int
+log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, uns cat)
 {
   ASSERT(ls);
 
   /* Check recursion depth */
-  if( depth > LS_MAX_DEPTH )
+  if (depth > LS_MAX_DEPTH)
     {
-      ls_passmsg(0, (struct log_stream *)&ls_default_log, stime, sutime,
-       "Loop in the log_stream system detected.", L_ERROR | (cat&LS_INTERNAL_MASK) );
+      log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime,
+       "Loop in the log_stream system detected.", L_ERROR | (cat & LS_INTERNAL_MASK));
       return 1;
     }
 
-  /* Filter by level and filter hook */
-  if(!( (1<<LS_GET_LEVEL(cat)) & ls->levels )) return 0;
-  if( ls->filter )
-    if( ls->filter(ls, m, cat) != 0 ) return 0;
+  /* Filter by level and hook function */
+  if (!((1 << LS_GET_LEVEL(cat)) & ls->levels))
+    return 0;
+  if (ls->filter && ls->filter(ls, m, cat))
+    return 0;
 
-  /* pass message to substreams */
+  /* Pass the message to substreams */
   CLIST_FOR_EACH(simp_node *, s, ls->substreams)
+    if (log_pass_msg(depth+1, s->p, stime, sutime, m, cat))
+      return 1;
+
+  /* Will pass to the handler of this stream... is there any? */
+  if (!ls->handler)
+    return 0;
+
+  /* Upper bound on message length */
+  int len = strlen(m) + strlen(stime) + strlen(sutime) + 32;
+  if (log_title)
+    len += strlen(log_title);
+  if (ls->name)
+    len += strlen(ls->name);
+
+  /* Get a buffer and format the message */
+  char *free_buf = NULL;
+  char *buf;
+  if (len <= 256)
+    buf = alloca(len);
+  else
+    buf = free_buf = xmalloc(len);
+  char *p = buf;
+
+  /* Level (2 chars) */
+  if (ls->msgfmt & LSFMT_LEVEL)
     {
-      if (ls_passmsg(depth+1, (struct log_stream*)(s->p), stime, sutime, m, cat))
-       return 1;
+      *p++ = LS_LEVEL_LETTER(LS_GET_LEVEL(cat));
+      *p++ = ' ';
     }
 
-  /* Prepare for handler */
-  if(ls->handler)
+  /* Time (|stime| + |sutime| + 1 chars) */
+  if (ls->msgfmt & LSFMT_TIME)
     {
-      int len = strlen(m) + strlen(stime) + strlen(sutime) + 32;
-      /* SHOULD be enough for all information, but beware */
-      if (log_title)  len += strlen(log_title);
-      if (ls->name)  len += strlen(ls->name);
-      char *buf=xmalloc(len);
-      char *p=buf;
-
-      /* Level (2 chars) */
-      if(ls->msgfmt & LSFMT_LEVEL)
-       {
-         *p++=LS_LEVEL_LETTER(LS_GET_LEVEL(cat));
-         *p++=' ';
-       }
-
-      /* Time (|stime| + |sutime| + 1 chars) */
-      if(ls->msgfmt & LSFMT_TIME)
+      const char *q = (char *)stime;
+      while (*q)
+       *p++ = *q++;
+      if (ls->msgfmt & LSFMT_USEC)
        {
-         char *q = (char *)stime;
-
-         while(*q)
-           *p++=*q++;
-         if(ls->msgfmt & LSFMT_USEC)
-           {
-             q = (char *)sutime;
-             while(*q)
-               *p++=*q++;
-           }
-         *p++=' ';
+         q = sutime;
+         while (*q)
+           *p++ = *q++;
        }
+      *p++ = ' ';
+    }
 
-      /* process name, PID ( |log_title| + 6 + (|PID|<=10) chars ) */
-      if((ls->msgfmt & LSFMT_TITLE) && log_title)
-       {
-         if(ls->msgfmt & LSFMT_PID)
-           p += sprintf(p, "[%s (%d)] ", log_title, getpid());
-         else
-           p += sprintf(p, "[%s] ", log_title);
-       }
+  /* Process name, PID ( |log_title| + 6 + (|PID|<=10) chars ) */
+  if ((ls->msgfmt & LSFMT_TITLE) && log_title)
+    {
+      if (ls->msgfmt & LSFMT_PID)
+       p += sprintf(p, "[%s (%d)] ", log_title, log_pid);
       else
-       {
-         if(ls->msgfmt & LSFMT_PID)
-           p += sprintf(p, "[%d] ", getpid());
-       }
-
-      /* log_stream name ( |ls->name| + 4 chars ) */
-      if(ls->msgfmt & LSFMT_LOGNAME)
-       {
-         if(ls->name)
-           p += sprintf(p, "<%s> ", ls->name);
-         else
-           p += sprintf(p, "<?> ");
-       }
+       p += sprintf(p, "[%s] ", log_title);
+    }
+  else
+    {
+      if (ls->msgfmt & LSFMT_PID)
+       p += sprintf(p, "[%d] ", log_pid);
+    }
 
-      /* finish the string and call the handler ( |m| + 1 chars ) */
-       {
-         char *q = (char *)m;
+  /* log_stream name ( |ls->name| + 4 chars ) */
+  if (ls->msgfmt & LSFMT_LOGNAME)
+    {
+      if (ls->name)
+       p += sprintf(p, "<%s> ", ls->name);
+      else
+       p += sprintf(p, "<?> ");
+    }
 
-         while(*q)
-           *p++=*q++;
-         *p++ = '\n';
-         *p++ = '\0';
-         ls->handler(ls, buf, cat);
-       }
-      xfree(buf);
+  /* The message itself ( |m| + 1 chars ) */
+    {
+      const char *q = m;
+      while (*q)
+       *p++ = *q++;
+      *p++ = '\n';
+      *p++ = '\0';
+      ls->handler(ls, buf, cat);
     }
+
+  if (free_buf)
+    xfree(free_buf);
   return 0;
 }
 
+/*** Utility functions ***/
+
 void
 msg(unsigned int cat, const char *fmt, ...)
 {
@@ -298,6 +303,7 @@ log_init(const char *argv0)
 {
   if (argv0)
     {
+      static char log_progname[32];
       strncpy(log_progname, log_basename(argv0), sizeof(log_progname)-1);
       log_progname[sizeof(log_progname)-1] = 0;
       log_title = log_progname;
@@ -308,8 +314,7 @@ log_init(const char *argv0)
 
 int main(void)
 {
-  // ls_default_log.msgfmt |= LSFMT_USEC;
-  msg(L_INFO, "Brum!");
+  msg(L_INFO, "Brum <%300s>", ":-)");
   return 0;
 }
 

diff --git a/ucw/log.h b/ucw/log.h
index b336f2e79aa5200308136cc8c39cc479229f32ab..bcd9ebc976855ec31ef909c51460bfa53ddf3612 100644 (file)
--- a/ucw/log.h
+++ b/ucw/log.h
@@ -159,7 +159,7 @@ void ls_die(const char *fmt, ...);
 /* depth prevents undetected looping */
 /* returns 1 in case of loop detection or other fatal error
  *         0 otherwise */
-int ls_passmsg(int depth, struct log_stream *ls, const char *stime, const char *sutime,
+int log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime,
     const char *msg, uns cat);
 
 /* Maximal depth of ls_passmsg recursion */