1 files changed, 82 insertions, 37 deletions

diff --git a/src/lib/log/log.c b/src/lib/log/log.c
index a9ad38fb25..c53db46a8c 100644
--- a/src/lib/log/log.c
+++ b/src/lib/log/log.c
@@ -32,7 +32,8 @@
 
 #define LOG_PRIVATE
 #include "lib/log/log.h"
-#include "lib/log/git_revision.h"
+#include "lib/log/log_sys.h"
+#include "lib/version/git_revision.h"
 #include "lib/log/ratelim.h"
 #include "lib/lock/compat_mutex.h"
 #include "lib/smartlist_core/smartlist_core.h"
@@ -48,15 +49,12 @@
 #include "lib/wallclock/approx_time.h"
 #include "lib/wallclock/time_to_tm.h"
 #include "lib/fdio/fdio.h"
+#include "lib/cc/ctassert.h"
 
 #ifdef HAVE_ANDROID_LOG_H
 #include <android/log.h>
 #endif // HAVE_ANDROID_LOG_H.
 
-/** Given a severity, yields an index into log_severity_list_t.masks to use
- * for that severity. */
-#define SEVERITY_MASK_IDX(sev) ((sev) - LOG_ERR)
-
 /** @{ */
 /** The string we stick at the end of a log message when it is too long,
  * and its length. */
@@ -153,7 +151,7 @@ severity_to_android_log_priority(int severity)
       // LCOV_EXCL_STOP
   }
 }
-#endif // HAVE_ANDROID_LOG_H.
+#endif /* defined(HAVE_ANDROID_LOG_H) */
 
 /** A mutex to guard changes to logfiles and logging. */
 static tor_mutex_t log_mutex;
@@ -223,6 +221,7 @@ int log_global_min_severity_ = LOG_NOTICE;
 
 static void delete_log(logfile_t *victim);
 static void close_log(logfile_t *victim);
+static void close_log_sigsafe(logfile_t *victim);
 
 static char *domain_to_string(log_domain_mask_t domain,
                              char *buf, size_t buflen);
@@ -533,7 +532,7 @@ logfile_deliver(logfile_t *lf, const char *buf, size_t msg_len,
     if (m != msg_after_prefix) {
       tor_free(m);
     }
-#else /* !(defined(MAXLINE)) */
+#else /* !defined(MAXLINE) */
     /* We have syslog but not MAXLINE.  That's promising! */
     syslog(severity, "%s", msg_after_prefix);
 #endif /* defined(MAXLINE) */
@@ -585,8 +584,7 @@ logv,(int severity, log_domain_mask_t domain, const char *funcname,
   /* check that severity is sane.  Overrunning the masks array leads to
    * interesting and hard to diagnose effects */
   raw_assert(severity >= LOG_ERR && severity <= LOG_DEBUG);
-  /* check that we've initialised the log mutex before we try to lock it */
-  raw_assert(log_mutex_initialized);
+
   LOCK_LOGS();
 
   if ((! (domain & LD_NOCB)) && pending_cb_messages
@@ -630,6 +628,10 @@ void
 tor_log(int severity, log_domain_mask_t domain, const char *format, ...)
 {
   va_list ap;
+
+  /* check that domain is composed of known domains and flags */
+  raw_assert((domain & (LD_ALL_DOMAINS|LD_ALL_FLAGS)) == domain);
+
   if (severity > log_global_min_severity_)
     return;
   va_start(ap,format);
@@ -663,18 +665,26 @@ tor_log_update_sigsafe_err_fds(void)
   const logfile_t *lf;
   int found_real_stderr = 0;
 
-  int fds[TOR_SIGSAFE_LOG_MAX_FDS];
+  /* log_fds and err_fds contain matching entries: log_fds are the fds used by
+   * the log module, and err_fds are the fds used by the err module.
+   * For stdio logs, the log_fd and err_fd values are identical.
+   * For file logs, the err_fd is a dup() of the log_fd.
+   */
+  int log_fds[TOR_SIGSAFE_LOG_MAX_FDS];
+  int err_fds[TOR_SIGSAFE_LOG_MAX_FDS];
   int n_fds;
 
   LOCK_LOGS();
   /* Reserve the first one for stderr. This is safe because when we daemonize,
-   * we dup2 /dev/null to stderr, */
-  fds[0] = STDERR_FILENO;
+   * we dup2 /dev/null to stderr.
+   * For stderr, log_fds and err_fds are the same. */
+  log_fds[0] = err_fds[0] = STDERR_FILENO;
   n_fds = 1;
 
   for (lf = logfiles; lf; lf = lf->next) {
-     /* Don't try callback to the control port, or syslogs: We can't
-      * do them from a signal handler. Don't try stdout: we always do stderr.
+     /* Don't try callback to the control port, syslogs, android logs, or any
+      * other non-file descriptor log: We can't call arbitrary functions from a
+      * signal handler.
       */
     if (lf->is_temporary || logfile_is_external(lf)
         || lf->seems_dead || lf->fd < 0)
@@ -683,25 +693,40 @@ tor_log_update_sigsafe_err_fds(void)
         (LD_BUG|LD_GENERAL)) {
       if (lf->fd == STDERR_FILENO)
         found_real_stderr = 1;
-      /* Avoid duplicates */
-      if (int_array_contains(fds, n_fds, lf->fd))
+      /* Avoid duplicates by checking the log module fd against log_fds */
+      if (int_array_contains(log_fds, n_fds, lf->fd))
         continue;
-      fds[n_fds++] = lf->fd;
+      /* Update log_fds using the log module's fd */
+      log_fds[n_fds] = lf->fd;
+      if (lf->needs_close) {
+        /* File log fds are duplicated, because close_log() closes the log
+         * module's fd. Both refer to the same file. */
+        err_fds[n_fds] = dup(lf->fd);
+      } else {
+        /* stdio log fds are not closed by the log module. */
+        err_fds[n_fds] = lf->fd;
+      }
+      n_fds++;
       if (n_fds == TOR_SIGSAFE_LOG_MAX_FDS)
         break;
     }
   }
 
   if (!found_real_stderr &&
-      int_array_contains(fds, n_fds, STDOUT_FILENO)) {
-    /* Don't use a virtual stderr when we're also logging to stdout. */
+      int_array_contains(log_fds, n_fds, STDOUT_FILENO)) {
+    /* Don't use a virtual stderr when we're also logging to stdout.
+     * If we reached max_fds logs, we'll now have (max_fds - 1) logs.
+     * That's ok, max_fds is large enough that most tor instances don't exceed
+     * it. */
     raw_assert(n_fds >= 2); /* Don't tor_assert inside log fns */
-    fds[0] = fds[--n_fds];
+    --n_fds;
+    log_fds[0] = log_fds[n_fds];
+    err_fds[0] = err_fds[n_fds];
   }
 
   UNLOCK_LOGS();
 
-  tor_log_set_sigsafe_err_fds(fds, n_fds);
+  tor_log_set_sigsafe_err_fds(err_fds, n_fds);
 }
 
 /** Add to <b>out</b> a copy of every currently configured log file name. Used
@@ -727,7 +752,7 @@ tor_log_get_logfile_names(smartlist_t *out)
 
 /** Implementation of the log_fn backend, used when we have
  * variadic macros. All arguments are as for log_fn, except for
- * <b>fn</b>, which is the name of the calling functions. */
+ * <b>fn</b>, which is the name of the calling function. */
 void
 log_fn_(int severity, log_domain_mask_t domain, const char *fn,
         const char *format, ...)
@@ -804,16 +829,16 @@ logs_free_all(void)
   }
 
   /* We _could_ destroy the log mutex here, but that would screw up any logs
-   * that happened between here and the end of execution. */
+   * that happened between here and the end of execution.
+   * If tor is re-initialized, log_mutex_initialized will still be 1. So we
+   * won't trigger any undefined behaviour by trying to re-initialize the
+   * log mutex. */
 }
 
 /** Remove and free the log entry <b>victim</b> from the linked-list
  * logfiles (it is probably present, but it might not be due to thread
  * racing issues). After this function is called, the caller shouldn't
  * refer to <b>victim</b> anymore.
- *
- * Long-term, we need to do something about races in the log subsystem
- * in general. See bug 222 for more details.
  */
 static void
 delete_log(logfile_t *victim)
@@ -833,13 +858,26 @@ delete_log(logfile_t *victim)
 }
 
 /** Helper: release system resources (but not memory) held by a single
- * logfile_t. */
+ * signal-safe logfile_t. If the log's resources can not be released in
+ * a signal handler, does nothing. */
 static void
-close_log(logfile_t *victim)
+close_log_sigsafe(logfile_t *victim)
 {
   if (victim->needs_close && victim->fd >= 0) {
+    /* We can't do anything useful here if close() fails: we're shutting
+     * down logging, and the err module only does fatal errors. */
     close(victim->fd);
     victim->fd = -1;
+  }
+}
+
+/** Helper: release system resources (but not memory) held by a single
+ * logfile_t. */
+static void
+close_log(logfile_t *victim)
+{
+  if (victim->needs_close) {
+    close_log_sigsafe(victim);
   } else if (victim->is_syslog) {
 #ifdef HAVE_SYSLOG_H
     if (--syslog_count == 0) {
@@ -863,7 +901,7 @@ set_log_severity_config(int loglevelMin, int loglevelMax,
   raw_assert(loglevelMax >= LOG_ERR && loglevelMax <= LOG_DEBUG);
   memset(severity_out, 0, sizeof(log_severity_list_t));
   for (i = loglevelMin; i >= loglevelMax; --i) {
-    severity_out->masks[SEVERITY_MASK_IDX(i)] = ~0u;
+    severity_out->masks[SEVERITY_MASK_IDX(i)] = LD_ALL_DOMAINS;
   }
 }
 
@@ -1020,7 +1058,7 @@ flush_pending_log_callbacks(void)
   do {
     SMARTLIST_FOREACH_BEGIN(messages, pending_log_message_t *, msg) {
       const int severity = msg->severity;
-      const int domain = msg->domain;
+      const log_domain_mask_t domain = msg->domain;
       for (lf = logfiles; lf; lf = lf->next) {
         if (! lf->callback || lf->seems_dead ||
             ! (lf->severities->masks[SEVERITY_MASK_IDX(severity)] & domain)) {
@@ -1231,7 +1269,7 @@ add_android_log(const log_severity_list_t *severity,
   UNLOCK_LOGS();
   return 0;
 }
-#endif // HAVE_ANDROID_LOG_H.
+#endif /* defined(HAVE_ANDROID_LOG_H) */
 
 /** If <b>level</b> is a valid log severity, return the corresponding
  * numeric value.  Otherwise, return -1. */
@@ -1267,9 +1305,16 @@ static const char *domain_list[] = {
   "GENERAL", "CRYPTO", "NET", "CONFIG", "FS", "PROTOCOL", "MM",
   "HTTP", "APP", "CONTROL", "CIRC", "REND", "BUG", "DIR", "DIRSERV",
   "OR", "EDGE", "ACCT", "HIST", "HANDSHAKE", "HEARTBEAT", "CHANNEL",
-  "SCHED", "GUARD", "CONSDIFF", "DOS", NULL
+  "SCHED", "GUARD", "CONSDIFF", "DOS", "PROCESS", "PT", "BTRACK", "MESG",
+  NULL
 };
 
+CTASSERT(ARRAY_LENGTH(domain_list) == N_LOGGING_DOMAINS + 1);
+
+CTASSERT(HIGHEST_RESERVED_LD_DOMAIN_ < LD_ALL_DOMAINS);
+CTASSERT(LD_ALL_DOMAINS < LOWEST_RESERVED_LD_FLAG_);
+CTASSERT(LOWEST_RESERVED_LD_FLAG_ < LD_ALL_FLAGS);
+
 /** Return a bitmask for the log domain for which <b>domain</b> is the name,
  * or 0 if there is no such name. */
 static log_domain_mask_t
@@ -1278,7 +1323,7 @@ parse_log_domain(const char *domain)
   int i;
   for (i=0; domain_list[i]; ++i) {
     if (!strcasecmp(domain, domain_list[i]))
-      return (1u<<i);
+      return (UINT64_C(1)<<i);
   }
   return 0;
 }
@@ -1350,7 +1395,7 @@ parse_log_severity_config(const char **cfg_ptr,
     const char *dash, *space;
     char *sev_lo, *sev_hi;
     int low, high, i;
-    log_domain_mask_t domains = ~0u;
+    log_domain_mask_t domains = LD_ALL_DOMAINS;
 
     if (*cfg == '[') {
       int err = 0;
@@ -1368,9 +1413,9 @@ parse_log_severity_config(const char **cfg_ptr,
       tor_free(domains_str);
       SMARTLIST_FOREACH_BEGIN(domains_list, const char *, domain) {
             if (!strcmp(domain, "*")) {
-              domains = ~0u;
+              domains = LD_ALL_DOMAINS;
             } else {
-              int d;
+              log_domain_mask_t d;
               int negate=0;
               if (*domain == '~') {
                 negate = 1;
@@ -1464,7 +1509,7 @@ switch_logs_debug(void)
   LOCK_LOGS();
   for (lf = logfiles; lf; lf=lf->next) {
     for (i = LOG_DEBUG; i >= LOG_ERR; --i)
-      lf->severities->masks[SEVERITY_MASK_IDX(i)] = ~0u;
+      lf->severities->masks[SEVERITY_MASK_IDX(i)] = LD_ALL_DOMAINS;
   }
   log_global_min_severity_ = get_min_log_level();
   UNLOCK_LOGS();