[tor-commits] [tor/master] Add a sighandler-safe logging mechanism

nickm at torproject.org nickm at torproject.org
Mon Nov 18 16:04:37 UTC 2013


commit bd8ad674b913582b6f8e5b85ac722e14598d681b
Author: Nick Mathewson <nickm at torproject.org>
Date:   Fri Jul 19 22:47:49 2013 -0400

    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 |   69 +++++---------------------
 src/common/backtrace.h |    2 +-
 src/common/log.c       |  125 +++++++++++++++++++++++++++++++++++++++++-------
 src/common/sandbox.c   |   47 +++---------------
 src/common/sandbox.h   |    1 -
 src/common/torlog.h    |    5 +-
 src/or/config.c        |   16 +------
 src/or/main.c          |    2 +-
 8 files changed, 135 insertions(+), 132 deletions(-)

diff --git a/src/common/backtrace.c b/src/common/backtrace.c
index d3f59b2..2c49146 100644
--- a/src/common/backtrace.c
+++ b/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);
 }
 
diff --git a/src/common/backtrace.h b/src/common/backtrace.h
index bb23960..7d7c10a 100644
--- a/src/common/backtrace.h
+++ b/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
diff --git a/src/common/log.c b/src/common/log.c
index 303fba9..3ce4df1 100644
--- a/src/common/log.c
+++ b/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)
diff --git a/src/common/sandbox.c b/src/common/sandbox.c
index dbb1657..a37c74e 100644
--- a/src/common/sandbox.c
+++ b/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
-}
 
diff --git a/src/common/sandbox.h b/src/common/sandbox.h
index bd6f0cf..54f16ec 100644
--- a/src/common/sandbox.h
+++ b/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_ */
diff --git a/src/common/torlog.h b/src/common/torlog.h
index ecd7e12..9032379 100644
--- a/src/common/torlog.h
+++ b/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_;
 
diff --git a/src/or/config.c b/src/or/config.c
index af5bf41..c62a25a 100644
--- a/src/or/config.c
+++ b/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;
diff --git a/src/or/main.c b/src/or/main.c
index ea86df0..a8f1c23 100644
--- a/src/or/main.c
+++ b/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();





More information about the tor-commits mailing list