Merge branch 'mr/334'

src/feature/relay/dns.c

@@ -63,6 +63,7 @@
 #include "feature/relay/dns.h"
 #include "feature/relay/router.h"
 #include "feature/relay/routermode.h"
+#include "feature/stats/rephist.h"
 #include "lib/crypt_ops/crypto_rand.h"
 #include "lib/evloop/compat_libevent.h"
 #include "lib/sandbox/sandbox.h"
@@ -1547,6 +1548,16 @@ evdns_callback(int result, char type, int count, int ttl, void *addresses,
 
   tor_addr_make_unspec(&addr);
 
+  /* Note down any DNS errors to the statistics module */
+  if (result == DNS_ERR_TIMEOUT) {
+    /* libevent timed out while resolving a name. However, because libevent
+     * handles retries and timeouts internally, this means that all attempts of
+     * libevent timed out. If we wanted to get more granular information about
+     * individual libevent attempts, we would have to implement our own DNS
+     * timeout/retry logic */
+    rep_hist_note_overload(OVERLOAD_GENERAL);
+  }
+
   /* Keep track of whether IPv6 is working */
   if (type == DNS_IPv6_AAAA) {
     if (result == DNS_ERR_TIMEOUT) {

src/feature/relay/onion_queue.c

@@ -33,6 +33,7 @@
 #include "core/or/circuitlist.h"
 #include "core/or/onion.h"
 #include "feature/nodelist/networkstatus.h"
+#include "feature/stats/rephist.h"
 
 #include "core/or/or_circuit_st.h"
 
@@ -163,15 +164,19 @@ onion_pending_add(or_circuit_t *circ, create_cell_t *onionskin)
 #define WARN_TOO_MANY_CIRC_CREATIONS_INTERVAL (60)
     static ratelim_t last_warned =
       RATELIM_INIT(WARN_TOO_MANY_CIRC_CREATIONS_INTERVAL);
-    char *m;
-    if (onionskin->handshake_type == ONION_HANDSHAKE_TYPE_NTOR &&
-        (m = rate_limit_log(&last_warned, approx_time()))) {
-      log_warn(LD_GENERAL,
-               "Your computer is too slow to handle this many circuit "
-               "creation requests! Please consider using the "
-               "MaxAdvertisedBandwidth config option or choosing a more "
-               "restricted exit policy.%s",m);
-      tor_free(m);
+    if (onionskin->handshake_type == ONION_HANDSHAKE_TYPE_NTOR) {
+      char *m;
+      /* Note this ntor onionskin drop as an overload */
+      rep_hist_note_overload(OVERLOAD_GENERAL);
+      if ((m = rate_limit_log(&last_warned, approx_time()))) {
+        log_warn(LD_GENERAL,
+                 "Your computer is too slow to handle this many circuit "
+                 "creation requests! Please consider using the "
+                 "MaxAdvertisedBandwidth config option or choosing a more "
+                 "restricted exit policy.%s",
+                 m);
+        tor_free(m);
+      }
     }
     tor_free(tmp);
     return -1;

src/feature/relay/router.c

@@ -3372,6 +3372,12 @@ extrainfo_dump_to_string_stats_helper(smartlist_t *chunks,
       if (contents)
         smartlist_add(chunks, contents);
     }
+    if (options->OverloadStatistics) {
+      contents = rep_hist_get_overload_stats_lines();
+      if (contents) {
+        smartlist_add(chunks, contents);
+      }
+    }
     /* bridge statistics */
     if (should_record_bridge_info(options)) {
       const char *bridge_stats = geoip_get_bridge_stats_extrainfo(now);

src/feature/stats/rephist.c

@@ -183,6 +183,133 @@ static time_t started_tracking_stability = 0;
 /** Map from hex OR identity digest to or_history_t. */
 static digestmap_t *history_map = NULL;
 
+/** Represents a state of overload stats.
+ *
+ *  All the timestamps in this structure have already been rounded down to the
+ *  nearest hour. */
+typedef struct {
+  /* When did we last experience a general overload? */
+  time_t overload_general_time;
+
+  /* When did we last experience a bandwidth-related overload? */
+  time_t overload_ratelimits_time;
+  /* How many times have we gone off the our read limits? */
+  uint64_t overload_read_count;
+  /* How many times have we gone off the our write limits? */
+  uint64_t overload_write_count;
+
+  /* When did we last experience a file descriptor exhaustion? */
+  time_t overload_fd_exhausted_time;
+  /* How many times have we experienced a file descriptor exhaustion? */
+  uint64_t overload_fd_exhausted;
+} overload_stats_t;
+
+/** Current state of overload stats */
+static overload_stats_t overload_stats;
+
+/** Return true if this overload happened within the last `n_hours`. */
+static bool
+overload_happened_recently(time_t overload_time, unsigned n_hours)
+{
+  /* An overload is relevant if it happened in the last 72 hours */
+  if (overload_time > approx_time() - 3600 * n_hours) {
+    return true;
+  }
+  return false;
+}
+
+/* The current version of the overload stats version */
+#define OVERLOAD_STATS_VERSION 1
+
+/** Returns an allocated string for extra-info documents for publishing
+ *  overload statistics. */
+char *
+rep_hist_get_overload_stats_lines(void)
+{
+  char *result = NULL;
+  smartlist_t *chunks = smartlist_new();
+  char tbuf[ISO_TIME_LEN+1];
+
+  /* First encode the general overload */
+  if (overload_happened_recently(overload_stats.overload_general_time, 72)) {
+    format_iso_time(tbuf, overload_stats.overload_general_time);
+    smartlist_add_asprintf(chunks, "overload-general %d %s",
+                           OVERLOAD_STATS_VERSION, tbuf);
+  }
+
+  /* Now do bandwidth-related overloads */
+  if (overload_happened_recently(overload_stats.overload_ratelimits_time,24)) {
+    const or_options_t *options = get_options();
+    format_iso_time(tbuf, overload_stats.overload_ratelimits_time);
+    smartlist_add_asprintf(chunks,
+                           "overload-ratelimits %d %s %" PRIu64 " %" PRIu64
+                           " %" PRIu64 " %" PRIu64,
+                           OVERLOAD_STATS_VERSION, tbuf,
+                           options->BandwidthRate, options->BandwidthBurst,
+                           overload_stats.overload_read_count,
+                           overload_stats.overload_write_count);
+  }
+
+  /* Finally file descriptor overloads */
+  if (overload_happened_recently(
+                              overload_stats.overload_fd_exhausted_time, 72)) {
+    format_iso_time(tbuf, overload_stats.overload_fd_exhausted_time);
+    smartlist_add_asprintf(chunks, "overload-fd-exhausted %d %s",
+                           OVERLOAD_STATS_VERSION, tbuf);
+  }
+
+  /* Bail early if we had nothing to write */
+  if (smartlist_len(chunks) == 0) {
+    goto done;
+  }
+
+  result = smartlist_join_strings(chunks, "\n", 0, NULL);
+
+ done:
+  SMARTLIST_FOREACH(chunks, char *, cp, tor_free(cp));
+  smartlist_free(chunks);
+  return result;
+}
+
+/** Round down the time in `a` to the beginning of the current hour */
+#define SET_TO_START_OF_HOUR(a) STMT_BEGIN \
+  (a) = approx_time() - (approx_time() % 3600); \
+STMT_END
+
+/** Note down an overload event of type `overload`. */
+void
+rep_hist_note_overload(overload_type_t overload)
+{
+  static time_t last_read_counted = 0;
+  static time_t last_write_counted = 0;
+
+  switch (overload) {
+  case OVERLOAD_GENERAL:
+    SET_TO_START_OF_HOUR(overload_stats.overload_general_time);
+    break;
+  case OVERLOAD_READ: {
+    SET_TO_START_OF_HOUR(overload_stats.overload_ratelimits_time);
+    if (approx_time() >= last_read_counted + 60) { /* Count once a minute */
+        overload_stats.overload_read_count++;
+        last_read_counted = approx_time();
+    }
+    break;
+  }
+  case OVERLOAD_WRITE: {
+    SET_TO_START_OF_HOUR(overload_stats.overload_ratelimits_time);
+    if (approx_time() >= last_write_counted + 60) { /* Count once a minute */
+      overload_stats.overload_write_count++;
+      last_write_counted = approx_time();
+    }
+    break;
+  }
+  case OVERLOAD_FD_EXHAUSTED:
+    SET_TO_START_OF_HOUR(overload_stats.overload_fd_exhausted_time);
+    overload_stats.overload_fd_exhausted++;
+    break;
+  }
+}
+
 /** Return the or_history_t for the OR with identity digest <b>id</b>,
  * creating it if necessary. */
 static or_history_t *

src/feature/stats/rephist.h

@@ -140,6 +140,24 @@ void rep_hist_reset_padding_counts(void);
 void rep_hist_prep_published_padding_counts(time_t now);
 void rep_hist_padding_count_timers(uint64_t num_timers);
 
+/**
+ * Represents the various types of overload we keep track of and expose in our
+ * extra-info descriptor.
+*/
+typedef enum {
+  /* A general overload -- can have many different causes. */
+  OVERLOAD_GENERAL,
+  /* We went over our configured read rate/burst bandwidth limit */
+  OVERLOAD_READ,
+  /* We went over our configured write rate/burst bandwidth limit */
+  OVERLOAD_WRITE,
+  /* We exhausted the file descriptors in this system */
+  OVERLOAD_FD_EXHAUSTED,
+} overload_type_t;
+
+void rep_hist_note_overload(overload_type_t overload);
+char *rep_hist_get_overload_stats_lines(void);
+
 #ifdef TOR_UNIT_TESTS
 struct hs_v2_stats_t;
 const struct hs_v2_stats_t *rep_hist_get_hs_v2_stats(void);