relay: Overload state on DNS timeout is now X% over Y secs

With this commit, we will only report a general overload state if we've
seen more than X% of DNS timeout errors over Y seconds. Previous
behavior was to report when a single timeout occured which is really too
small of a threshold.

The value X is a consensus parameters called
"overload_dns_timeout_scale_percent" which is a scaled percentage
(factor of 1000) so we can represent decimal points for X like 0.5% for
instance. Its default is 1000 which ends up being 1%.

The value Y is a consensus parameters called
"overload_dns_timeout_period_secs" which is the time period for which
will gather DNS errors and once over, we assess if that X% has been
reached ultimately triggering a general overload signal.

Closes #40491

Signed-off-by: David Goulet <dgoulet@torproject.org>

changes/ticket40491

@@ -0,0 +1,7 @@
+  o Major bugfixes (relay, overload state):
+    - Report the general overload state for DNS timeout errors only if X% of all
+      DNS queries over Y seconds are errors. Before that, it only took 1 timeout
+      to report the overload state which was just too low of a threshold. The X
+      and Y values are 1% and 10 minutes respectively but they are also
+      controlled by consensus parameters. Fixes bug 40491; bugfix on
+      0.4.6.1-alpha.

src/feature/nodelist/networkstatus.c

@@ -105,6 +105,7 @@
 #include "feature/dirauth/vote_microdesc_hash_st.h"
 #include "feature/nodelist/vote_routerstatus_st.h"
 #include "feature/nodelist/routerstatus_st.h"
+#include "feature/stats/rephist.h"
 
 #ifdef HAVE_UNISTD_H
 #include <unistd.h>
@@ -1665,6 +1666,7 @@ notify_before_networkstatus_changes(const networkstatus_t *old_c,
   dos_consensus_has_changed(new_c);
   relay_consensus_has_changed(new_c);
   hs_dos_consensus_has_changed(new_c);
+  rep_hist_consensus_has_changed(new_c);
 }
 
 /* Called after a new consensus has been put in the global state. It is safe

src/feature/stats/rephist.c

@@ -219,6 +219,59 @@ static uint64_t stats_n_tcp_exhaustion = 0;
 
 /***** DNS statistics *****/
 
+/* We use a scale here so we can represent percentages with decimal points by
+ * scaling the value by this factor and so 0.5% becomes a value of 500.
+ * Default is 1% and thus min and max range is 0 to 100%. */
+#define OVERLOAD_DNS_TIMEOUT_PERCENT_SCALE 1000.0
+#define OVERLOAD_DNS_TIMEOUT_PERCENT_DEFAULT 1000
+#define OVERLOAD_DNS_TIMEOUT_PERCENT_MIN 0
+#define OVERLOAD_DNS_TIMEOUT_PERCENT_MAX 100000
+
+/** Consensus parameter: indicate what fraction of DNS timeout errors over the
+ * total number of DNS requests must be reached before we trigger a general
+ * overload signal .*/
+static double overload_dns_timeout_fraction =
+   OVERLOAD_DNS_TIMEOUT_PERCENT_DEFAULT /
+   OVERLOAD_DNS_TIMEOUT_PERCENT_SCALE / 100.0;
+
+/* Number of seconds for the assessment period. Default is 10 minutes (600) and
+ * the min max range is within a 32bit value. */
+#define OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_DEFAULT (10 * 60)
+#define OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_MIN 0
+#define OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_MAX INT32_MAX
+
+/** Consensus parameter: Period, in seconds, over which we count the number of
+ * DNS requests and timeout errors. After that period, we assess if we trigger
+ * an overload or not. */
+static int32_t overload_dns_timeout_period_secs =
+  OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_DEFAULT;
+
+/** Overload DNS statistics. The information in this object is used to assess
+ * if, due to DNS errors, we should emit a general overload signal or not.
+ *
+ * NOTE: This structure is _not_ per DNS query type like the statistics below
+ * because of a libevent bug
+ * (https://github.com/libevent/libevent/issues/1219), on error, the type is
+ * not propagated up back to the user and so we need to keep our own stats for
+ * the overload signal. */
+typedef struct {
+  /** Total number of DNS request seen at an Exit. They might not all end
+   * successfully or might even be lost by tor. This counter is incremented
+   * right before the DNS request is initiated. */
+  uint64_t stats_n_request;
+
+  /** Total number of DNS timeout errors. */
+  uint64_t stats_n_error_timeout;
+
+  /** When is the next assessment time of the general overload for DNS errors.
+   * Once this time is reached, all stats are reset and this time is set to the
+   * next assessment time. */
+  time_t next_assessment_time;
+} overload_dns_stats_t;
+
+/** Keep track of the DNS requests for the general overload state. */
+static overload_dns_stats_t overload_dns_stats;
+
 /** Represents the statistics of DNS queries seen if it is an Exit. */
 typedef struct {
   /* Total number of DNS errors found in RFC 1035 (from 0 to 5 code). */
@@ -266,6 +319,60 @@ get_dns_stats_by_type(const int type)
   }
 }
 
+/** Assess the DNS timeout errors and if we have enough to trigger a general
+ * overload. */
+static void
+overload_general_dns_assessment(void)
+{
+  /* Initialize the time. Should be done once. */
+  if (overload_dns_stats.next_assessment_time == 0) {
+    goto reset;
+  }
+
+  /* Not the time yet. */
+  if (overload_dns_stats.next_assessment_time > approx_time()) {
+    return;
+  }
+
+  /* Lets see if we can signal a general overload. */
+  double fraction = (double) overload_dns_stats.stats_n_error_timeout /
+                    (double) overload_dns_stats.stats_n_request;
+  if (fraction >= overload_dns_timeout_fraction) {
+    log_notice(LD_HIST, "General overload -> DNS timeouts (%" PRIu64 ") "
+               "fraction %.4f%% is above threshold of %.4f%%",
+               overload_dns_stats.stats_n_error_timeout,
+               fraction * 100.0,
+               overload_dns_timeout_fraction * 100.0);
+    rep_hist_note_overload(OVERLOAD_GENERAL);
+  }
+
+ reset:
+  /* Reset counters for the next period. */
+  overload_dns_stats.stats_n_error_timeout = 0;
+  overload_dns_stats.stats_n_request = 0;
+  overload_dns_stats.next_assessment_time =
+    approx_time() + overload_dns_timeout_period_secs;
+}
+
+/** Called just before the consensus will be replaced. Update the consensus
+ * parameters in case they changed. */
+void
+rep_hist_consensus_has_changed(const networkstatus_t *ns)
+{
+  overload_dns_timeout_fraction =
+    networkstatus_get_param(ns, "overload_dns_timeout_scale_percent",
+                            OVERLOAD_DNS_TIMEOUT_PERCENT_DEFAULT,
+                            OVERLOAD_DNS_TIMEOUT_PERCENT_MIN,
+                            OVERLOAD_DNS_TIMEOUT_PERCENT_MAX) /
+    OVERLOAD_DNS_TIMEOUT_PERCENT_SCALE / 100.0;
+
+  overload_dns_timeout_period_secs =
+    networkstatus_get_param(ns, "overload_dns_timeout_period_secs",
+                            OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_DEFAULT,
+                            OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_MIN,
+                            OVERLOAD_DNS_TIMEOUT_PERIOD_SECS_MAX);
+}
+
 /** Return the DNS error count for the given libevent DNS type and error code.
  * The possible types are: DNS_IPv4_A, DNS_PTR, DNS_IPv6_AAAA. */
 uint64_t
@@ -320,10 +427,31 @@ rep_hist_get_n_dns_request(int type)
 }
 
 /** Note a DNS error for the given given libevent DNS record type and error
- * code. Possible types are: DNS_IPv4_A, DNS_PTR, DNS_IPv6_AAAA. */
+ * code. Possible types are: DNS_IPv4_A, DNS_PTR, DNS_IPv6_AAAA.
+ *
+ * NOTE: Libevent is _not_ returning the type in case of an error and so if
+ * error is anything but DNS_ERR_NONE, the type is not usable and set to 0.
+ *
+ * See: https://gitlab.torproject.org/tpo/core/tor/-/issues/40490 */
 void
 rep_hist_note_dns_error(int type, uint8_t error)
 {
+  /* Assess if we need to trigger a general overload with regards to the DNS
+   * errors or not. */
+  overload_general_dns_assessment();
+
+  /* Because of the libevent problem (see note in the function comment), we
+   * disregard the DNS query type and keep track of DNS timeout for the
+   * overload state. */
+  if (error == DNS_ERR_TIMEOUT) {
+    overload_dns_stats.stats_n_error_timeout++;
+  }
+  overload_dns_stats.stats_n_request++;
+
+  /* Again, the libevent bug (see function comment), for an error that is
+   * anything but DNS_ERR_NONE, the type is always 0 which means that we don't
+   * have a DNS stat object for it so this code will do nothing until libevent
+   * is fixed. */
   dns_stats_t *dns_stats = get_dns_stats_by_type(type);
   /* Unsupported DNS query type. */
   if (!dns_stats) {

src/feature/stats/rephist.h

@@ -89,6 +89,8 @@ uint64_t rep_hist_get_n_dns_request(int type);
 void rep_hist_note_dns_request(int type);
 void rep_hist_note_dns_error(int type, uint8_t error);
 
+void rep_hist_consensus_has_changed(const networkstatus_t *ns);
+
 extern uint64_t rephist_total_alloc;
 extern uint32_t rephist_total_num;
 #ifdef TOR_UNIT_TESTS

src/test/test_stats.c

@@ -51,6 +51,8 @@
 #include "feature/stats/bw_array_st.h"
 #include "feature/relay/router.h"
 
+#include <event2/dns.h>
+
 /** Run unit tests for some stats code. */
 static void
 test_stats(void *arg)
@@ -865,6 +867,81 @@ test_overload_stats(void *arg)
   tor_free(stats_str);
 }
 
+/** Test the overload stats logic. */
+static void
+test_overload_dns_timeout(void *arg)
+{
+  char *stats_str = NULL;
+  (void) arg;
+
+  /* Lets simulate a series of timeouts but below our default 1% threshold. */
+
+  for (int i = 0; i < 1000; i++) {
+    /* This should trigger 9 timeouts which is just below 1% (10) */
+    if (i > 0 && !(i % 100)) {
+      rep_hist_note_dns_error(0, DNS_ERR_TIMEOUT);
+    } else {
+      rep_hist_note_dns_error(0, DNS_ERR_NONE);
+    }
+  }
+
+  /* No overload yet. */
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(!stats_str);
+
+  /* Move it 10 minutes in the future and see if we get a general overload. */
+  update_approx_time(approx_time() + (10 * 60));
+
+  /* This query should NOT trigger the general overload because we are below
+   * our default of 1%. */
+  rep_hist_note_dns_error(0, DNS_ERR_NONE);
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(!stats_str);
+
+  /* We'll now go above our 1% threshold. */
+  for (int i = 0; i < 1000; i++) {
+    /* This should trigger 10 timeouts which is our threshold of 1% (10) */
+    if (!(i % 10)) {
+      rep_hist_note_dns_error(0, DNS_ERR_TIMEOUT);
+    } else {
+      rep_hist_note_dns_error(0, DNS_ERR_NONE);
+    }
+  }
+
+  /* Move it 10 minutes in the future and see if we get a general overload. */
+  update_approx_time(approx_time() + (10 * 60));
+
+  /* This query should trigger the general overload because we are above 1%. */
+  rep_hist_note_dns_error(0, DNS_ERR_NONE);
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(stats_str);
+  tor_free(stats_str);
+
+  /* Move 72h in the future, we should NOT get an overload anymore. */
+  update_approx_time(approx_time() + (72 * 3600));
+
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(!stats_str);
+
+  /* This query should NOT trigger the general overload. */
+  rep_hist_note_dns_error(0, DNS_ERR_TIMEOUT);
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(!stats_str);
+
+  /* Move it 10 minutes in the future and see if we get a general overload. We
+   * have now 100% of requests timing out. */
+  update_approx_time(approx_time() + (10 * 60));
+
+  /* This query should trigger the general overload with 50% of timeouts. */
+  rep_hist_note_dns_error(0, DNS_ERR_NONE);
+  stats_str = rep_hist_get_overload_general_line();
+  tt_assert(stats_str);
+  tor_free(stats_str);
+
+ done:
+  tor_free(stats_str);
+}
+
 #define ENT(name)                                                       \
   { #name, test_ ## name , 0, NULL, NULL }
 #define FORK(name)                                                      \
@@ -881,6 +958,7 @@ struct testcase_t stats_tests[] = {
   FORK(rephist_v3_onions),
   FORK(load_stats_file),
   FORK(overload_stats),
+  FORK(overload_dns_timeout),
 
   END_OF_TESTCASES
 };