commit 93ff1870ba153332ab695e53d906da6a14a8097c Author: David Goulet <dgoulet@torproject.org> Date: Tue Apr 17 08:38:34 2018 -0400 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> --- src/or/dos.c | 15 +++++++++------ src/or/relay.c | 4 ++++ src/or/relay.h | 1 + src/test/test_status.c | 12 +++++++++++- 4 files changed, 25 insertions(+), 7 deletions(-) diff --git a/src/or/dos.c b/src/or/dos.c index 4d1797eec..2cb347058 100644 --- 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 5a3c43e05..b3571d6cd 100644 --- 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 c9281c5ea..e96639170 100644 --- 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 50ea203e4..b4ca17891 100644 --- 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;