diff options
Diffstat (limited to 'src/test/test_status.c')
| -rw-r--r-- | src/test/test_status.c | 823 |
1 files changed, 335 insertions, 488 deletions
diff --git a/src/test/test_status.c b/src/test/test_status.c index 9c47469975..b938b86326 100644 --- a/src/test/test_status.c +++ b/src/test/test_status.c @@ -1,4 +1,4 @@ -/* Copyright (c) 2014-2019, The Tor Project, Inc. */ +/* Copyright (c) 2014-2020, The Tor Project, Inc. */ /* See LICENSE for licensing information */ #define STATUS_PRIVATE @@ -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" @@ -33,10 +34,6 @@ #include "test/test.h" -#define NS_MODULE status - -#define NS_SUBMODULE count_circuits - /* * Test that count_circuits() is correctly counting the number of * global circuits. @@ -44,10 +41,10 @@ static smartlist_t * mock_global_circuitlist = NULL; -NS_DECL(smartlist_t *, circuit_get_global_list, (void)); +static smartlist_t * status_count_circuits_circuit_get_global_list(void); static void -NS(test_main)(void *arg) +test_status_count_circuits(void *arg) { /* Choose origin_circuit_t wlog. */ origin_circuit_t *mock_circuit1, *mock_circuit2; @@ -61,7 +58,8 @@ NS(test_main)(void *arg) smartlist_add(mock_global_circuitlist, TO_CIRCUIT(mock_circuit1)); smartlist_add(mock_global_circuitlist, TO_CIRCUIT(mock_circuit2)); - NS_MOCK(circuit_get_global_list); + MOCK(circuit_get_global_list, + status_count_circuits_circuit_get_global_list); actual_circuits = count_circuits(); @@ -72,25 +70,22 @@ NS(test_main)(void *arg) tor_free(mock_circuit2); smartlist_free(mock_global_circuitlist); mock_global_circuitlist = NULL; - NS_UNMOCK(circuit_get_global_list); + UNMOCK(circuit_get_global_list); } static smartlist_t * -NS(circuit_get_global_list)(void) +status_count_circuits_circuit_get_global_list(void) { return mock_global_circuitlist; } -#undef NS_SUBMODULE -#define NS_SUBMODULE secs_to_uptime - /* * Test that secs_to_uptime() is converting the number of seconds that * Tor is up for into the appropriate string form containing hours and minutes. */ static void -NS(test_main)(void *arg) +test_status_secs_to_uptime(void *arg) { const char *expected; char *actual; @@ -161,9 +156,6 @@ NS(test_main)(void *arg) tor_free(actual); } -#undef NS_SUBMODULE -#define NS_SUBMODULE bytes_to_usage - /* * Test that bytes_to_usage() is correctly converting the number of bytes that * Tor has read/written into the appropriate string form containing kilobytes, @@ -171,7 +163,7 @@ NS(test_main)(void *arg) */ static void -NS(test_main)(void *arg) +test_status_bytes_to_usage(void *arg) { const char *expected; char *actual; @@ -242,29 +234,30 @@ NS(test_main)(void *arg) tor_free(actual); } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, fails) - /* * Tests that log_heartbeat() fails when in the public server mode, * not hibernating, and we couldn't get the current routerinfo. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(const routerinfo_t *, router_get_my_routerinfo, (void)); +static double status_hb_fails_tls_get_write_overhead_ratio(void); +static int status_hb_fails_we_are_hibernating(void); +static int status_hb_fails_public_server_mode(const or_options_t *options); +static const routerinfo_t * status_hb_fails_router_get_my_routerinfo(void); static void -NS(test_main)(void *arg) +test_status_hb_fails(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(router_get_my_routerinfo); + MOCK(tls_get_write_overhead_ratio, + status_hb_fails_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_fails_we_are_hibernating); + MOCK(public_server_mode, + status_hb_fails_public_server_mode); + MOCK(router_get_my_routerinfo, + status_hb_fails_router_get_my_routerinfo); expected = -1; actual = log_heartbeat(0); @@ -272,26 +265,26 @@ NS(test_main)(void *arg) tt_int_op(actual, OP_EQ, expected); done: - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(router_get_my_routerinfo); + UNMOCK(tls_get_write_overhead_ratio); + UNMOCK(we_are_hibernating); + UNMOCK(public_server_mode); + UNMOCK(router_get_my_routerinfo); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_fails_tls_get_write_overhead_ratio(void) { return 2.0; } static int -NS(we_are_hibernating)(void) +status_hb_fails_we_are_hibernating(void) { return 0; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_fails_public_server_mode(const or_options_t *options) { (void)options; @@ -299,43 +292,45 @@ NS(public_server_mode)(const or_options_t *options) } static const routerinfo_t * -NS(router_get_my_routerinfo)(void) +status_hb_fails_router_get_my_routerinfo(void) { return NULL; } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, not_in_consensus) - /* * Tests that log_heartbeat() logs appropriately if we are not in the cached * consensus. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(const routerinfo_t *, router_get_my_routerinfo, (void)); -NS_DECL(const node_t *, node_get_by_id, (const char *identity_digest)); -NS_DECL(void, logv, (int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap)); -NS_DECL(int, server_mode, (const or_options_t *options)); +static double status_hb_not_in_consensus_tls_get_write_overhead_ratio(void); +static int status_hb_not_in_consensus_we_are_hibernating(void); +static int status_hb_not_in_consensus_public_server_mode( + const or_options_t *options); +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 int status_hb_not_in_consensus_server_mode(const or_options_t *options); static routerinfo_t *mock_routerinfo; static void -NS(test_main)(void *arg) +test_status_hb_not_in_consensus(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(router_get_my_routerinfo); - NS_MOCK(node_get_by_id); - NS_MOCK(logv); - NS_MOCK(server_mode); + MOCK(tls_get_write_overhead_ratio, + status_hb_not_in_consensus_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_not_in_consensus_we_are_hibernating); + MOCK(public_server_mode, + status_hb_not_in_consensus_public_server_mode); + MOCK(router_get_my_routerinfo, + status_hb_not_in_consensus_get_my_routerinfo); + MOCK(node_get_by_id, + status_hb_not_in_consensus_node_get_by_id); + MOCK(server_mode, + status_hb_not_in_consensus_server_mode); log_global_min_severity_ = LOG_DEBUG; onion_handshakes_requested[ONION_HANDSHAKE_TYPE_TAP] = 1; @@ -344,36 +339,56 @@ NS(test_main)(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(CALLED(logv), OP_EQ, 6); - done: - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(router_get_my_routerinfo); - NS_UNMOCK(node_get_by_id); - NS_UNMOCK(logv); - NS_UNMOCK(server_mode); + 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(server_mode); tor_free(mock_routerinfo); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_not_in_consensus_tls_get_write_overhead_ratio(void) { return 1.0; } static int -NS(we_are_hibernating)(void) +status_hb_not_in_consensus_we_are_hibernating(void) { return 0; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_not_in_consensus_public_server_mode(const or_options_t *options) { (void)options; @@ -381,7 +396,7 @@ NS(public_server_mode)(const or_options_t *options) } static const routerinfo_t * -NS(router_get_my_routerinfo)(void) +status_hb_not_in_consensus_get_my_routerinfo(void) { mock_routerinfo = tor_malloc(sizeof(routerinfo_t)); @@ -389,158 +404,95 @@ NS(router_get_my_routerinfo)(void) } static const node_t * -NS(node_get_by_id)(const char *identity_digest) +status_hb_not_in_consensus_node_get_by_id(const char *identity_digest) { (void)identity_digest; return NULL; } -static void -NS(logv)(int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap) -{ - switch (CALLED(logv)) - { - case 0: - tt_int_op(severity, OP_EQ, LOG_NOTICE); - tt_int_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_int_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_int_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_int_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_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; - } - - done: - CALLED(logv)++; -} - static int -NS(server_mode)(const or_options_t *options) +status_hb_not_in_consensus_server_mode(const or_options_t *options) { (void)options; return 0; } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, simple) - /* * Tests that log_heartbeat() correctly logs heartbeat information * normally. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(long, get_uptime, (void)); -NS_DECL(uint64_t, get_bytes_read, (void)); -NS_DECL(uint64_t, get_bytes_written, (void)); -NS_DECL(void, logv, (int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap)); -NS_DECL(int, server_mode, (const or_options_t *options)); - -static int NS(n_msgs) = 0; +static double status_hb_simple_tls_get_write_overhead_ratio(void); +static int status_hb_simple_we_are_hibernating(void); +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 int status_hb_simple_server_mode(const or_options_t *options); static void -NS(test_main)(void *arg) +test_status_hb_simple(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(get_uptime); - NS_MOCK(get_bytes_read); - NS_MOCK(get_bytes_written); - NS_MOCK(logv); - NS_MOCK(server_mode); + MOCK(tls_get_write_overhead_ratio, + status_hb_simple_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_simple_we_are_hibernating); + MOCK(public_server_mode, + status_hb_simple_public_server_mode); + MOCK(get_uptime, + status_hb_simple_get_uptime); + MOCK(get_bytes_read, + status_hb_simple_get_bytes_read); + MOCK(get_bytes_written, + status_hb_simple_get_bytes_written); + 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(NS(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: - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(get_uptime); - NS_UNMOCK(get_bytes_read); - NS_UNMOCK(get_bytes_written); - NS_UNMOCK(logv); - NS_UNMOCK(server_mode); + 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(server_mode); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_simple_tls_get_write_overhead_ratio(void) { return 1.0; } static int -NS(we_are_hibernating)(void) +status_hb_simple_we_are_hibernating(void) { return 1; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_simple_public_server_mode(const or_options_t *options) { (void)options; @@ -548,135 +500,129 @@ NS(public_server_mode)(const or_options_t *options) } static long -NS(get_uptime)(void) +status_hb_simple_get_uptime(void) { return 0; } static uint64_t -NS(get_bytes_read)(void) +status_hb_simple_get_bytes_read(void) { return 0; } static uint64_t -NS(get_bytes_written)(void) +status_hb_simple_get_bytes_written(void) { return 0; } -static void -NS(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; - ++NS(n_msgs); - - tt_int_op(severity, OP_EQ, LOG_NOTICE); - tt_int_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 -NS(server_mode)(const or_options_t *options) +status_hb_simple_server_mode(const or_options_t *options) { (void)options; return 0; } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, calls_log_accounting) - /* * Tests that log_heartbeat() correctly logs heartbeat information * and accounting information when configured. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(long, get_uptime, (void)); -NS_DECL(uint64_t, get_bytes_read, (void)); -NS_DECL(uint64_t, get_bytes_written, (void)); -NS_DECL(void, logv, (int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap)); -NS_DECL(int, server_mode, (const or_options_t *options)); -NS_DECL(or_state_t *, get_or_state, (void)); -NS_DECL(int, accounting_is_enabled, (const or_options_t *options)); -NS_DECL(time_t, accounting_get_end_time, (void)); - -static or_state_t * NS(mock_state) = NULL; -static or_options_t * NS(mock_options) = NULL; +static double status_hb_calls_log_accounting_tls_get_write_overhead_ratio( + void); +static int status_hb_calls_log_accounting_we_are_hibernating(void); +static int status_hb_calls_log_accounting_public_server_mode( + const or_options_t *options); +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 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); +static int status_hb_calls_log_accounting_accounting_is_enabled( + const or_options_t *options); +static time_t status_hb_calls_log_accounting_accounting_get_end_time(void); + +static or_state_t * status_hb_calls_log_accounting_mock_state = NULL; +static or_options_t * status_hb_calls_log_accounting_mock_options = NULL; static void -NS(test_main)(void *arg) +test_status_hb_calls_log_accounting(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(get_uptime); - NS_MOCK(get_bytes_read); - NS_MOCK(get_bytes_written); - NS_MOCK(logv); - NS_MOCK(server_mode); - NS_MOCK(get_or_state); - NS_MOCK(accounting_is_enabled); - NS_MOCK(accounting_get_end_time); + MOCK(tls_get_write_overhead_ratio, + status_hb_calls_log_accounting_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_calls_log_accounting_we_are_hibernating); + MOCK(public_server_mode, + status_hb_calls_log_accounting_public_server_mode); + MOCK(get_uptime, + status_hb_calls_log_accounting_get_uptime); + MOCK(get_bytes_read, + status_hb_calls_log_accounting_get_bytes_read); + MOCK(get_bytes_written, + status_hb_calls_log_accounting_get_bytes_written); + MOCK(server_mode, + status_hb_calls_log_accounting_server_mode); + MOCK(get_or_state, + status_hb_calls_log_accounting_get_or_state); + MOCK(accounting_is_enabled, + status_hb_calls_log_accounting_accounting_is_enabled); + MOCK(accounting_get_end_time, + status_hb_calls_log_accounting_accounting_get_end_time); 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(CALLED(logv), 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: - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(get_uptime); - NS_UNMOCK(get_bytes_read); - NS_UNMOCK(get_bytes_written); - NS_UNMOCK(logv); - NS_UNMOCK(server_mode); - NS_UNMOCK(accounting_is_enabled); - NS_UNMOCK(accounting_get_end_time); - tor_free_(NS(mock_state)); - tor_free_(NS(mock_options)); + 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(server_mode); + UNMOCK(accounting_is_enabled); + UNMOCK(accounting_get_end_time); + tor_free_(status_hb_calls_log_accounting_mock_state); + tor_free_(status_hb_calls_log_accounting_mock_options); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_calls_log_accounting_tls_get_write_overhead_ratio(void) { return 1.0; } static int -NS(we_are_hibernating)(void) +status_hb_calls_log_accounting_we_are_hibernating(void) { return 0; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_calls_log_accounting_public_server_mode(const or_options_t *options) { (void)options; @@ -684,77 +630,25 @@ NS(public_server_mode)(const or_options_t *options) } static long -NS(get_uptime)(void) +status_hb_calls_log_accounting_get_uptime(void) { return 0; } static uint64_t -NS(get_bytes_read)(void) +status_hb_calls_log_accounting_get_bytes_read(void) { return 0; } static uint64_t -NS(get_bytes_written)(void) +status_hb_calls_log_accounting_get_bytes_written(void) { return 0; } -static void -NS(logv)(int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap) -{ - switch (CALLED(logv)) - { - case 0: - tt_int_op(severity, OP_EQ, LOG_NOTICE); - tt_int_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_int_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: - CALLED(logv)++; -} - static int -NS(server_mode)(const or_options_t *options) +status_hb_calls_log_accounting_server_mode(const or_options_t *options) { (void)options; @@ -762,7 +656,8 @@ NS(server_mode)(const or_options_t *options) } static int -NS(accounting_is_enabled)(const or_options_t *options) +status_hb_calls_log_accounting_accounting_is_enabled( + const or_options_t *options) { (void)options; @@ -770,93 +665,110 @@ NS(accounting_is_enabled)(const or_options_t *options) } static time_t -NS(accounting_get_end_time)(void) +status_hb_calls_log_accounting_accounting_get_end_time(void) { return 60; } static or_state_t * -NS(get_or_state)(void) +status_hb_calls_log_accounting_get_or_state(void) { - NS(mock_state) = tor_malloc_zero(sizeof(or_state_t)); - NS(mock_state)->AccountingBytesReadInInterval = 0; - NS(mock_state)->AccountingBytesWrittenInInterval = 0; + status_hb_calls_log_accounting_mock_state = + tor_malloc_zero(sizeof(or_state_t)); + status_hb_calls_log_accounting_mock_state + ->AccountingBytesReadInInterval = 0; + status_hb_calls_log_accounting_mock_state + ->AccountingBytesWrittenInInterval = 0; - return NS(mock_state); + return status_hb_calls_log_accounting_mock_state; } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, packaged_cell_fullness) - /* * Tests that log_heartbeat() correctly logs packaged cell * fullness information. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(long, get_uptime, (void)); -NS_DECL(uint64_t, get_bytes_read, (void)); -NS_DECL(uint64_t, get_bytes_written, (void)); -NS_DECL(void, logv, (int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap)); -NS_DECL(int, server_mode, (const or_options_t *options)); -NS_DECL(int, accounting_is_enabled, (const or_options_t *options)); +static double status_hb_packaged_cell_fullness_tls_get_write_overhead_ratio( + void); +static int status_hb_packaged_cell_fullness_we_are_hibernating(void); +static int status_hb_packaged_cell_fullness_public_server_mode( + const or_options_t *options); +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 int status_hb_packaged_cell_fullness_server_mode( + const or_options_t *options); +static int status_hb_packaged_cell_fullness_accounting_is_enabled( + const or_options_t *options); static void -NS(test_main)(void *arg) +test_status_hb_packaged_cell_fullness(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(get_uptime); - NS_MOCK(get_bytes_read); - NS_MOCK(get_bytes_written); - NS_MOCK(logv); - NS_MOCK(server_mode); - NS_MOCK(accounting_is_enabled); + MOCK(tls_get_write_overhead_ratio, + status_hb_packaged_cell_fullness_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_packaged_cell_fullness_we_are_hibernating); + MOCK(public_server_mode, + status_hb_packaged_cell_fullness_public_server_mode); + MOCK(get_uptime, + status_hb_packaged_cell_fullness_get_uptime); + MOCK(get_bytes_read, + status_hb_packaged_cell_fullness_get_bytes_read); + MOCK(get_bytes_written, + status_hb_packaged_cell_fullness_get_bytes_written); + MOCK(server_mode, + status_hb_packaged_cell_fullness_server_mode); + MOCK(accounting_is_enabled, + status_hb_packaged_cell_fullness_accounting_is_enabled); log_global_min_severity_ = LOG_DEBUG; 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(CALLED(logv), 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; - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(get_uptime); - NS_UNMOCK(get_bytes_read); - NS_UNMOCK(get_bytes_written); - NS_UNMOCK(logv); - NS_UNMOCK(server_mode); - NS_UNMOCK(accounting_is_enabled); + 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(server_mode); + UNMOCK(accounting_is_enabled); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_packaged_cell_fullness_tls_get_write_overhead_ratio(void) { return 1.0; } static int -NS(we_are_hibernating)(void) +status_hb_packaged_cell_fullness_we_are_hibernating(void) { return 0; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_packaged_cell_fullness_public_server_mode( + const or_options_t *options) { (void)options; @@ -864,65 +776,25 @@ NS(public_server_mode)(const or_options_t *options) } static long -NS(get_uptime)(void) +status_hb_packaged_cell_fullness_get_uptime(void) { return 0; } static uint64_t -NS(get_bytes_read)(void) +status_hb_packaged_cell_fullness_get_bytes_read(void) { return 0; } static uint64_t -NS(get_bytes_written)(void) +status_hb_packaged_cell_fullness_get_bytes_written(void) { return 0; } -static void -NS(logv)(int severity, log_domain_mask_t domain, const char *funcname, - const char *suffix, const char *format, va_list ap) -{ - switch (CALLED(logv)) - { - case 0: - tt_int_op(severity, OP_EQ, LOG_NOTICE); - tt_int_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_int_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: - CALLED(logv)++; -} - static int -NS(server_mode)(const or_options_t *options) +status_hb_packaged_cell_fullness_server_mode(const or_options_t *options) { (void)options; @@ -930,82 +802,95 @@ NS(server_mode)(const or_options_t *options) } static int -NS(accounting_is_enabled)(const or_options_t *options) +status_hb_packaged_cell_fullness_accounting_is_enabled( + const or_options_t *options) { (void)options; return 0; } -#undef NS_SUBMODULE -#define NS_SUBMODULE ASPECT(log_heartbeat, tls_write_overhead) - /* * Tests that log_heartbeat() correctly logs the TLS write overhead information * when the TLS write overhead ratio exceeds 1. */ -NS_DECL(double, tls_get_write_overhead_ratio, (void)); -NS_DECL(int, we_are_hibernating, (void)); -NS_DECL(int, public_server_mode, (const or_options_t *options)); -NS_DECL(long, get_uptime, (void)); -NS_DECL(uint64_t, get_bytes_read, (void)); -NS_DECL(uint64_t, get_bytes_written, (void)); -NS_DECL(void, logv, (int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap)); -NS_DECL(int, server_mode, (const or_options_t *options)); -NS_DECL(int, accounting_is_enabled, (const or_options_t *options)); +static double status_hb_tls_write_overhead_tls_get_write_overhead_ratio(void); +static int status_hb_tls_write_overhead_we_are_hibernating(void); +static int status_hb_tls_write_overhead_public_server_mode( + const or_options_t *options); +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 int status_hb_tls_write_overhead_server_mode( + const or_options_t *options); +static int status_hb_tls_write_overhead_accounting_is_enabled( + const or_options_t *options); static void -NS(test_main)(void *arg) +test_status_hb_tls_write_overhead(void *arg) { int expected, actual; (void)arg; - NS_MOCK(tls_get_write_overhead_ratio); - NS_MOCK(we_are_hibernating); - NS_MOCK(public_server_mode); - NS_MOCK(get_uptime); - NS_MOCK(get_bytes_read); - NS_MOCK(get_bytes_written); - NS_MOCK(logv); - NS_MOCK(server_mode); - NS_MOCK(accounting_is_enabled); + MOCK(tls_get_write_overhead_ratio, + status_hb_tls_write_overhead_tls_get_write_overhead_ratio); + MOCK(we_are_hibernating, + status_hb_tls_write_overhead_we_are_hibernating); + MOCK(public_server_mode, + status_hb_tls_write_overhead_public_server_mode); + MOCK(get_uptime, + status_hb_tls_write_overhead_get_uptime); + MOCK(get_bytes_read, + status_hb_tls_write_overhead_get_bytes_read); + MOCK(get_bytes_written, + status_hb_tls_write_overhead_get_bytes_written); + MOCK(server_mode, + status_hb_tls_write_overhead_server_mode); + MOCK(accounting_is_enabled, + status_hb_tls_write_overhead_accounting_is_enabled); stats_n_data_cells_packaged = 0; 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(CALLED(logv), 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: - NS_UNMOCK(tls_get_write_overhead_ratio); - NS_UNMOCK(we_are_hibernating); - NS_UNMOCK(public_server_mode); - NS_UNMOCK(get_uptime); - NS_UNMOCK(get_bytes_read); - NS_UNMOCK(get_bytes_written); - NS_UNMOCK(logv); - NS_UNMOCK(server_mode); - NS_UNMOCK(accounting_is_enabled); + 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(server_mode); + UNMOCK(accounting_is_enabled); } static double -NS(tls_get_write_overhead_ratio)(void) +status_hb_tls_write_overhead_tls_get_write_overhead_ratio(void) { return 2.0; } static int -NS(we_are_hibernating)(void) +status_hb_tls_write_overhead_we_are_hibernating(void) { return 0; } static int -NS(public_server_mode)(const or_options_t *options) +status_hb_tls_write_overhead_public_server_mode(const or_options_t *options) { (void)options; @@ -1013,65 +898,25 @@ NS(public_server_mode)(const or_options_t *options) } static long -NS(get_uptime)(void) +status_hb_tls_write_overhead_get_uptime(void) { return 0; } static uint64_t -NS(get_bytes_read)(void) +status_hb_tls_write_overhead_get_bytes_read(void) { return 0; } static uint64_t -NS(get_bytes_written)(void) +status_hb_tls_write_overhead_get_bytes_written(void) { return 0; } -static void -NS(logv)(int severity, log_domain_mask_t domain, - const char *funcname, const char *suffix, const char *format, va_list ap) -{ - switch (CALLED(logv)) - { - case 0: - tt_int_op(severity, OP_EQ, LOG_NOTICE); - tt_int_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_int_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: - CALLED(logv)++; -} - static int -NS(server_mode)(const or_options_t *options) +status_hb_tls_write_overhead_server_mode(const or_options_t *options) { (void)options; @@ -1079,24 +924,26 @@ NS(server_mode)(const or_options_t *options) } static int -NS(accounting_is_enabled)(const or_options_t *options) +status_hb_tls_write_overhead_accounting_is_enabled(const or_options_t *options) { (void)options; return 0; } -#undef NS_SUBMODULE - struct testcase_t status_tests[] = { - TEST_CASE(count_circuits), - TEST_CASE(secs_to_uptime), - TEST_CASE(bytes_to_usage), - TEST_CASE_ASPECT(log_heartbeat, fails), - TEST_CASE_ASPECT(log_heartbeat, simple), - TEST_CASE_ASPECT(log_heartbeat, not_in_consensus), - TEST_CASE_ASPECT(log_heartbeat, calls_log_accounting), - TEST_CASE_ASPECT(log_heartbeat, packaged_cell_fullness), - TEST_CASE_ASPECT(log_heartbeat, tls_write_overhead), + { "count_circuits", test_status_count_circuits, TT_FORK, NULL, NULL }, + { "secs_to_uptime", test_status_secs_to_uptime, TT_FORK, NULL, NULL }, + { "bytes_to_usage", test_status_bytes_to_usage, TT_FORK, NULL, NULL }, + { "hb_fails", test_status_hb_fails, TT_FORK, NULL, NULL }, + { "hb_simple", test_status_hb_simple, TT_FORK, NULL, NULL }, + { "hb_not_in_consensus", test_status_hb_not_in_consensus, + TT_FORK, NULL, NULL }, + { "hb_calls_log_accounting", test_status_hb_calls_log_accounting, + TT_FORK, NULL, NULL }, + { "hb_packaged_cell_fullness", test_status_hb_packaged_cell_fullness, + TT_FORK, NULL, NULL }, + { "hb_tls_write_overhead", test_status_hb_tls_write_overhead, + TT_FORK, NULL, NULL }, END_OF_TESTCASES }; |