Merge branch 'tor-github/pr/1303'

9 files changed, 158 insertions, 23 deletions

diff --git a/changes/bug31594 b/changes/bug31594
new file mode 100644
index 0000000000..75e6ec33cc
--- /dev/null
+++ b/changes/bug31594
@@ -0,0 +1,5 @@
+  o Minor bugfixes (error handling):
+    - When tor aborts due to an error, close log file descriptors before
+      aborting. Closing the logs makes some OSes flush log file buffers,
+      rather than deleting buffered log lines. Fixes bug 31594;
+      bugfix on 0.2.5.2-alpha.
diff --git a/src/lib/err/backtrace.c b/src/lib/err/backtrace.c
index 75d5093c54..c2011285c0 100644
--- a/src/lib/err/backtrace.c
+++ b/src/lib/err/backtrace.c
@@ -172,7 +172,7 @@ crash_handler(int sig, siginfo_t *si, void *ctx_)
   for (i=0; i < n_fds; ++i)
     backtrace_symbols_fd(cb_buf, (int)depth, fds[i]);
 
-  abort();
+  tor_raw_abort_();
 }
 
 /** Write a backtrace to all of the emergency-error fds. */
diff --git a/src/lib/err/torerr.c b/src/lib/err/torerr.c
index 48fcf35e06..0a4ee5d417 100644
--- a/src/lib/err/torerr.c
+++ b/src/lib/err/torerr.c
@@ -110,6 +110,14 @@ tor_log_get_sigsafe_err_fds(const int **out)
  * Update the list of fds that get errors from inside a signal handler or
  * other emergency condition. Ignore any beyond the first
  * TOR_SIGSAFE_LOG_MAX_FDS.
+ *
+ * These fds must remain open even after the log module has shut down. (And
+ * they should remain open even while logs are being reconfigured.) Therefore,
+ * any fds closed by the log module should be dup()ed, and the duplicate fd
+ * should be given to the err module in fds. In particular, the log module
+ * closes the file log fds, but does not close the stdio log fds.
+ *
+ * If fds is NULL or n is 0, clears the list of error fds.
  */
 void
 tor_log_set_sigsafe_err_fds(const int *fds, int n)
@@ -118,8 +126,18 @@ tor_log_set_sigsafe_err_fds(const int *fds, int n)
     n = TOR_SIGSAFE_LOG_MAX_FDS;
   }
 
-  memcpy(sigsafe_log_fds, fds, n * sizeof(int));
-  n_sigsafe_log_fds = n;
+  /* Clear the entire array. This code mitigates against some race conditions,
+   * but there are still some races here:
+   * - err logs are disabled while the array is cleared, and
+   * - a thread can read the old value of n_sigsafe_log_fds, then read a
+   *   partially written array.
+   * We could fix these races using atomics, but atomics use the err module. */
+  n_sigsafe_log_fds = 0;
+  memset(sigsafe_log_fds, 0, sizeof(sigsafe_log_fds));
+  if (fds && n > 0) {
+    memcpy(sigsafe_log_fds, fds, n * sizeof(int));
+    n_sigsafe_log_fds = n;
+  }
 }
 
 /**
@@ -133,6 +151,32 @@ tor_log_reset_sigsafe_err_fds(void)
 }
 
 /**
+ * Close the list of fds that get errors from inside a signal handler or
+ * other emergency condition. These fds are shared with the logging code:
+ * closing them flushes the log buffers, and prevents any further logging.
+ *
+ * This function closes stderr, so it should only be called immediately before
+ * process shutdown.
+ */
+void
+tor_log_close_sigsafe_err_fds(void)
+{
+  int n_fds, i;
+  const int *fds = NULL;
+
+  n_fds = tor_log_get_sigsafe_err_fds(&fds);
+  for (i = 0; i < n_fds; ++i) {
+    /* tor_log_close_sigsafe_err_fds_on_error() is called on error and on
+     * shutdown, so we can't log or take any useful action if close()
+     * fails. */
+    (void)close(fds[i]);
+  }
+
+  /* Don't even try logging, we've closed all the log fds. */
+  tor_log_set_sigsafe_err_fds(NULL, 0);
+}
+
+/**
  * Set the granularity (in ms) to use when reporting fatal errors outside
  * the logging system.
  */
@@ -171,6 +215,18 @@ tor_raw_assertion_failed_msg_(const char *file, int line, const char *expr,
   tor_log_err_sigsafe_write("\n");
 }
 
+/**
+ * Call the abort() function to kill the current process with a fatal
+ * error. But first, close the raw error file descriptors, so error messages
+ * are written before process termination.
+ **/
+void
+tor_raw_abort_(void)
+{
+  tor_log_close_sigsafe_err_fds();
+  abort();
+}
+
 /* As format_{hex,dex}_number_sigsafe, but takes a <b>radix</b> argument
  * in range 2..16 inclusive. */
 static int
@@ -205,7 +261,7 @@ format_number_sigsafe(unsigned long x, char *buf, int buf_len,
     unsigned digit = (unsigned) (x % radix);
     if (cp <= buf) {
       /* Not tor_assert(); see above. */
-      abort();
+      tor_raw_abort_();
     }
     --cp;
     *cp = "0123456789ABCDEF"[digit];
@@ -214,7 +270,7 @@ format_number_sigsafe(unsigned long x, char *buf, int buf_len,
 
   /* NOT tor_assert; see above. */
   if (cp != buf) {
-    abort(); // LCOV_EXCL_LINE
+    tor_raw_abort_(); // LCOV_EXCL_LINE
   }
 
   return len;
diff --git a/src/lib/err/torerr.h b/src/lib/err/torerr.h
index c2da6697a9..0e839cb1ba 100644
--- a/src/lib/err/torerr.h
+++ b/src/lib/err/torerr.h
@@ -20,13 +20,13 @@
 #define raw_assert(expr) STMT_BEGIN                                     \
     if (!(expr)) {                                                      \
       tor_raw_assertion_failed_msg_(__FILE__, __LINE__, #expr, NULL);   \
-      abort();                                                          \
+      tor_raw_abort_();                                                 \
     }                                                                   \
   STMT_END
 #define raw_assert_unreached(expr) raw_assert(0)
 #define raw_assert_unreached_msg(msg) STMT_BEGIN                    \
     tor_raw_assertion_failed_msg_(__FILE__, __LINE__, "0", (msg));  \
-    abort();                                                        \
+    tor_raw_abort_();                                               \
   STMT_END
 
 void tor_raw_assertion_failed_msg_(const char *file, int line,
@@ -40,8 +40,11 @@ void tor_log_err_sigsafe(const char *m, ...);
 int tor_log_get_sigsafe_err_fds(const int **out);
 void tor_log_set_sigsafe_err_fds(const int *fds, int n);
 void tor_log_reset_sigsafe_err_fds(void);
+void tor_log_close_sigsafe_err_fds(void);
 void tor_log_sigsafe_err_set_granularity(int ms);
 
+void tor_raw_abort_(void) ATTR_NORETURN;
+
 int format_hex_number_sigsafe(unsigned long x, char *buf, int max_len);
 int format_dec_number_sigsafe(unsigned long x, char *buf, int max_len);
 
diff --git a/src/lib/err/torerr_sys.c b/src/lib/err/torerr_sys.c
index 34f70f1f0b..eb818004fb 100644
--- a/src/lib/err/torerr_sys.c
+++ b/src/lib/err/torerr_sys.c
@@ -27,8 +27,11 @@ subsys_torerr_initialize(void)
 static void
 subsys_torerr_shutdown(void)
 {
-  tor_log_reset_sigsafe_err_fds();
+  /* Stop handling signals with backtraces, then close the logs. */
   clean_up_backtrace_handler();
+  /* We can't log any log messages after this point: we've closed all the log
+   * fds, including stdio. */
+  tor_log_close_sigsafe_err_fds();
 }
 
 const subsys_fns_t sys_torerr = {
diff --git a/src/lib/log/log.c b/src/lib/log/log.c
index 56f016eae4..be6f459554 100644
--- a/src/lib/log/log.c
+++ b/src/lib/log/log.c
@@ -225,6 +225,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);
@@ -665,13 +666,24 @@ 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,
+   * and the err module closes the fd on shutdown.
+   * For file logs, the err_fd is a dup() of the log_fd,
+   * and the log and err modules both close their respective fds on shutdown.
+   * (Once all fds representing a file are closed, the underlying file is
+   * closed.)
+   */
+  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) {
@@ -685,25 +697,39 @@ 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, and tor_log_close_sigsafe_err_fds() closes the err
+         * 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.
+         * tor_log_close_sigsafe_err_fds() closes stdio logs.  */
+        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)) {
+      int_array_contains(log_fds, n_fds, STDOUT_FILENO)) {
     /* Don't use a virtual stderr when we're also logging to stdout. */
     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
@@ -809,6 +835,30 @@ logs_free_all(void)
    * that happened between here and the end of execution. */
 }
 
+/** Close signal-safe log files.
+ * Closing the log files makes the process and OS flush log buffers.
+ *
+ * This function is safe to call from a signal handler. It should only be
+ * called when shutting down the log or err modules. It is currenly called
+ * by the err module, when terminating the process on an abnormal condition.
+ */
+void
+logs_close_sigsafe(void)
+{
+  logfile_t *victim, *next;
+  /* We can't LOCK_LOGS() in a signal handler, because it may call
+   * signal-unsafe functions. And we can't deallocate memory, either. */
+  next = logfiles;
+  logfiles = NULL;
+  while (next) {
+    victim = next;
+    next = next->next;
+    if (victim->needs_close) {
+      close_log_sigsafe(victim);
+    }
+  }
+}
+
 /** 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
@@ -835,13 +885,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) {
diff --git a/src/lib/log/log.h b/src/lib/log/log.h
index c4a27782c3..4291418eb6 100644
--- a/src/lib/log/log.h
+++ b/src/lib/log/log.h
@@ -173,6 +173,7 @@ void logs_set_domain_logging(int enabled);
 int get_min_log_level(void);
 void switch_logs_debug(void);
 void logs_free_all(void);
+void logs_close_sigsafe(void);
 void add_temp_log(int min_severity);
 void close_temp_logs(void);
 void rollback_log_changes(void);
diff --git a/src/lib/log/util_bug.c b/src/lib/log/util_bug.c
index 76b97c1a08..0e99be35a4 100644
--- a/src/lib/log/util_bug.c
+++ b/src/lib/log/util_bug.c
@@ -11,6 +11,7 @@
 #include "lib/log/util_bug.h"
 #include "lib/log/log.h"
 #include "lib/err/backtrace.h"
+#include "lib/err/torerr.h"
 #ifdef TOR_UNIT_TESTS
 #include "lib/smartlist_core/smartlist_core.h"
 #include "lib/smartlist_core/smartlist_foreach.h"
@@ -161,16 +162,18 @@ tor_bug_occurred_(const char *fname, unsigned int line,
 }
 
 /**
- * Call the abort() function to kill the current process with a fatal
- * error.
+ * Call the tor_raw_abort_() function to close raw logs, then kill the current
+ * process with a fatal error. But first, close the file-based log file
+ * descriptors, so error messages are written before process termination.
  *
  * (This is a separate function so that we declare it in util_bug.h without
- * including stdlib in all the users of util_bug.h)
+ * including torerr.h in all the users of util_bug.h)
  **/
 void
 tor_abort_(void)
 {
-  abort();
+  logs_close_sigsafe();
+  tor_raw_abort_();
 }
 
 #ifdef _WIN32
diff --git a/src/trunnel/trunnel-local.h b/src/trunnel/trunnel-local.h
index c4118fce4c..80da371560 100644
--- a/src/trunnel/trunnel-local.h
+++ b/src/trunnel/trunnel-local.h
@@ -14,5 +14,6 @@
 #define trunnel_reallocarray tor_reallocarray
 #define trunnel_assert tor_assert
 #define trunnel_memwipe(mem, len) memwipe((mem), 0, (len))
+#define trunnel_abort tor_abort_
 
 #endif