Logging: L_SIGHANDLER should be really safe.

I have realized that many operations performed by the log stream code are
either unsafe to call from signal handlers, subject to races between the
main program and its signal handlers, or subject to deadlocks when the
ucwlib_lock is taken.

I have therefore changed the semantics of L_SIGHANDLER to provide only
the minimal logging service: All sighandler messages are now logged to
stderr (which usually follows the main log file) and they are limited
to 255 characters (so that no dynamic allocation is performed).

diff --git a/ucw/doc/log.txt b/ucw/doc/log.txt
index 94e1e82a87bd10d58c84932fcc0c66faab367dc9..2da50e1e6c9e3a3b5d597c5dbe63a63755b21137 100644 (file)
--- a/ucw/doc/log.txt
+++ b/ucw/doc/log.txt
@@ -18,9 +18,8 @@ A newline character is automatically appended; the message should not contain
 any control characters.
 
 The first argument of `msg` can be OR'ed with additional flags. Most notably, you can
-add `L_SIGHANDLER` if you wish to log a message from a signal handler (calling
-time-related functions in libc from signal handlers is generally unsafe, so
-`msg` does not log a timestamp in such cases).
+add `L_SIGHANDLER` if you wish to log a message from a signal handler (see below
+for discussion on signals and reentrancy in general).
 
 By default, all messages are logged to stderr. If you wish to use a log file,
 call `log_file(@name)`. All subsequent logging will use this file and stderr
@@ -118,6 +117,11 @@ LibUCW therefore offers only limited logging services in such situations and
 you must use the `L_SIGHANDLER` flag to request it. Otherwise, deadlocks get
 ready to happen.
 
+Messages logged with `L_SIGHANDLER` set are written directly to stderr (which
+is usually an alias for the main log file, at least if you use <<log_file()>>)
+and they do not carry a timestamp. Logging of sighandler messages to general
+log streams or to syslog is therefore not supported.
+
 ucw/log.h
 ---------
 !!ucw/log.h

diff --git a/ucw/log.c b/ucw/log.c
index 1ed35feef49d9b08502503e479417445b908b521..5a5dc808c9487ba8d479a896187678701387445f 100644 (file)
--- a/ucw/log.c
+++ b/ucw/log.c
@@ -100,18 +100,21 @@ vmsg(uns cat, const char *fmt, va_list args)
   char msgbuf[256];
   char *p;
   int len;
-  struct log_stream *ls = log_stream_by_flags(cat);
+  uns sighandler = cat & L_SIGHANDLER;
+  struct log_stream *ls;
   struct log_msg m = { .flags = cat };
 
-  /* Check the stream existence */
-  if (!ls)
+  /* Find the destination stream */
+  if (sighandler)
+    ls = &log_stream_default;
+  else if (!(ls = log_stream_by_flags(cat)))
     {
       msg((LS_CTRL_MASK&cat)|L_WARN, "No log_stream with number %d! Logging to the default log.", LS_GET_STRNUM(cat));
       ls = &log_stream_default;
     }
 
   /* Get the current time */
-  if (!(cat & L_SIGHANDLER))
+  if (!sighandler)
     {
       /* CAVEAT: These calls are not safe in signal handlers. */
       gettimeofday(&tv, NULL);
@@ -137,7 +140,7 @@ vmsg(uns cat, const char *fmt, va_list args)
   va_copy(args2, args);
   len = vsnprintf(msgbuf, sizeof(msgbuf), fmt, args2);
   va_end(args2);
-  if (len < (int) sizeof(msgbuf))
+  if (len < (int) sizeof(msgbuf) || sighandler)
     m.raw_msg = msgbuf;
   else
     {
@@ -240,7 +243,7 @@ log_pass_msg(int depth, struct log_stream *ls, struct log_msg *m)
 
   /* Get a buffer and format the message */
   char *free_buf = NULL;
-  if (len <= 256)
+  if (len <= 256 || (m->flags & L_SIGHANDLER))
     m->m = alloca(len);
   else
     m->m = free_buf = xmalloc(len);