ucw/log.c

   1 /*
   2  *      UCW Library -- Logging
   3  *
   4  *      (c) 1997--2009 Martin Mares <mj@ucw.cz>
   5  *      (c) 2008 Tomas Gavenciak <gavento@ucw.cz>
   6  *
   7  *      This software may be freely distributed and used according to the terms
   8  *      of the GNU Lesser General Public License.
   9  */
  10
  11 #include "ucw/lib.h"
  12 #include "ucw/log.h"
  13 #include "ucw/simple-lists.h"
  14
  15 #include <stdio.h>
  16 #include <stdlib.h>
  17 #include <string.h>
  18 #include <unistd.h>
  19 #include <sys/time.h>
  20 #include <time.h>
  21 #include <alloca.h>
  22 #include <errno.h>
  23
  24 char *log_title;
  25 int log_pid;
  26 void (*log_die_hook)(void);
  27
  28 /*** The default log stream, which logs to stderr ***/
  29
  30 static int default_log_handler(struct log_stream *ls, const char *m, uns cat UNUSED)
  31 {
  32   // This is a completely bare version of the log-file module. Errors are ignored.
  33   write(ls->idata, m, strlen(m));
  34   return 0;
  35 }
  36
  37 const struct log_stream log_stream_default = {
  38   .name = "stderr",
  39   .idata = 2,
  40   .handler = default_log_handler,
  41   .levels = LS_ALL_LEVELS,
  42   .msgfmt = LSFMT_DEFAULT,
  43   // an empty clist
  44   .substreams.head.next = (cnode *) &log_stream_default.substreams.head,
  45   .substreams.head.prev = (cnode *) &log_stream_default.substreams.head,
  46 };
  47
  48 /*** Registry of streams and their identifiers ***/
  49
  50 struct lsbuf_t log_streams;             /* A growing array of pointers to log_streams */
  51 int log_streams_after = 0;              /* The first never-used index in log_streams.ptr */
  52
  53 /*
  54  *  Find a stream by its identifier given as LS_SET_STRNUM(flags).
  55  *  Returns NULL if the stream doesn't exist or it's invalid.
  56  *
  57  *  If the log-stream machinery has not been initialized (which is normal for programs
  58  *  with no fancy logging), the log_streams gbuf is empty and this function only
  59  *  translates stream #0 to the static log_stream_default.
  60  */
  61
  62 struct log_stream *
  63 log_stream_by_flags(uns flags)
  64 {
  65   int n = LS_GET_STRNUM(flags);
  66   if (n < 0 || n >= log_streams_after || log_streams.ptr[n]->regnum == -1)
  67     return (n ? NULL : (struct log_stream *) &log_stream_default);
  68   return log_streams.ptr[n];
  69 }
  70
  71 /*** Logging ***/
  72
  73 void
  74 vmsg(uns cat, const char *fmt, va_list args)
  75 {
  76   struct timeval tv;
  77   int have_tm = 0;
  78   struct tm tm;
  79   va_list args2;
  80   char stime[24];
  81   char sutime[12];
  82   char msgbuf[256];
  83   char *m, *p;
  84   int len;
  85   struct log_stream *ls = log_stream_by_flags(cat);
  86
  87   /* Check the stream existence */
  88   if (!ls)
  89     {
  90       msg((LS_INTERNAL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.", LS_GET_STRNUM(cat));
  91       ls = (struct log_stream *) &log_stream_default;
  92     }
  93
  94   /* Get the current time */
  95   if (!(cat & LSFLAG_SIGHANDLER))
  96     {
  97       /* CAVEAT: These calls are not safe in signal handlers. */
  98       gettimeofday(&tv, NULL);
  99       if (localtime_r(&tv.tv_sec, &tm))
 100         have_tm = 1;
 101     }
 102
 103   /* Generate time strings */
 104   if (have_tm)
 105     {
 106       strftime(stime, sizeof(stime), "%Y-%m-%d %H:%M:%S", &tm);
 107       snprintf(sutime, sizeof(sutime), ".%06d", (int)tv.tv_usec);
 108     }
 109   else
 110     {
 111       snprintf(stime, sizeof(stime), "\?\?\?\?-\?\?-\?\? \?\?:\?\?:\?\?");
 112       snprintf(sutime, sizeof(sutime), ".\?\?\?\?\?\?");
 113     }
 114
 115   /* Generate the message string */
 116   va_copy(args2, args);
 117   len = vsnprintf(msgbuf, sizeof(msgbuf), fmt, args2);
 118   va_end(args2);
 119   if (len < (int) sizeof(msgbuf))
 120     m = msgbuf;
 121   else
 122     {
 123       m = xmalloc(len+1);
 124       vsnprintf(m, len+1, fmt, args);
 125     }
 126
 127   /* Remove non-printable characters and newlines */
 128   p = m;
 129   while (*p)
 130     {
 131       if (*p < 0x20 && *p != '\t')
 132         *p = 0x7f;
 133       p++;
 134     }
 135
 136   /* Pass the message to the log_stream */
 137   if (log_pass_msg(0, ls, stime, sutime, m, cat))
 138     {
 139       /* Error (such as infinite loop) occurred */
 140       log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime, m, cat);
 141     }
 142
 143   if (m != msgbuf)
 144     xfree(m);
 145 }
 146
 147 /* Maximal depth of log_pass_msg recursion */
 148 #define LS_MAX_DEPTH 64
 149
 150 int
 151 log_pass_msg(int depth, struct log_stream *ls, const char *stime, const char *sutime, const char *m, uns cat)
 152 {
 153   ASSERT(ls);
 154
 155   /* Check recursion depth */
 156   if (depth > LS_MAX_DEPTH)
 157     {
 158       log_pass_msg(0, (struct log_stream *) &log_stream_default, stime, sutime,
 159         "Loop in the log_stream system detected.", L_ERROR | (cat & LS_INTERNAL_MASK));
 160       return 1;
 161     }
 162
 163   /* Filter by level and hook function */
 164   if (!((1 << LS_GET_LEVEL(cat)) & ls->levels))
 165     return 0;
 166   if (ls->filter && ls->filter(ls, m, cat))
 167     return 0;
 168
 169   /* Pass the message to substreams */
 170   CLIST_FOR_EACH(simp_node *, s, ls->substreams)
 171     if (log_pass_msg(depth+1, s->p, stime, sutime, m, cat))
 172       return 1;
 173
 174   /* Will pass to the handler of this stream... is there any? */
 175   if (!ls->handler)
 176     return 0;
 177
 178   /* Upper bound on message length */
 179   int len = strlen(m) + strlen(stime) + strlen(sutime) + 32;
 180   if (log_title)
 181     len += strlen(log_title);
 182   if (ls->name)
 183     len += strlen(ls->name);
 184
 185   /* Get a buffer and format the message */
 186   char *free_buf = NULL;
 187   char *buf;
 188   if (len <= 256)
 189     buf = alloca(len);
 190   else
 191     buf = free_buf = xmalloc(len);
 192   char *p = buf;
 193
 194   /* Level (2 chars) */
 195   if (ls->msgfmt & LSFMT_LEVEL)
 196     {
 197       *p++ = LS_LEVEL_LETTER(LS_GET_LEVEL(cat));
 198       *p++ = ' ';
 199     }
 200
 201   /* Time (|stime| + |sutime| + 1 chars) */
 202   if (ls->msgfmt & LSFMT_TIME)
 203     {
 204       const char *q = (char *)stime;
 205       while (*q)
 206         *p++ = *q++;
 207       if (ls->msgfmt & LSFMT_USEC)
 208         {
 209           q = sutime;
 210           while (*q)
 211             *p++ = *q++;
 212         }
 213       *p++ = ' ';
 214     }
 215
 216   /* Process name, PID ( |log_title| + 6 + (|PID|<=10) chars ) */
 217   if ((ls->msgfmt & LSFMT_TITLE) && log_title)
 218     {
 219       if (ls->msgfmt & LSFMT_PID)
 220         p += sprintf(p, "[%s (%d)] ", log_title, log_pid);
 221       else
 222         p += sprintf(p, "[%s] ", log_title);
 223     }
 224   else
 225     {
 226       if (ls->msgfmt & LSFMT_PID)
 227         p += sprintf(p, "[%d] ", log_pid);
 228     }
 229
 230   /* log_stream name ( |ls->name| + 4 chars ) */
 231   if (ls->msgfmt & LSFMT_LOGNAME)
 232     {
 233       if (ls->name)
 234         p += sprintf(p, "<%s> ", ls->name);
 235       else
 236         p += sprintf(p, "<?> ");
 237     }
 238
 239   /* The message itself ( |m| + 1 chars ) */
 240     {
 241       const char *q = m;
 242       while (*q)
 243         *p++ = *q++;
 244       *p++ = '\n';
 245       *p++ = '\0';
 246       ls->handler(ls, buf, cat);
 247     }
 248
 249   if (free_buf)
 250     xfree(free_buf);
 251   return 0;
 252 }
 253
 254 /*** Utility functions ***/
 255
 256 void
 257 msg(unsigned int cat, const char *fmt, ...)
 258 {
 259   va_list args;
 260
 261   va_start(args, fmt);
 262   vmsg(cat, fmt, args);
 263   va_end(args);
 264 }
 265
 266 void
 267 die(const char *fmt, ...)
 268 {
 269   va_list args;
 270
 271   va_start(args, fmt);
 272   vmsg(L_FATAL, fmt, args);
 273   va_end(args);
 274   if (log_die_hook)
 275     log_die_hook();
 276 #ifdef DEBUG_DIE_BY_ABORT
 277   abort();
 278 #else
 279   exit(1);
 280 #endif
 281 }
 282
 283 void
 284 assert_failed(const char *assertion, const char *file, int line)
 285 {
 286   msg(L_FATAL, "Assertion `%s' failed at %s:%d", assertion, file, line);
 287   abort();
 288 }
 289
 290 void
 291 assert_failed_noinfo(void)
 292 {
 293   die("Internal error: Assertion failed.");
 294 }
 295
 296 static const char *
 297 log_basename(const char *n)
 298 {
 299   const char *p = n;
 300
 301   while (*n)
 302     if (*n++ == '/')
 303       p = n;
 304   return p;
 305 }
 306
 307 void
 308 log_init(const char *argv0)
 309 {
 310   if (argv0)
 311     {
 312       static char log_progname[32];
 313       strncpy(log_progname, log_basename(argv0), sizeof(log_progname)-1);
 314       log_progname[sizeof(log_progname)-1] = 0;
 315       log_title = log_progname;
 316     }
 317 }
 318
 319 void
 320 log_fork(void)
 321 {
 322   log_pid = getpid();
 323 }
 324
 325 #ifdef TEST
 326
 327 #include <syslog.h>
 328
 329 int main(void)
 330 {
 331   struct log_stream *ls = log_new_syslog(LOG_USER, "syslog");
 332   msg(L_INFO | ls->regnum, "Brum <%300s>", ":-)");
 333   return 0;
 334 }
 335
 336 #endif