heartbeat: Log the number of circuits killed because too many cells

We recently merged a circuit cell queue size safeguard. This commit adds the
number of killed circuits that have reached the limit to the DoS heartbeat. It
now looks like this:

  [notice] DoS mitigation since startup: 0 circuits killed with too many
  cells. 0 circuits rejected, 0 marked addresses. 0 connections closed. 0
  single hop clients refused.

Second thing that this patch does. It makes tor always print the DoS
mitigation heartbeat line (for a relay) even though no DoS mitigation have
been enabled. The reason is because we now kill circuits that have too many
cells regardless on if it is enabled or not but also it will give the operator
a chance to learn what is enabled with the heartbeat instead of suddenly
appearing when it is enabled by let say the consensus.

Fixes #25824

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

diff --git a/src/or/dos.c b/src/or/dos.c
index 4d1797eece77f3faf3c591f6721af3334331f97c..2cb3470582b14b87bf71fdbf9ed84a37f95f5f85 100644 (file)
--- a/src/or/dos.c
+++ b/src/or/dos.c
@@ -15,6 +15,7 @@
 #include "main.h"
 #include "networkstatus.h"
 #include "nodelist.h"
+#include "relay.h"
 #include "router.h"
 
 #include "dos.h"
@@ -622,10 +623,12 @@ dos_log_heartbeat(void)
   char *conn_msg = NULL;
   char *cc_msg = NULL;
   char *single_hop_client_msg = NULL;
+  char *circ_stats_msg = NULL;
 
-  if (!dos_is_enabled()) {
-    goto end;
-  }
+  /* Stats number coming from relay.c append_cell_to_circuit_queue(). */
+  tor_asprintf(&circ_stats_msg,
+               " %" PRIu64 " circuits killed with too many cells.",
+               stats_n_circ_max_cell_reached);
 
   if (dos_cc_enabled) {
     tor_asprintf(&cc_msg,
@@ -647,7 +650,8 @@ dos_log_heartbeat(void)
   }
 
   log_notice(LD_HEARTBEAT,
-             "DoS mitigation since startup:%s%s%s",
+             "DoS mitigation since startup:%s%s%s%s",
+             circ_stats_msg,
              (cc_msg != NULL) ? cc_msg : " [cc not enabled]",
              (conn_msg != NULL) ? conn_msg : " [conn not enabled]",
              (single_hop_client_msg != NULL) ? single_hop_client_msg : "");
@@ -655,8 +659,7 @@ dos_log_heartbeat(void)
   tor_free(conn_msg);
   tor_free(cc_msg);
   tor_free(single_hop_client_msg);
-
- end:
+  tor_free(circ_stats_msg);
   return;
 }
 

diff --git a/src/or/relay.c b/src/or/relay.c
index 5a3c43e05865d6ddec069e6bd899c75dd5dfd9e8..b3571d6cdf42b5958dcbfd853cdab34acde832f8 100644 (file)
--- a/src/or/relay.c
+++ b/src/or/relay.c
@@ -115,6 +115,9 @@ uint64_t stats_n_relay_cells_relayed = 0;
  * hop?
  */
 uint64_t stats_n_relay_cells_delivered = 0;
+/** Stats: how many circuits have we closed due to the cell queue limit being
+ * reached (see append_cell_to_circuit_queue()) */
+uint64_t stats_n_circ_max_cell_reached = 0;
 
 /** Used to tell which stream to read from first on a circuit. */
 static tor_weak_rng_t stream_choice_rng = TOR_WEAK_RNG_INIT;
@@ -3041,6 +3044,7 @@ append_cell_to_circuit_queue(circuit_t *circ, channel_t *chan,
            (exitward) ? "Outbound" : "Inbound", queue->n,
            max_circuit_cell_queue_size);
     circuit_mark_for_close(circ, END_CIRC_REASON_RESOURCELIMIT);
+    stats_n_circ_max_cell_reached++;
     return;
   }
 

diff --git a/src/or/relay.h b/src/or/relay.h
index c9281c5eaea24375bc5a779e9e31920d07c4a3c7..e96639170c5502dbe7aa4d57f6c5ecbf5669456e 100644 (file)
--- a/src/or/relay.h
+++ b/src/or/relay.h
@@ -14,6 +14,7 @@
 
 extern uint64_t stats_n_relay_cells_relayed;
 extern uint64_t stats_n_relay_cells_delivered;
+extern uint64_t stats_n_circ_max_cell_reached;
 
 void relay_consensus_has_changed(const networkstatus_t *ns);
 int circuit_receive_relay_cell(cell_t *cell, circuit_t *circ,

diff --git a/src/test/test_status.c b/src/test/test_status.c
index 50ea203e4d79ad0f62dbb04d22eeb7a9f429eb35..b4ca17891bb6d874f6da34b0508681fb7082d9d8 100644 (file)
--- a/src/test/test_status.c
+++ b/src/test/test_status.c
@@ -340,7 +340,7 @@ NS(test_main)(void *arg)
   actual = log_heartbeat(0);
 
   tt_int_op(actual, OP_EQ, expected);
-  tt_int_op(CALLED(logv), OP_EQ, 5);
+  tt_int_op(CALLED(logv), OP_EQ, 6);
 
   done:
     NS_UNMOCK(tls_get_write_overhead_ratio);
@@ -439,6 +439,16 @@ NS(logv)(int severity, log_domain_mask_t domain,
       tt_ptr_op(strstr(funcname, "rep_hist_log_link_protocol_counts"),
                 OP_NE, NULL);
       break;
+    case 5:
+      tt_int_op(severity, OP_EQ, LOG_NOTICE);
+      tt_int_op(domain, OP_EQ, LD_HEARTBEAT);
+      tt_str_op(format, OP_EQ, "DoS mitigation since startup:%s%s%s%s");
+      tt_str_op(va_arg(ap, char *), OP_EQ,
+                " 0 circuits killed with too many cells.");
+      tt_str_op(va_arg(ap, char *), OP_EQ, " [cc not enabled]");
+      tt_str_op(va_arg(ap, char *), OP_EQ, " [conn not enabled]");
+      tt_str_op(va_arg(ap, char *), OP_EQ, "");
+      break;
     default:
       tt_abort_msg("unexpected call to logv()");  // TODO: prettyprint args
       break;