Add a sighandler-safe logging mechanism

We had accidentially grown two fake ones: one for backtrace.c, and one
for sandbox.c.  Let's do this properly instead.

Now, when we configure logs, we keep track of fds that should get told
about bad stuff happening from signal handlers.  There's another entry
point for these that avoids using non-signal-handler-safe functions.

src/common/backtrace.c

@@ -5,6 +5,7 @@
 #include "backtrace.h"
 #include "compat.h"
 #include "util.h"
+#include "torlog.h"
 
 #ifdef HAVE_EXECINFO_H
 #include <execinfo.h>
@@ -25,34 +26,8 @@
 #define NO_BACKTRACE_IMPL
 #endif
 
-static char *bt_filename = NULL;
 static char *bt_version = NULL;
 
-#ifndef NO_BACKTRACE_IMPL
-/**DOCDOC*/
-static int
-open_bt_target(void)
-{
-  int fd = -1;
-  if (bt_filename)
-    fd = open(bt_filename, O_WRONLY|O_CREAT|O_APPEND, 0700);
-  return fd;
-}
-#endif
-
-/**DOCDOC*/
-static void
-bt_write(int fd, const char *s, ssize_t n)
-{
-  int r;
-  if (n < 0) n = strlen(s);
-
-  r = write(STDERR_FILENO, s, n);
-  if (fd >= 0)
-    r = write(fd, s, n);
-  (void)r; 
-}
-
 #ifdef USE_BACKTRACE
 #define MAX_DEPTH 256
 static void *cb_buf[MAX_DEPTH];
@@ -61,33 +36,20 @@ static void *cb_buf[MAX_DEPTH];
 void
 dump_backtrace(const char *msg)
 {
-  char timebuf[32];
-  time_t t = time(NULL);
-  int timebuf_len;
   int depth;
-  int fd;
+  const int *fds;
+  int n_fds;
+  int i;
+
   if (!msg) msg = "unspecified crash";
 
   depth = backtrace(cb_buf, MAX_DEPTH);
 
-  t /= 900; t *= 900; /* Round to the previous 15 minutes */
-  timebuf[0] = '\0';
-  timebuf_len = format_dec_number_sigsafe(t, timebuf, sizeof(timebuf));
-
-  fd = open_bt_target();
-  bt_write(fd, "========================================"
-               "====================================\n", -1);
-  bt_write(fd, bt_version, -1);
-  bt_write(fd, " died around T=", -1);
-  bt_write(fd, timebuf, timebuf_len);
-  bt_write(fd, ": ", 2);
-  bt_write(fd, msg, -1);
-  bt_write(fd, "\n", 1);
-  backtrace_symbols_fd(cb_buf, depth, STDERR_FILENO);
-  if (fd >= 0)
-    backtrace_symbols_fd(cb_buf, depth, fd);
-
-  close(fd);
+  tor_log_err_sigsafe(bt_version, " died: ", msg, "\n",
+                      NULL);
+  n_fds = tor_log_get_sigsafe_err_fds(&fds);
+  for (i=0; i < n_fds; ++i)
+    backtrace_symbols_fd(cb_buf, depth, fds[i]);
 }
 
 /**DOCDOC*/
@@ -110,10 +72,7 @@ remove_bt_handler(void)
 void
 dump_backtrace(const char *msg)
 {
-  bt_write(-1, bt_version, -1);
-  bt_write(-1, " died: ", -1);
-  bt_write(-1, msg, -1);
-  bt_write(-1, "\n", -1);
+  tor_log_err_sigsafe(bt_version, " died: ", msg, "\n", NULL);
 }
 
 /**DOCDOC*/
@@ -132,11 +91,8 @@ remove_bt_handler(void)
 
 /**DOCDOC*/
 int
-configure_backtrace_handler(const char *filename, const char *tor_version)
+configure_backtrace_handler(const char *tor_version)
 {
-  tor_free(bt_filename);
-  if (filename)
-    bt_filename = tor_strdup(filename);
   tor_free(bt_version);
   if (!tor_version)
     tor_version = "Tor";
@@ -151,7 +107,6 @@ clean_up_backtrace_handler(void)
 {
   remove_bt_handler();
 
-  tor_free(bt_filename);
   tor_free(bt_version);
 }
 

src/common/backtrace.h

@@ -5,7 +5,7 @@
 #define TOR_BACKTRACE_H
 
 void dump_backtrace(const char *msg);
-int configure_backtrace_handler(const char *filename, const char *tor_version);
+int configure_backtrace_handler(const char *tor_version);
 void clean_up_backtrace_handler(void);
 
 #endif

src/common/log.c

@@ -443,6 +443,115 @@ tor_log(int severity, log_domain_mask_t domain, const char *format, ...)
   va_end(ap);
 }
 
+/** Maximum number of fds that will get notifications if we crash */
+#define MAX_SIGSAFE_FDS 8
+/** Array of fds to log crash-style warnings to. */
+static int sigsafe_log_fds[MAX_SIGSAFE_FDS] = { STDERR_FILENO };
+/** The number of elements used in sigsafe_log_fds */
+static int n_sigsafe_log_fds = 1;
+
+/** Write <b>s</b> to each element of sigsafe_log_fds. Return 0 on success, -1
+ * on failure. */
+static int
+tor_log_err_sigsafe_write(const char *s)
+{
+  int i;
+  ssize_t r;
+  size_t len = strlen(s);
+  int err = 0;
+  for (i=0; i < n_sigsafe_log_fds; ++i) {
+    r = write(sigsafe_log_fds[i], s, len);
+    err += (r != (ssize_t)len);
+  }
+  return err ? -1 : 0;
+}
+
+/** Given a list of string arguments ending with a NULL, writes them
+ * to our logs and to stderr (if possible).  This function is safe to call
+ * from within a signal handler. */
+void
+tor_log_err_sigsafe(const char *m, ...)
+{
+  va_list ap;
+  const char *x;
+  char timebuf[32];
+  time_t now = time(NULL);
+
+  if (!m)
+    return;
+  if (log_time_granularity >= 2000) {
+    int g = log_time_granularity / 1000;
+    now -= now % g;
+  }
+  timebuf[0] = '\0';
+  format_dec_number_sigsafe(now, timebuf, sizeof(timebuf));
+  tor_log_err_sigsafe_write("\n=========================================="
+                             "================== T=");
+  tor_log_err_sigsafe_write(timebuf);
+  tor_log_err_sigsafe_write("\n");
+  tor_log_err_sigsafe_write(m);
+  va_start(ap, m);
+  while ((x = va_arg(ap, const char*))) {
+    tor_log_err_sigsafe_write(x);
+  }
+  va_end(ap);
+}
+
+/** Set *<b>out</b> to a pointer to an array of the fds to log errors to from
+ * inside a signal handler. Return the number of elements in the array. */
+int
+tor_log_get_sigsafe_err_fds(const int **out)
+{
+  *out = sigsafe_log_fds;
+  return n_sigsafe_log_fds;
+}
+
+/** Helper function; return true iff the <b>n</b>-element array <b>array</b>
+ * contains <b>item</b>. */
+static int
+int_array_contains(const int *array, int n, int item)
+{
+  int j;
+  for (j = 0; j < n; ++j) {
+    if (array[j] == item)
+      return 1;
+  }
+  return 0;
+}
+
+/** Function to call whenever the list of logs changes to get ready to log
+ * from signal handlers. */
+void
+tor_log_update_sigsafe_err_fds(void)
+{
+  const logfile_t *lf;
+
+  LOCK_LOGS();
+  /* Always try for stderr. This is safe because when we daemonize, we dup2
+   * /dev/null to stderr, */
+  sigsafe_log_fds[0] = STDERR_FILENO;
+  n_sigsafe_log_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.
+      */
+    if (lf->is_temporary || lf->is_syslog ||
+        lf->callback || lf->seems_dead || lf->fd < 0)
+      continue;
+    if (lf->severities->masks[SEVERITY_MASK_IDX(LOG_ERR)] &
+        (LD_BUG|LD_GENERAL)) {
+      /* Avoid duplicates */
+      if (int_array_contains(sigsafe_log_fds, n_sigsafe_log_fds, lf->fd))
+        continue;
+      sigsafe_log_fds[n_sigsafe_log_fds++] = lf->fd;
+      if (n_sigsafe_log_fds == MAX_SIGSAFE_FDS)
+        break;
+    }
+  }
+  UNLOCK_LOGS();
+}
+
 /** Output a message to the log, prefixed with a function name <b>fn</b>. */
 #ifdef __GNUC__
 /** GCC-based implementation of the log_fn backend, used when we have
@@ -1142,22 +1251,6 @@ get_min_log_level(void)
   return min;
 }
 
-/** Return the fd of a file log that is receiving ERR messages, or -1 if
- * no such log exists. */
-int
-get_err_logging_fd(void)
-{
-  const logfile_t *lf;
-  for (lf = logfiles; lf; lf = lf->next) {
-    if (lf->is_temporary || lf->is_syslog || !lf->filename ||
-        lf->callback || lf->seems_dead || lf->fd < 0)
-      continue;
-    if (lf->severities->masks[LOG_ERR] & LD_GENERAL)
-      return lf->fd;
-  }
-  return -1;
-}
-
 /** Switch all logs to output at most verbose level. */
 void
 switch_logs_debug(void)

src/common/sandbox.c

@@ -184,16 +184,6 @@ install_glob_syscall_filter(void)
   return (rc < 0 ? -rc : rc);
 }
 
-/** Additional file descriptor to use when logging seccomp2 failures */
-static int sigsys_debugging_fd = -1;
-
-/** Use the file descriptor <b>fd</b> to log seccomp2 failures. */
-static void
-sigsys_set_debugging_fd(int fd)
-{
-  sigsys_debugging_fd = fd;
-}
-
 /**
  * Function called when a SIGSYS is caught by the application. It notifies the
  * user that an error has occurred and either terminates or allows the
@@ -203,8 +193,8 @@ static void
 sigsys_debugging(int nr, siginfo_t *info, void *void_context)
 {
   ucontext_t *ctx = (ucontext_t *) (void_context);
-  char message[256];
-  int rv = 0, syscall, length, err;
+  char number[32];
+  int syscall;
   (void) nr;
 
   if (info->si_code != SYS_SECCOMP)
@@ -215,24 +205,11 @@ sigsys_debugging(int nr, siginfo_t *info, void *void_context)
 
   syscall = ctx->uc_mcontext.gregs[REG_SYSCALL];
 
-  strlcpy(message, "\n\n(Sandbox) Caught a bad syscall attempt (syscall 0x",
-          sizeof(message));
-  (void) format_hex_number_sigsafe(syscall, message+strlen(message),
-                                   sizeof(message)-strlen(message));
-  strlcat(message, ")\n", sizeof(message));
-  length = strlen(message);
-
-  err = 0;
-  if (sigsys_debugging_fd >= 0) {
-    rv = write(sigsys_debugging_fd, message, length);
-    err += rv != length;
-  }
-
-  rv = write(STDOUT_FILENO, message, length);
-  err += rv != length;
-
-  if (err)
-    _exit(2);
+  format_dec_number_sigsafe(syscall, number, sizeof(number));
+  tor_log_err_sigsafe("(Sandbox) Caught a bad syscall attempt (syscall ",
+                      number,
+                      ")\n",
+                      NULL);
 
 #if defined(DEBUGGING_CLOSE)
   _exit(1);
@@ -318,14 +295,4 @@ tor_global_sandbox(void)
 #endif
 }
 
-/** Use <b>fd</b> to log non-survivable sandbox violations. */
-void
-sandbox_set_debugging_fd(int fd)
-{
-#ifdef USE_LIBSECCOMP
-  sigsys_set_debugging_fd(fd);
-#else
-  (void)fd;
-#endif
-}
 

src/common/sandbox.h

@@ -48,7 +48,6 @@
 
 #endif // __linux__
 
-void sandbox_set_debugging_fd(int fd);
 int tor_global_sandbox(void);
 
 #endif /* SANDBOX_H_ */

src/common/torlog.h

@@ -136,7 +136,6 @@ int get_min_log_level(void);
 void switch_logs_debug(void);
 void logs_free_all(void);
 void add_temp_log(int min_severity);
-int get_err_logging_fd(void);
 void close_temp_logs(void);
 void rollback_log_changes(void);
 void mark_logs_temp(void);
@@ -149,6 +148,10 @@ void set_log_time_granularity(int granularity_msec);
 void tor_log(int severity, log_domain_mask_t domain, const char *format, ...)
   CHECK_PRINTF(3,4);
 
+void tor_log_err_sigsafe(const char *m, ...);
+int tor_log_get_sigsafe_err_fds(const int **out);
+void tor_log_update_sigsafe_err_fds(void);
+
 #if defined(__GNUC__) || defined(RUNNING_DOXYGEN)
 extern int log_global_min_severity_;
 

src/or/config.c

@@ -12,7 +12,6 @@
 #define CONFIG_PRIVATE
 #include "or.h"
 #include "addressmap.h"
-#include "backtrace.h"
 #include "channel.h"
 #include "circuitbuild.h"
 #include "circuitlist.h"
@@ -1114,19 +1113,6 @@ options_act_reversible(const or_options_t *old_options, char **msg)
     /* No need to roll back, since you can't change the value. */
   }
 
-  /* Enable crash logging to files */
-  {
-    /* XXXX we might want to set this up earlier, if possible! */
-    char *backtrace_fname = NULL;
-    char *progname = NULL;
-    tor_asprintf(&backtrace_fname, "%s"PATH_SEPARATOR"stack_dump",
-                 options->DataDirectory);
-    tor_asprintf(&progname, "Tor %s", get_version());
-    configure_backtrace_handler(backtrace_fname, progname);
-    tor_free(backtrace_fname);
-    tor_free(progname);
-  }
-
   /* Write control ports to disk as appropriate */
   control_ports_write_to_file();
 
@@ -1156,7 +1142,7 @@ options_act_reversible(const or_options_t *old_options, char **msg)
     goto rollback;
   }
 
-  sandbox_set_debugging_fd(get_err_logging_fd());
+  tor_log_update_sigsafe_err_fds();
 
  commit:
   r = 0;

src/or/main.c

@@ -2685,7 +2685,7 @@ tor_main(int argc, char *argv[])
   }
 #endif
 
-  configure_backtrace_handler(NULL, get_version());
+  configure_backtrace_handler(get_version());
 
   update_approx_time(time(NULL));
   tor_threads_init();