summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
Diffstat (limited to 'src')
-rw-r--r--src/core/mainloop/connection.c6
-rw-r--r--src/core/or/channel.c2
-rw-r--r--src/core/or/channel.h3
-rw-r--r--src/core/or/channeltls.c7
-rw-r--r--src/core/or/or_circuit_st.h4
-rw-r--r--src/core/or/status.c41
-rw-r--r--src/core/or/status.h1
-rw-r--r--src/feature/client/bridges.c6
-rw-r--r--src/feature/client/entrynodes.c6
-rw-r--r--src/feature/hs/hs_dos.c5
-rw-r--r--src/feature/hs/hs_intropoint.c5
-rw-r--r--src/feature/relay/circuitbuild_relay.c24
-rw-r--r--src/feature/relay/router.c25
-rw-r--r--src/feature/relay/router.h1
-rw-r--r--src/lib/log/ratelim.c12
-rw-r--r--src/lib/log/ratelim.h8
-rw-r--r--src/test/test_logging.c6
-rw-r--r--src/test/test_status.c341
18 files changed, 208 insertions, 295 deletions
diff --git a/src/core/mainloop/connection.c b/src/core/mainloop/connection.c
index 7f4c6a5f48..82886ccd0b 100644
--- a/src/core/mainloop/connection.c
+++ b/src/core/mainloop/connection.c
@@ -82,6 +82,7 @@
#include "core/or/policies.h"
#include "core/or/reasons.h"
#include "core/or/relay.h"
+#include "core/or/status.h"
#include "core/or/crypt_path.h"
#include "core/proto/proto_haproxy.h"
#include "core/proto/proto_http.h"
@@ -2042,6 +2043,9 @@ connection_handle_listener_read(connection_t *conn, int new_type)
connection_mark_for_close(newconn);
return 0;
}
+
+ note_connection(true /* inbound */, conn->socket_family);
+
return 0;
}
@@ -2213,6 +2217,8 @@ connection_connect_sockaddr,(connection_t *conn,
}
}
+ note_connection(false /* outbound */, conn->socket_family);
+
/* it succeeded. we're connected. */
log_fn(inprogress ? LOG_DEBUG : LOG_INFO, LD_NET,
"Connection to socket %s (sock "TOR_SOCKET_T_FORMAT").",
diff --git a/src/core/or/channel.c b/src/core/or/channel.c
index 91f083ec00..d082174dc8 100644
--- a/src/core/or/channel.c
+++ b/src/core/or/channel.c
@@ -871,6 +871,8 @@ channel_init(channel_t *chan)
/* Channel is not in the scheduler heap. */
chan->sched_heap_idx = -1;
+
+ tor_addr_make_unspec(&chan->addr_according_to_peer);
}
/**
diff --git a/src/core/or/channel.h b/src/core/or/channel.h
index 10b80aa7d5..606b0730b8 100644
--- a/src/core/or/channel.h
+++ b/src/core/or/channel.h
@@ -236,6 +236,9 @@ struct channel_t {
/** The handle to this channel (to free on canceled timers) */
struct channel_handle_t *timer_handle;
+ /** If not UNSPEC, the address that the peer says we have. */
+ tor_addr_t addr_according_to_peer;
+
/**
* These two fields specify the minimum and maximum negotiated timeout
* values for inactivity (send or receive) before we decide to pad a
diff --git a/src/core/or/channeltls.c b/src/core/or/channeltls.c
index 51b772728e..a0debf8d22 100644
--- a/src/core/or/channeltls.c
+++ b/src/core/or/channeltls.c
@@ -1856,6 +1856,13 @@ channel_tls_process_netinfo_cell(cell_t *cell, channel_tls_t *chan)
}
}
+ if (me) {
+ /* We have a descriptor, so we are a relay: record the address that the
+ * other side said we had. */
+ tor_addr_copy(&TLS_CHAN_TO_BASE(chan)->addr_according_to_peer,
+ &my_apparent_addr);
+ }
+
n_other_addrs = netinfo_cell_get_n_my_addrs(netinfo_cell);
for (uint8_t i = 0; i < n_other_addrs; i++) {
/* Consider all the other addresses; if any matches, this connection is
diff --git a/src/core/or/or_circuit_st.h b/src/core/or/or_circuit_st.h
index 9bfe999728..4e17b1c143 100644
--- a/src/core/or/or_circuit_st.h
+++ b/src/core/or/or_circuit_st.h
@@ -75,6 +75,10 @@ struct or_circuit_t {
/** If set, the DoS defenses are enabled on this circuit meaning that the
* introduce2_bucket is initialized and used. */
unsigned int introduce2_dos_defense_enabled : 1;
+ /** If set, the DoS defenses were explicitly enabled through the
+ * ESTABLISH_INTRO cell extension. If unset, the consensus is used to learn
+ * if the defenses can be enabled or not. */
+ unsigned int introduce2_dos_defense_explicit : 1;
/** INTRODUCE2 cell bucket controlling how much can go on this circuit. Only
* used if this is a service introduction circuit at the intro point
diff --git a/src/core/or/status.c b/src/core/or/status.c
index ed8448883c..00a88a3178 100644
--- a/src/core/or/status.c
+++ b/src/core/or/status.c
@@ -113,6 +113,41 @@ log_onion_service_stats(void)
hs_stats_get_n_rendezvous_launches());
}
+/**
+ * @name connection counts for heartbeat
+ *
+ * Tracks incoming and outgoing connections on IPv4/IPv6, for heartbeat
+ * logs.
+ **/
+/**@{*/
+static unsigned n_incoming_ipv4;
+static unsigned n_incoming_ipv6;
+static unsigned n_outgoing_ipv4;
+static unsigned n_outgoing_ipv6;
+/**@}*/
+
+/**
+ * Note that a connection has arrived or has been made, for use in the
+ * heartbeat message.
+ **/
+void
+note_connection(bool inbound, int family)
+{
+ if (family == AF_INET) {
+ if (inbound) {
+ ++n_incoming_ipv4;
+ } else {
+ ++n_outgoing_ipv4;
+ }
+ } else if (family == AF_INET6) {
+ if (inbound) {
+ ++n_incoming_ipv6;
+ } else {
+ ++n_outgoing_ipv6;
+ }
+ }
+}
+
/** Log a "heartbeat" message describing Tor's status and history so that the
* user can know that there is indeed a running Tor. Return 0 on success and
* -1 on failure. */
@@ -143,8 +178,12 @@ log_heartbeat(time_t now)
bw_sent = bytes_to_usage(get_bytes_written());
log_fn(LOG_NOTICE, LD_HEARTBEAT, "Heartbeat: Tor's uptime is %s, with %d "
- "circuits open. I've sent %s and received %s.%s",
+ "circuits open. I've sent %s and received %s. I've received %u "
+ "connections on IPv4 and %u on IPv6. I've made %u connections "
+ "with IPv4 and %u with IPv6.%s",
uptime, count_circuits(), bw_sent, bw_rcvd,
+ n_incoming_ipv4, n_incoming_ipv6,
+ n_outgoing_ipv4, n_outgoing_ipv6,
hibernating?" We are currently hibernating.":"");
dirclient_dump_total_dls();
diff --git a/src/core/or/status.h b/src/core/or/status.h
index 639f8cdf51..271e0dbc9a 100644
--- a/src/core/or/status.h
+++ b/src/core/or/status.h
@@ -11,6 +11,7 @@
#include "lib/testsupport/testsupport.h"
+void note_connection(bool inbound, int family);
int log_heartbeat(time_t now);
#ifdef STATUS_PRIVATE
diff --git a/src/feature/client/bridges.c b/src/feature/client/bridges.c
index cc17e8fa67..59f79219cf 100644
--- a/src/feature/client/bridges.c
+++ b/src/feature/client/bridges.c
@@ -249,8 +249,8 @@ get_configured_bridge_by_exact_addr_port_digest(const tor_addr_t *addr,
* address/port matches only. */
int
addr_is_a_configured_bridge(const tor_addr_t *addr,
- uint16_t port,
- const char *digest)
+ uint16_t port,
+ const char *digest)
{
tor_assert(addr);
return get_configured_bridge_by_addr_port_digest(addr, port, digest) ? 1 : 0;
@@ -596,7 +596,7 @@ find_transport_name_by_bridge_addrport(const tor_addr_t *addr, uint16_t port)
*/
int
get_transport_by_bridge_addrport(const tor_addr_t *addr, uint16_t port,
- const transport_t **transport)
+ const transport_t **transport)
{
*transport = NULL;
if (!bridge_list)
diff --git a/src/feature/client/entrynodes.c b/src/feature/client/entrynodes.c
index c51958acec..2104a622da 100644
--- a/src/feature/client/entrynodes.c
+++ b/src/feature/client/entrynodes.c
@@ -3139,9 +3139,9 @@ entry_guard_parse_from_state(const char *s)
guard->sampled_idx = guard->confirmed_idx;
} else {
- log_warn(LD_GUARD, "The state file seems to be into a status that could"
- " yield to weird entry node selection: we're missing both a"
- " sampled_idx and a confirmed_idx.");
+ log_info(LD_GUARD, "The state file seems to be into a status that could"
+ " yield to weird entry node selection: we're missing both a"
+ " sampled_idx and a confirmed_idx.");
guard->sampled_idx = invalid_sampled_idx++;
}
diff --git a/src/feature/hs/hs_dos.c b/src/feature/hs/hs_dos.c
index 1f7415a280..04c2bfbb89 100644
--- a/src/feature/hs/hs_dos.c
+++ b/src/feature/hs/hs_dos.c
@@ -93,6 +93,11 @@ update_intro_circuits(void)
smartlist_t *intro_circs = hs_circuitmap_get_all_intro_circ_relay_side();
SMARTLIST_FOREACH_BEGIN(intro_circs, circuit_t *, circ) {
+ /* Ignore circuit if the defenses were set explicitly through the
+ * ESTABLISH_INTRO cell DoS extension. */
+ if (TO_OR_CIRCUIT(circ)->introduce2_dos_defense_explicit) {
+ continue;
+ }
/* Defenses might have been enabled or disabled. */
TO_OR_CIRCUIT(circ)->introduce2_dos_defense_enabled =
consensus_param_introduce_defense_enabled;
diff --git a/src/feature/hs/hs_intropoint.c b/src/feature/hs/hs_intropoint.c
index e282d1f1bd..69d60f21c3 100644
--- a/src/feature/hs/hs_intropoint.c
+++ b/src/feature/hs/hs_intropoint.c
@@ -285,6 +285,11 @@ handle_establish_intro_cell_dos_extension(
}
}
+ /* At this point, the extension is valid so any values out of it implies
+ * that it was set explicitly and thus flag the circuit that it should not
+ * look at the consensus for that reason for the defenses' values. */
+ circ->introduce2_dos_defense_explicit = 1;
+
/* A value of 0 is valid in the sense that we accept it but we still disable
* the defenses so return false. */
if (intro2_rate_per_sec == 0 || intro2_burst_per_sec == 0) {
diff --git a/src/feature/relay/circuitbuild_relay.c b/src/feature/relay/circuitbuild_relay.c
index ad20e143be..64f3c341ae 100644
--- a/src/feature/relay/circuitbuild_relay.c
+++ b/src/feature/relay/circuitbuild_relay.c
@@ -588,13 +588,23 @@ onionskin_answer(struct or_circuit_t *circ,
if ((!channel_is_local(circ->p_chan)
|| get_options()->ExtendAllowPrivateAddresses)
&& !channel_is_outgoing(circ->p_chan)) {
- /* record that we could process create cells from a non-local conn
- * that we didn't initiate; presumably this means that create cells
- * can reach us too. */
- tor_addr_t remote_addr;
- if (channel_get_addr_if_possible(circ->p_chan, &remote_addr)) {
- int family = tor_addr_family(&remote_addr);
- router_orport_found_reachable(family);
+ /* Okay, it's a create cell from a non-local connection
+ * that we didn't initiate. Presumably this means that create cells
+ * can reach us too. But what address can they reach us on? */
+ const tor_addr_t *my_supposed_addr = &circ->p_chan->addr_according_to_peer;
+ if (router_addr_is_my_published_addr(my_supposed_addr)) {
+ /* Great, this create cell came on connection where the peer says
+ * that the our address is an address we're actually advertising!
+ * That should mean that we're reachable. But before we finally
+ * declare ourselves reachable, make sure that the address listed
+ * by the peer is the same family as the peer is actually using.
+ */
+ tor_addr_t remote_addr;
+ int family = tor_addr_family(my_supposed_addr);
+ if (channel_get_addr_if_possible(circ->p_chan, &remote_addr) &&
+ tor_addr_family(&remote_addr) == family) {
+ router_orport_found_reachable(family);
+ }
}
}
diff --git a/src/feature/relay/router.c b/src/feature/relay/router.c
index 9bf0e7026f..11847a2616 100644
--- a/src/feature/relay/router.c
+++ b/src/feature/relay/router.c
@@ -1729,6 +1729,31 @@ router_is_me(const routerinfo_t *router)
return router_digest_is_me(router->cache_info.identity_digest);
}
+/**
+ * Return true if we are a server, and if @a addr is an address we are
+ * currently publishing (or trying to publish) in our descriptor.
+ * Return false otherwise.
+ **/
+bool
+router_addr_is_my_published_addr(const tor_addr_t *addr)
+{
+ IF_BUG_ONCE(!addr)
+ return false;
+
+ const routerinfo_t *me = router_get_my_routerinfo();
+ if (!me)
+ return false;
+
+ switch (tor_addr_family(addr)) {
+ case AF_INET:
+ return tor_addr_eq(addr, &me->ipv4_addr);
+ case AF_INET6:
+ return tor_addr_eq(addr, &me->ipv6_addr);
+ default:
+ return false;
+ }
+}
+
/** Return a routerinfo for this OR, rebuilding a fresh one if
* necessary. Return NULL on error, or if called on an OP. */
MOCK_IMPL(const routerinfo_t *,
diff --git a/src/feature/relay/router.h b/src/feature/relay/router.h
index 89b4a479a4..f71ada8eb7 100644
--- a/src/feature/relay/router.h
+++ b/src/feature/relay/router.h
@@ -100,6 +100,7 @@ int router_digest_is_me(const char *digest);
const uint8_t *router_get_my_id_digest(void);
int router_extrainfo_digest_is_me(const char *digest);
int router_is_me(const routerinfo_t *router);
+bool router_addr_is_my_published_addr(const tor_addr_t *addr);
int router_build_fresh_descriptor(routerinfo_t **r, extrainfo_t **e);
int router_rebuild_descriptor(int force);
char *router_dump_router_to_string(routerinfo_t *router,
diff --git a/src/lib/log/ratelim.c b/src/lib/log/ratelim.c
index ac401fb398..8dfaee3384 100644
--- a/src/lib/log/ratelim.c
+++ b/src/lib/log/ratelim.c
@@ -11,6 +11,7 @@
#include "lib/log/ratelim.h"
#include "lib/malloc/malloc.h"
#include "lib/string/printf.h"
+#include "lib/intmath/muldiv.h"
/** If the rate-limiter <b>lim</b> is ready at <b>now</b>, return the number
* of calls to rate_limit_is_ready (including this one!) since the last time
@@ -42,19 +43,24 @@ rate_limit_log(ratelim_t *lim, time_t now)
{
int n;
if ((n = rate_limit_is_ready(lim, now))) {
+ time_t started_limiting = lim->started_limiting;
+ lim->started_limiting = 0;
if (n == 1) {
return tor_strdup("");
} else {
char *cp=NULL;
const char *opt_over = (n >= RATELIM_TOOMANY) ? "over " : "";
- /* XXXX this is not exactly correct: the messages could have occurred
- * any time between the old value of lim->allowed and now. */
+ unsigned difference = (unsigned)(now - started_limiting);
+ difference = round_to_next_multiple_of(difference, 60);
tor_asprintf(&cp,
" [%s%d similar message(s) suppressed in last %d seconds]",
- opt_over, n-1, lim->rate);
+ opt_over, n-1, (int)difference);
return cp;
}
} else {
+ if (lim->started_limiting == 0) {
+ lim->started_limiting = now;
+ }
return NULL;
}
}
diff --git a/src/lib/log/ratelim.h b/src/lib/log/ratelim.h
index e9b55d40dc..9e202028cf 100644
--- a/src/lib/log/ratelim.h
+++ b/src/lib/log/ratelim.h
@@ -40,13 +40,19 @@
</pre>
*/
typedef struct ratelim_t {
+ /** How many seconds must elapse between log messages? */
int rate;
+ /** When did this limiter last allow a message to appear? */
time_t last_allowed;
+ /** When did this limiter start suppressing messages? */
+ time_t started_limiting;
+ /** How many messages has this limiter suppressed since it last allowed
+ * one to appear? */
int n_calls_since_last_time;
} ratelim_t;
#ifndef COCCI
-#define RATELIM_INIT(r) { (r), 0, 0 }
+#define RATELIM_INIT(r) { (r), 0, 0, 0 }
#endif
#define RATELIM_TOOMANY (16*1000*1000)
diff --git a/src/test/test_logging.c b/src/test/test_logging.c
index e09f7a21cd..58d0f24bd3 100644
--- a/src/test/test_logging.c
+++ b/src/test/test_logging.c
@@ -160,6 +160,7 @@ test_ratelim(void *arg)
tor_free(msg);
int i;
+ time_t first_suppressed_at = now + 60;
for (i = 0; i < 9; ++i) {
now += 60; /* one minute has passed. */
msg = rate_limit_log(&ten_min, now);
@@ -167,12 +168,15 @@ test_ratelim(void *arg)
tt_int_op(ten_min.last_allowed, OP_EQ, start);
tt_int_op(ten_min.n_calls_since_last_time, OP_EQ, i + 1);
}
+ tt_i64_op(ten_min.started_limiting, OP_EQ, first_suppressed_at);
now += 240; /* Okay, we can be done. */
msg = rate_limit_log(&ten_min, now);
tt_ptr_op(msg, OP_NE, NULL);
tt_str_op(msg, OP_EQ,
- " [9 similar message(s) suppressed in last 600 seconds]");
+ " [9 similar message(s) suppressed in last 720 seconds]");
+ tt_i64_op(now, OP_EQ, first_suppressed_at + 720);
+
done:
tor_free(msg);
}
diff --git a/src/test/test_status.c b/src/test/test_status.c
index 82afe0fd2a..b938b86326 100644
--- a/src/test/test_status.c
+++ b/src/test/test_status.c
@@ -26,6 +26,7 @@
#include "feature/nodelist/nodelist.h"
#include "app/config/statefile.h"
#include "lib/tls/tortls.h"
+#include "test/log_test_helpers.h"
#include "core/or/origin_circuit_st.h"
#include "app/config/or_state_st.h"
@@ -308,10 +309,6 @@ static int status_hb_not_in_consensus_public_server_mode(
static const routerinfo_t *status_hb_not_in_consensus_get_my_routerinfo(void);
static const node_t * status_hb_not_in_consensus_node_get_by_id(
const char *identity_digest);
-static void status_hb_not_in_consensus_logv(
- int severity, log_domain_mask_t domain, const char *funcname,
- const char *suffix, const char *format, va_list ap);
-static int status_hb_not_in_consensus_logv_called = 0;
static int status_hb_not_in_consensus_server_mode(const or_options_t *options);
static routerinfo_t *mock_routerinfo;
@@ -332,8 +329,6 @@ test_status_hb_not_in_consensus(void *arg)
status_hb_not_in_consensus_get_my_routerinfo);
MOCK(node_get_by_id,
status_hb_not_in_consensus_node_get_by_id);
- MOCK(logv,
- status_hb_not_in_consensus_logv);
MOCK(server_mode,
status_hb_not_in_consensus_server_mode);
@@ -344,18 +339,38 @@ test_status_hb_not_in_consensus(void *arg)
onion_handshakes_assigned[ONION_HANDSHAKE_TYPE_NTOR] = 1;
expected = 0;
+ setup_capture_of_logs(LOG_INFO);
actual = log_heartbeat(0);
-
tt_int_op(actual, OP_EQ, expected);
- tt_int_op(status_hb_not_in_consensus_logv_called, OP_EQ, 6);
- done:
+ expect_log_msg("Heartbeat: It seems like we are "
+ "not in the cached consensus.\n");
+ expect_log_msg("Heartbeat: Tor's uptime is 0:00 hours, "
+ "with 0 circuits open. "
+ "I've sent 0 kB and received 0 kB. "
+ "I've received 0 connections on IPv4 and 0 on IPv6. "
+ "I've made 0 connections with IPv4 and 0 with IPv6.\n");
+ expect_log_msg("Average packaged cell fullness: 100.000%. "
+ "TLS write overhead: 0%\n");
+ expect_log_msg("Circuit handshake stats since last time: 1/1 TAP, "
+ "1/1 NTor.\n");
+ expect_log_msg("Since startup we initiated 0 and received 0 v1 "
+ "connections; initiated 0 and received 0 v2 connections; "
+ "initiated 0 and received 0 v3 connections; "
+ "initiated 0 and received 0 v4 connections; "
+ "initiated 0 and received 0 v5 connections.\n");
+ expect_log_msg("DoS mitigation since startup: 0 circuits killed with "
+ "too many cells. [cc not enabled] [conn not enabled] "
+ "0 INTRODUCE2 rejected.\n");
+ tt_int_op(mock_saved_log_n_entries(), OP_EQ, 6);
+
+ done:
+ teardown_capture_of_logs();
UNMOCK(tls_get_write_overhead_ratio);
UNMOCK(we_are_hibernating);
UNMOCK(public_server_mode);
UNMOCK(router_get_my_routerinfo);
UNMOCK(node_get_by_id);
- UNMOCK(logv);
UNMOCK(server_mode);
tor_free(mock_routerinfo);
}
@@ -396,76 +411,6 @@ status_hb_not_in_consensus_node_get_by_id(const char *identity_digest)
return NULL;
}
-static void
-status_hb_not_in_consensus_logv(int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix, const char *format, va_list ap)
-{
- switch (status_hb_not_in_consensus_logv_called)
- {
- case 0:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: It seems like we are not in the cached consensus.");
- break;
- case 1:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Tor's uptime is %s, with %d circuits open. "
- "I've sent %s and received %s.%s");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:00 hours"); /* uptime */
- tt_int_op(va_arg(ap, int), OP_EQ, 0); /* count_circuits() */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, ""); /* hibernating */
- break;
- case 2:
- tt_int_op(severity, OP_EQ, LOG_INFO);
- break;
- case 3:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "rep_hist_log_circuit_handshake_stats"),
- OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Circuit handshake stats since last time: %d/%d TAP, %d/%d NTor.");
- tt_int_op(va_arg(ap, int), OP_EQ, 1); /* handshakes assigned (TAP) */
- tt_int_op(va_arg(ap, int), OP_EQ, 1); /* handshakes requested (TAP) */
- tt_int_op(va_arg(ap, int), OP_EQ, 1); /* handshakes assigned (NTOR) */
- tt_int_op(va_arg(ap, int), OP_EQ, 1); /* handshakes requested (NTOR) */
- break;
- case 4:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- 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_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_str_op(format, OP_EQ, "DoS mitigation since startup:%s%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, "");
- tt_str_op(va_arg(ap, char *), OP_EQ, " 0 INTRODUCE2 rejected.");
- break;
- default:
- tt_abort_msg("unexpected call to logv()"); // TODO: prettyprint args
- break;
- }
-
- done:
- status_hb_not_in_consensus_logv_called++;
-}
-
static int
status_hb_not_in_consensus_server_mode(const or_options_t *options)
{
@@ -485,14 +430,8 @@ static int status_hb_simple_public_server_mode(const or_options_t *options);
static long status_hb_simple_get_uptime(void);
static uint64_t status_hb_simple_get_bytes_read(void);
static uint64_t status_hb_simple_get_bytes_written(void);
-static void status_hb_simple_logv(int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix,
- const char *format, va_list ap);
-ATTR_UNUSED static int status_hb_simple_logv_called = 0;
static int status_hb_simple_server_mode(const or_options_t *options);
-static int status_hb_simple_n_msgs = 0;
-
static void
test_status_hb_simple(void *arg)
{
@@ -511,27 +450,32 @@ test_status_hb_simple(void *arg)
status_hb_simple_get_bytes_read);
MOCK(get_bytes_written,
status_hb_simple_get_bytes_written);
- MOCK(logv,
- status_hb_simple_logv);
MOCK(server_mode,
status_hb_simple_server_mode);
log_global_min_severity_ = LOG_DEBUG;
+ setup_capture_of_logs(LOG_INFO);
expected = 0;
actual = log_heartbeat(0);
tt_int_op(actual, OP_EQ, expected);
- tt_int_op(status_hb_simple_n_msgs, OP_EQ, 1);
+
+ expect_log_msg("Heartbeat: Tor's uptime is 0:00 hours, "
+ "with 0 circuits open. "
+ "I've sent 0 kB and received 0 kB. "
+ "I've received 0 connections on IPv4 and 0 on IPv6. "
+ "I've made 0 connections with IPv4 and 0 with IPv6. "
+ "We are currently hibernating.\n");
done:
+ teardown_capture_of_logs();
UNMOCK(tls_get_write_overhead_ratio);
UNMOCK(we_are_hibernating);
UNMOCK(public_server_mode);
UNMOCK(get_uptime);
UNMOCK(get_bytes_read);
UNMOCK(get_bytes_written);
- UNMOCK(logv);
UNMOCK(server_mode);
}
@@ -573,32 +517,6 @@ status_hb_simple_get_bytes_written(void)
return 0;
}
-static void
-status_hb_simple_logv(int severity, log_domain_mask_t domain,
- const char *funcname,
- const char *suffix, const char *format, va_list ap)
-{
- if (severity == LOG_INFO)
- return;
- ++status_hb_simple_n_msgs;
-
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Tor's uptime is %s, with %d circuits open. "
- "I've sent %s and received %s.%s");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:00 hours"); /* uptime */
- tt_int_op(va_arg(ap, int), OP_EQ, 0); /* count_circuits() */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, " We are currently hibernating.");
-
- done:
- ;
-}
-
static int
status_hb_simple_server_mode(const or_options_t *options)
{
@@ -620,11 +538,6 @@ static int status_hb_calls_log_accounting_public_server_mode(
static long status_hb_calls_log_accounting_get_uptime(void);
static uint64_t status_hb_calls_log_accounting_get_bytes_read(void);
static uint64_t status_hb_calls_log_accounting_get_bytes_written(void);
-static void status_hb_calls_log_accounting_logv(
- int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix,
- const char *format, va_list ap);
-static int status_hb_calls_log_accounting_logv_called = 0;
static int status_hb_calls_log_accounting_server_mode(
const or_options_t *options);
static or_state_t * status_hb_calls_log_accounting_get_or_state(void);
@@ -653,8 +566,6 @@ test_status_hb_calls_log_accounting(void *arg)
status_hb_calls_log_accounting_get_bytes_read);
MOCK(get_bytes_written,
status_hb_calls_log_accounting_get_bytes_written);
- MOCK(logv,
- status_hb_calls_log_accounting_logv);
MOCK(server_mode,
status_hb_calls_log_accounting_server_mode);
MOCK(get_or_state,
@@ -666,20 +577,31 @@ test_status_hb_calls_log_accounting(void *arg)
log_global_min_severity_ = LOG_DEBUG;
+ setup_capture_of_logs(LOG_NOTICE);
expected = 0;
actual = log_heartbeat(0);
tt_int_op(actual, OP_EQ, expected);
- tt_int_op(status_hb_calls_log_accounting_logv_called, OP_EQ, 3);
+
+ expect_log_msg("Heartbeat: Tor's uptime is 0:00 hours, "
+ "with 0 circuits open. "
+ "I've sent 0 kB and received 0 kB. "
+ "I've received 0 connections on IPv4 and 0 on IPv6. "
+ "I've made 0 connections with IPv4 and 0 with IPv6.\n");
+
+ expect_log_msg_containing("Heartbeat: Accounting enabled. Sent: 0 kB, "
+ "Received: 0 kB, Used: 0 kB / 0 kB, Rule: max. "
+ "The current accounting interval ends on ");
+ tt_int_op(mock_saved_log_n_entries(), OP_EQ, 2);
done:
+ teardown_capture_of_logs();
UNMOCK(tls_get_write_overhead_ratio);
UNMOCK(we_are_hibernating);
UNMOCK(public_server_mode);
UNMOCK(get_uptime);
UNMOCK(get_bytes_read);
UNMOCK(get_bytes_written);
- UNMOCK(logv);
UNMOCK(server_mode);
UNMOCK(accounting_is_enabled);
UNMOCK(accounting_get_end_time);
@@ -725,58 +647,6 @@ status_hb_calls_log_accounting_get_bytes_written(void)
return 0;
}
-static void
-status_hb_calls_log_accounting_logv(int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix, const char *format, va_list ap)
-{
- switch (status_hb_calls_log_accounting_logv_called)
- {
- case 0:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Tor's uptime is %s, with %d circuits open. "
- "I've sent %s and received %s.%s");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:00 hours"); /* uptime */
- tt_int_op(va_arg(ap, int), OP_EQ, 0); /* count_circuits() */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, ""); /* hibernating */
- break;
- case 1:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_accounting"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Accounting enabled. Sent: %s, Received: %s, Used: %s / "
- "%s, Rule: %s. The current accounting interval ends on %s, in %s.");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* acc_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* acc_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* acc_used */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* acc_max */
- tt_str_op(va_arg(ap, char *), OP_EQ, "max"); /* acc_rule */
- /* format_local_iso_time uses local tz, so we can't just compare
- * the string against a constant */
- char datetime[ISO_TIME_LEN+1];
- format_local_iso_time(datetime, 60);
- tt_str_op(va_arg(ap, char *), OP_EQ, datetime); /* end_buf */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:01 hours"); /* remaining */
- break;
- case 2:
- tt_int_op(severity, OP_EQ, LOG_INFO);
- break;
- default:
- tt_abort_msg("unexpected call to logv()"); // TODO: prettyprint args
- break;
- }
-
- done:
- status_hb_calls_log_accounting_logv_called++;
-}
-
static int
status_hb_calls_log_accounting_server_mode(const or_options_t *options)
{
@@ -826,11 +696,6 @@ static int status_hb_packaged_cell_fullness_public_server_mode(
static long status_hb_packaged_cell_fullness_get_uptime(void);
static uint64_t status_hb_packaged_cell_fullness_get_bytes_read(void);
static uint64_t status_hb_packaged_cell_fullness_get_bytes_written(void);
-static void status_hb_packaged_cell_fullness_logv(
- int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix,
- const char *format, va_list ap);
-static int status_hb_packaged_cell_fullness_logv_called = 0;
static int status_hb_packaged_cell_fullness_server_mode(
const or_options_t *options);
static int status_hb_packaged_cell_fullness_accounting_is_enabled(
@@ -854,8 +719,6 @@ test_status_hb_packaged_cell_fullness(void *arg)
status_hb_packaged_cell_fullness_get_bytes_read);
MOCK(get_bytes_written,
status_hb_packaged_cell_fullness_get_bytes_written);
- MOCK(logv,
- status_hb_packaged_cell_fullness_logv);
MOCK(server_mode,
status_hb_packaged_cell_fullness_server_mode);
MOCK(accounting_is_enabled,
@@ -865,12 +728,20 @@ test_status_hb_packaged_cell_fullness(void *arg)
stats_n_data_bytes_packaged = RELAY_PAYLOAD_SIZE;
stats_n_data_cells_packaged = 2;
expected = 0;
+ setup_capture_of_logs(LOG_INFO);
actual = log_heartbeat(0);
tt_int_op(actual, OP_EQ, expected);
- tt_int_op(status_hb_packaged_cell_fullness_logv_called, OP_EQ, 2);
+ expect_log_msg("Heartbeat: Tor's uptime is 0:00 hours, "
+ "with 0 circuits open. "
+ "I've sent 0 kB and received 0 kB. "
+ "I've received 0 connections on IPv4 and 0 on IPv6. "
+ "I've made 0 connections with IPv4 and 0 with IPv6.\n");
+ expect_log_msg("Average packaged cell fullness: 50.000%. "
+ "TLS write overhead: 0%\n");
done:
+ teardown_capture_of_logs();
stats_n_data_bytes_packaged = 0;
stats_n_data_cells_packaged = 0;
UNMOCK(tls_get_write_overhead_ratio);
@@ -879,7 +750,6 @@ test_status_hb_packaged_cell_fullness(void *arg)
UNMOCK(get_uptime);
UNMOCK(get_bytes_read);
UNMOCK(get_bytes_written);
- UNMOCK(logv);
UNMOCK(server_mode);
UNMOCK(accounting_is_enabled);
}
@@ -923,47 +793,6 @@ status_hb_packaged_cell_fullness_get_bytes_written(void)
return 0;
}
-static void
-status_hb_packaged_cell_fullness_logv(int severity,
- log_domain_mask_t domain, const char *funcname,
- const char *suffix, const char *format, va_list ap)
-{
- switch (status_hb_packaged_cell_fullness_logv_called)
- {
- case 0:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Tor's uptime is %s, with %d circuits open. "
- "I've sent %s and received %s.%s");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:00 hours"); /* uptime */
- tt_int_op(va_arg(ap, int), OP_EQ, 0); /* count_circuits() */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, ""); /* hibernating */
- break;
- case 1:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Average packaged cell fullness: %2.3f%%. "
- "TLS write overhead: %.f%%");
- tt_double_op(fabs(va_arg(ap, double) - 50.0), OP_LE, DBL_EPSILON);
- tt_double_op(fabs(va_arg(ap, double) - 0.0), OP_LE, DBL_EPSILON);
- break;
- default:
- tt_abort_msg("unexpected call to logv()"); // TODO: prettyprint args
- break;
- }
-
- done:
- status_hb_packaged_cell_fullness_logv_called++;
-}
-
static int
status_hb_packaged_cell_fullness_server_mode(const or_options_t *options)
{
@@ -993,11 +822,6 @@ static int status_hb_tls_write_overhead_public_server_mode(
static long status_hb_tls_write_overhead_get_uptime(void);
static uint64_t status_hb_tls_write_overhead_get_bytes_read(void);
static uint64_t status_hb_tls_write_overhead_get_bytes_written(void);
-static void status_hb_tls_write_overhead_logv(
- int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix,
- const char *format, va_list ap);
-static int status_hb_tls_write_overhead_logv_called = 0;
static int status_hb_tls_write_overhead_server_mode(
const or_options_t *options);
static int status_hb_tls_write_overhead_accounting_is_enabled(
@@ -1021,8 +845,6 @@ test_status_hb_tls_write_overhead(void *arg)
status_hb_tls_write_overhead_get_bytes_read);
MOCK(get_bytes_written,
status_hb_tls_write_overhead_get_bytes_written);
- MOCK(logv,
- status_hb_tls_write_overhead_logv);
MOCK(server_mode,
status_hb_tls_write_overhead_server_mode);
MOCK(accounting_is_enabled,
@@ -1031,19 +853,26 @@ test_status_hb_tls_write_overhead(void *arg)
log_global_min_severity_ = LOG_DEBUG;
expected = 0;
+ setup_capture_of_logs(LOG_NOTICE);
actual = log_heartbeat(0);
tt_int_op(actual, OP_EQ, expected);
- tt_int_op(status_hb_tls_write_overhead_logv_called, OP_EQ, 2);
+ expect_log_msg("Heartbeat: Tor's uptime is 0:00 hours, "
+ "with 0 circuits open. "
+ "I've sent 0 kB and received 0 kB. "
+ "I've received 0 connections on IPv4 and 0 on IPv6. "
+ "I've made 0 connections with IPv4 and 0 with IPv6.\n");
+ expect_log_msg("Average packaged cell fullness: 100.000%. "
+ "TLS write overhead: 100%\n");
done:
+ teardown_capture_of_logs();
UNMOCK(tls_get_write_overhead_ratio);
UNMOCK(we_are_hibernating);
UNMOCK(public_server_mode);
UNMOCK(get_uptime);
UNMOCK(get_bytes_read);
UNMOCK(get_bytes_written);
- UNMOCK(logv);
UNMOCK(server_mode);
UNMOCK(accounting_is_enabled);
}
@@ -1086,46 +915,6 @@ status_hb_tls_write_overhead_get_bytes_written(void)
return 0;
}
-static void
-status_hb_tls_write_overhead_logv(int severity, log_domain_mask_t domain,
- const char *funcname, const char *suffix, const char *format, va_list ap)
-{
- switch (status_hb_tls_write_overhead_logv_called)
- {
- case 0:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Heartbeat: Tor's uptime is %s, with %d circuits open. "
- "I've sent %s and received %s.%s");
- tt_str_op(va_arg(ap, char *), OP_EQ, "0:00 hours"); /* uptime */
- tt_int_op(va_arg(ap, int), OP_EQ, 0); /* count_circuits() */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_sent */
- tt_str_op(va_arg(ap, char *), OP_EQ, "0 kB"); /* bw_rcvd */
- tt_str_op(va_arg(ap, char *), OP_EQ, ""); /* hibernating */
- break;
- case 1:
- tt_int_op(severity, OP_EQ, LOG_NOTICE);
- tt_u64_op(domain, OP_EQ, LD_HEARTBEAT);
- tt_ptr_op(strstr(funcname, "log_heartbeat"), OP_NE, NULL);
- tt_ptr_op(suffix, OP_EQ, NULL);
- tt_str_op(format, OP_EQ,
- "Average packaged cell fullness: %2.3f%%. "
- "TLS write overhead: %.f%%");
- tt_int_op(fabs(va_arg(ap, double) - 100.0) <= DBL_EPSILON, OP_EQ, 1);
- tt_double_op(fabs(va_arg(ap, double) - 100.0), OP_LE, DBL_EPSILON);
- break;
- default:
- tt_abort_msg("unexpected call to logv()"); // TODO: prettyprint args
- break;
- }
-
- done:
- status_hb_tls_write_overhead_logv_called++;
-}
-
static int
status_hb_tls_write_overhead_server_mode(const or_options_t *options)
{