From fe92e9bb9647123381a8428ed438283fb1a749f4 Mon Sep 17 00:00:00 2001 From: Ola Bini Date: Fri, 29 Jan 2016 11:38:54 -0500 Subject: [PATCH 1/4] Add a helper to search for strings in the log, and change option tests to use this helper instead of looking at specific indices in the log list --- src/test/log_test_helpers.c | 17 ++++ src/test/log_test_helpers.h | 1 + src/test/test_options.c | 159 ++++++++++++++++++------------------ 3 files changed, 97 insertions(+), 80 deletions(-) diff --git a/src/test/log_test_helpers.c b/src/test/log_test_helpers.c index 51b5f9b7b1..88d28e1cc0 100644 --- a/src/test/log_test_helpers.c +++ b/src/test/log_test_helpers.c @@ -83,6 +83,23 @@ mock_saved_logs(void) return saved_logs; } +int +mock_saved_log_has_message(const char *msg) +{ + int has_msg = 0; + if (saved_logs) { + SMARTLIST_FOREACH(saved_logs, mock_saved_log_entry_t *, m, + { + if (msg && m->generated_msg && + !strcmp(msg, m->generated_msg)) { + has_msg = 1; + } + }); + } + + return has_msg; +} + void mock_saving_logv(int severity, log_domain_mask_t domain, const char *funcname, const char *suffix, diff --git a/src/test/log_test_helpers.h b/src/test/log_test_helpers.h index af8e8a60e7..3a565c67c5 100644 --- a/src/test/log_test_helpers.h +++ b/src/test/log_test_helpers.h @@ -26,6 +26,7 @@ void teardown_capture_of_logs(int prev); const char *mock_saved_log_at(int ix); int mock_saved_severity_at(int ix); int mock_saved_log_number(void); +int mock_saved_log_has_message(const char *msg); #endif diff --git a/src/test/test_options.c b/src/test/test_options.c index 4bae065925..da8bc2128a 100644 --- a/src/test/test_options.c +++ b/src/test/test_options.c @@ -367,6 +367,14 @@ free_options_test_data(options_test_data_t *td) tor_free(td); } +#define expect_log_msg(str) \ + tt_assert_msg(mock_saved_log_has_message(str), \ + "expected log to contain " # str); + +#define expect_no_log_msg(str) \ + tt_assert_msg(!mock_saved_log_has_message(str), \ + "expected log to not contain " # str); + static void test_options_validate__uname_for_server(void *ignored) { @@ -379,7 +387,7 @@ test_options_validate__uname_for_server(void *ignored) MOCK(get_uname, fixed_get_uname); fixed_get_uname_result = "Windows 95"; options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Tor is running as a server, but you" + expect_log_msg("Tor is running as a server, but you" " are running Windows 95; this probably won't work. See https://www" ".torproject.org/docs/faq.html#BestOSForRelay for details.\n"); tor_free(msg); @@ -387,7 +395,7 @@ test_options_validate__uname_for_server(void *ignored) fixed_get_uname_result = "Windows 98"; mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Tor is running as a server, but you" + expect_log_msg("Tor is running as a server, but you" " are running Windows 98; this probably won't work. See https://www" ".torproject.org/docs/faq.html#BestOSForRelay for details.\n"); tor_free(msg); @@ -395,7 +403,7 @@ test_options_validate__uname_for_server(void *ignored) fixed_get_uname_result = "Windows Me"; mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Tor is running as a server, but you" + expect_log_msg("Tor is running as a server, but you" " are running Windows Me; this probably won't work. See https://www" ".torproject.org/docs/faq.html#BestOSForRelay for details.\n"); tor_free(msg); @@ -512,7 +520,7 @@ test_options_validate__contactinfo(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_EQ, + expect_log_msg( "Your ContactInfo config option is not" " set. Please consider setting it, so we can contact you if your" " server is misconfigured or something else goes wrong.\n"); @@ -524,7 +532,7 @@ test_options_validate__contactinfo(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_NE, + expect_no_log_msg( "Your ContactInfo config option is not" " set. Please consider setting it, so we can contact you if your" " server is misconfigured or something else goes wrong.\n"); @@ -632,7 +640,7 @@ test_options_validate__authdir(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_str_op(msg, OP_EQ, "Failed to resolve/guess local address. See logs for" " details."); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Could not resolve local Address " + expect_log_msg("Could not resolve local Address " "'this.should.not_exist.example.org'. Failing.\n"); tor_free(msg); @@ -763,7 +771,7 @@ test_options_validate__authdir(void *ignored) "SchedulerLowWaterMark__ 10\n"); mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Authoritative directory servers " + expect_log_msg("Authoritative directory servers " "can't set UseEntryGuards. Disabling.\n"); tt_int_op(tdata->opt->UseEntryGuards, OP_EQ, 0); tor_free(msg); @@ -777,7 +785,7 @@ test_options_validate__authdir(void *ignored) "SchedulerLowWaterMark__ 10\n"); mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Authoritative directories always try" + expect_log_msg("Authoritative directories always try" " to download extra-info documents. Setting DownloadExtraInfo.\n"); tt_int_op(tdata->opt->DownloadExtraInfo, OP_EQ, 1); tor_free(msg); @@ -792,7 +800,7 @@ test_options_validate__authdir(void *ignored) "SchedulerLowWaterMark__ 10\n"); mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(0), OP_NE, "Authoritative directories always try" + expect_no_log_msg("Authoritative directories always try" " to download extra-info documents. Setting DownloadExtraInfo.\n"); tt_int_op(tdata->opt->DownloadExtraInfo, OP_EQ, 1); tor_free(msg); @@ -935,7 +943,7 @@ test_options_validate__relay_with_hidden_services(void *ignored) ); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(1), OP_EQ, + expect_log_msg( "Tor is currently configured as a relay and a hidden service. " "That's not very secure: you should probably run your hidden servi" "ce in a separate Tor process, at least -- see " @@ -1145,7 +1153,7 @@ test_options_validate__exclude_nodes(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_EQ, + expect_log_msg( "You have asked to exclude certain relays from all positions " "in your circuits. Expect hidden services and other Tor " "features to be broken in unpredictable ways.\n"); @@ -1158,7 +1166,7 @@ test_options_validate__exclude_nodes(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_NE, + expect_no_log_msg( "You have asked to exclude certain relays from all positions " "in your circuits. Expect hidden services and other Tor " "features to be broken in unpredictable ways.\n"); @@ -1183,8 +1191,7 @@ test_options_validate__scheduler(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Bad SchedulerLowWaterMark__ option\n"); + expect_log_msg("Bad SchedulerLowWaterMark__ option\n"); tor_free(msg); // TODO: this test cannot run on platforms where UINT32_MAX == UINT64_MAX. @@ -1207,8 +1214,7 @@ test_options_validate__scheduler(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Bad SchedulerHighWaterMark option\n"); + expect_log_msg("Bad SchedulerHighWaterMark option\n"); tor_free(msg); done: @@ -1283,8 +1289,7 @@ test_options_validate__tlsec(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Unrecognized TLSECGroup: Falling back to the default.\n"); + expect_log_msg("Unrecognized TLSECGroup: Falling back to the default.\n"); tt_assert(!tdata->opt->TLSECGroup); tor_free(msg); @@ -1295,7 +1300,7 @@ test_options_validate__tlsec(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_NE, + expect_no_log_msg( "Unrecognized TLSECGroup: Falling back to the default.\n"); tt_assert(tdata->opt->TLSECGroup); tor_free(msg); @@ -1307,7 +1312,7 @@ test_options_validate__tlsec(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(0), OP_NE, + expect_no_log_msg( "Unrecognized TLSECGroup: Falling back to the default.\n"); tt_assert(tdata->opt->TLSECGroup); tor_free(msg); @@ -1360,8 +1365,7 @@ test_options_validate__recommended_packages(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_NE, "Invalid RecommendedPackage line " + expect_no_log_msg("Invalid RecommendedPackage line " "invalid-package-line will be ignored\n"); done: @@ -1455,9 +1459,7 @@ test_options_validate__paths_needed(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_assert(tdata->opt->PathsNeededToBuildCircuits > 0.24 && tdata->opt->PathsNeededToBuildCircuits < 0.26); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "PathsNeededToBuildCircuits is too low. Increasing to 0.25\n"); + expect_log_msg("PathsNeededToBuildCircuits is too low. Increasing to 0.25\n"); tor_free(msg); free_options_test_data(tdata); @@ -1471,8 +1473,7 @@ test_options_validate__paths_needed(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_assert(tdata->opt->PathsNeededToBuildCircuits > 0.94 && tdata->opt->PathsNeededToBuildCircuits < 0.96); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "PathsNeededToBuildCircuits is " + expect_log_msg("PathsNeededToBuildCircuits is " "too high. Decreasing to 0.95\n"); tor_free(msg); @@ -1638,11 +1639,10 @@ test_options_validate__reachable_addresses(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_int_op(mock_saved_log_number(), OP_EQ, 6); - tt_str_op(mock_saved_log_at(1), OP_EQ, "Converting FascistFirewall config " + expect_log_msg("Converting FascistFirewall config " "option to new format: \"ReachableDirAddresses *:80\"\n"); tt_str_op(tdata->opt->ReachableDirAddresses->value, OP_EQ, "*:80"); - tt_str_op(mock_saved_log_at(2), OP_EQ, "Converting FascistFirewall config " + expect_log_msg("Converting FascistFirewall config " "option to new format: \"ReachableORAddresses *:443\"\n"); tt_str_op(tdata->opt->ReachableORAddresses->value, OP_EQ, "*:443"); tor_free(msg); @@ -1675,8 +1675,7 @@ test_options_validate__reachable_addresses(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_int_op(mock_saved_log_number(), OP_EQ, 5); - tt_str_op(mock_saved_log_at(1), OP_EQ, "Converting FascistFirewall and " + expect_log_msg("Converting FascistFirewall and " "FirewallPorts config options to new format: " "\"ReachableAddresses *:123\"\n"); tt_str_op(tdata->opt->ReachableAddresses->value, OP_EQ, "*:123"); @@ -2056,7 +2055,7 @@ test_options_validate__publish_server_descriptor(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_str_op(mock_saved_log_at(1), OP_EQ, "Can't set a DirPort on a bridge " + expect_log_msg("Can't set a DirPort on a bridge " "relay; disabling DirPort\n"); tt_assert(!tdata->opt->DirPort_lines); tt_assert(!tdata->opt->DirPort_set); @@ -2158,7 +2157,7 @@ test_options_validate__hidserv(void *ignored) tdata->opt->MinUptimeHidServDirectoryV2 = -1; ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_EQ, "MinUptimeHidServDirectoryV2 " + expect_log_msg("MinUptimeHidServDirectoryV2 " "option must be at least 0 seconds. Changing to 0.\n"); tt_int_op(tdata->opt->MinUptimeHidServDirectoryV2, OP_EQ, 0); tor_free(msg); @@ -2169,7 +2168,7 @@ test_options_validate__hidserv(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_EQ, "RendPostPeriod option is too short;" + expect_log_msg("RendPostPeriod option is too short;" " raising to 600 seconds.\n"); tt_int_op(tdata->opt->RendPostPeriod, OP_EQ, 600); tor_free(msg); @@ -2180,7 +2179,7 @@ test_options_validate__hidserv(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_EQ, "RendPostPeriod is too large; " + expect_log_msg("RendPostPeriod is too large; " "clipping to 302400s.\n"); tt_int_op(tdata->opt->RendPostPeriod, OP_EQ, 302400); tor_free(msg); @@ -2206,7 +2205,7 @@ test_options_validate__predicted_ports(void *ignored) TEST_OPTIONS_DEFAULT_VALUES); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_EQ, "PredictedPortsRelevanceTime is too " + expect_log_msg("PredictedPortsRelevanceTime is too " "large; clipping to 3600s.\n"); tt_int_op(tdata->opt->PredictedPortsRelevanceTime, OP_EQ, 3600); @@ -2433,7 +2432,7 @@ test_options_validate__circuits(void *ignored) tdata = get_options_test_data(TEST_OPTIONS_DEFAULT_VALUES "MaxCircuitDirtiness 2592001\n"); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(1), OP_EQ, "MaxCircuitDirtiness option is too " + expect_log_msg("MaxCircuitDirtiness option is too " "high; setting to 30 days.\n"); tt_int_op(tdata->opt->MaxCircuitDirtiness, OP_EQ, 2592000); tor_free(msg); @@ -2443,7 +2442,7 @@ test_options_validate__circuits(void *ignored) tdata = get_options_test_data(TEST_OPTIONS_DEFAULT_VALUES "CircuitStreamTimeout 1\n"); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(2), OP_EQ, "CircuitStreamTimeout option is too" + expect_log_msg("CircuitStreamTimeout option is too" " short; raising to 10 seconds.\n"); tt_int_op(tdata->opt->CircuitStreamTimeout, OP_EQ, 10); tor_free(msg); @@ -2453,7 +2452,7 @@ test_options_validate__circuits(void *ignored) tdata = get_options_test_data(TEST_OPTIONS_DEFAULT_VALUES "CircuitStreamTimeout 111\n"); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(2), OP_NE, "CircuitStreamTimeout option is too" + expect_no_log_msg("CircuitStreamTimeout option is too" " short; raising to 10 seconds.\n"); tt_int_op(tdata->opt->CircuitStreamTimeout, OP_EQ, 111); tor_free(msg); @@ -2463,7 +2462,7 @@ test_options_validate__circuits(void *ignored) tdata = get_options_test_data(TEST_OPTIONS_DEFAULT_VALUES "HeartbeatPeriod 1\n"); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(2), OP_EQ, "HeartbeatPeriod option is too short;" + expect_log_msg("HeartbeatPeriod option is too short;" " raising to 1800 seconds.\n"); tt_int_op(tdata->opt->HeartbeatPeriod, OP_EQ, 1800); tor_free(msg); @@ -2473,7 +2472,7 @@ test_options_validate__circuits(void *ignored) tdata = get_options_test_data(TEST_OPTIONS_DEFAULT_VALUES "HeartbeatPeriod 1982\n"); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(2), OP_NE, "HeartbeatPeriod option is too short;" + expect_no_log_msg("HeartbeatPeriod option is too short;" " raising to 1800 seconds.\n"); tt_int_op(tdata->opt->HeartbeatPeriod, OP_EQ, 1982); tor_free(msg); @@ -2484,7 +2483,7 @@ test_options_validate__circuits(void *ignored) "CircuitBuildTimeout 1\n" ); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(1), OP_EQ, "CircuitBuildTimeout is shorter (1" + expect_log_msg("CircuitBuildTimeout is shorter (1" " seconds) than the recommended minimum (10 seconds), and " "LearnCircuitBuildTimeout is disabled. If tor isn't working, " "raise this value or enable LearnCircuitBuildTimeout.\n"); @@ -2496,7 +2495,7 @@ test_options_validate__circuits(void *ignored) "CircuitBuildTimeout 11\n" ); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_str_op(mock_saved_log_at(1), OP_NE, "CircuitBuildTimeout is shorter (1 " + expect_no_log_msg("CircuitBuildTimeout is shorter (1 " "seconds) than the recommended minimum (10 seconds), and " "LearnCircuitBuildTimeout is disabled. If tor isn't working, " "raise this value or enable LearnCircuitBuildTimeout.\n"); @@ -2590,7 +2589,7 @@ test_options_validate__rend(void *ignored) ); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_EQ, "UseEntryGuards is disabled, but you" + expect_log_msg("UseEntryGuards is disabled, but you" " have configured one or more hidden services on this Tor " "instance. Your hidden services will be very easy to locate using" " a well-known attack -- see http://freehaven.net/anonbib/#hs-" @@ -2607,7 +2606,7 @@ test_options_validate__rend(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(1), OP_NE, "UseEntryGuards is disabled, but you" + expect_no_log_msg("UseEntryGuards is disabled, but you" " have configured one or more hidden services on this Tor " "instance. Your hidden services will be very easy to locate using" " a well-known attack -- see http://freehaven.net/anonbib/#hs-" @@ -2710,7 +2709,7 @@ test_options_validate__accounting(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(4), OP_EQ, "Using accounting with a hidden " + expect_log_msg("Using accounting with a hidden " "service and an ORPort is risky: your hidden service(s) and " "your public address will all turn off at the same time, " "which may alert observers that they are being run by the " @@ -2727,7 +2726,7 @@ test_options_validate__accounting(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(4), OP_NE, "Using accounting with a hidden " + expect_no_log_msg("Using accounting with a hidden " "service and an ORPort is risky: your hidden service(s) and " "your public address will all turn off at the same time, " "which may alert observers that they are being run by the " @@ -2746,7 +2745,7 @@ test_options_validate__accounting(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_EQ, "Using accounting with multiple " + expect_log_msg("Using accounting with multiple " "hidden services is risky: they will all turn off at the same" " time, which may alert observers that they are being run by " "the same party.\n"); @@ -2957,7 +2956,7 @@ test_options_validate__proxy(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, "HTTPProxy configured, but no SOCKS " + expect_log_msg("HTTPProxy configured, but no SOCKS " "proxy or HTTPS proxy configured. Watch out: this configuration " "will proxy unencrypted directory connections only.\n"); tor_free(msg); @@ -2970,7 +2969,7 @@ test_options_validate__proxy(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, "HTTPProxy configured, but no SOCKS " + expect_no_log_msg("HTTPProxy configured, but no SOCKS " "proxy or HTTPS proxy configured. Watch out: this configuration " "will proxy unencrypted directory connections only.\n"); tor_free(msg); @@ -2983,7 +2982,7 @@ test_options_validate__proxy(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, "HTTPProxy configured, but no SOCKS " + expect_no_log_msg("HTTPProxy configured, but no SOCKS " "proxy or HTTPS proxy configured. Watch out: this configuration " "will proxy unencrypted directory connections only.\n"); tor_free(msg); @@ -2996,7 +2995,7 @@ test_options_validate__proxy(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "HTTPProxy configured, but no SOCKS proxy or HTTPS proxy " "configured. Watch out: this configuration will proxy " "unencrypted directory connections only.\n"); @@ -3166,7 +3165,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, + expect_log_msg( "ControlPort is open, but no authentication method has been " "configured. This means that any program on your computer can " "reconfigure your Tor. That's bad! You should upgrade your Tor" @@ -3182,7 +3181,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlPort is open, but no authentication method has been " "configured. This means that any program on your computer can " "reconfigure your Tor. That's bad! You should upgrade your Tor " @@ -3199,7 +3198,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlPort is open, but no authentication method has been " "configured. This means that any program on your computer can " "reconfigure your Tor. That's bad! You should upgrade your Tor " @@ -3214,7 +3213,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlPort is open, but no authentication method has been " "configured. This means that any program on your computer can " "reconfigure your Tor. That's bad! You should upgrade your Tor " @@ -3229,7 +3228,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, + expect_log_msg( "ControlSocket is world writable, but no authentication method has" " been configured. This means that any program on your computer " "can reconfigure your Tor. That's bad! You should upgrade your " @@ -3245,7 +3244,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlSocket is world writable, but no authentication method has" " been configured. This means that any program on your computer " "can reconfigure your Tor. That's bad! You should upgrade your " @@ -3262,7 +3261,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlSocket is world writable, but no authentication method has" " been configured. This means that any program on your computer " "can reconfigure your Tor. That's bad! You should upgrade your " @@ -3277,7 +3276,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "ControlSocket is world writable, but no authentication method has" " been configured. This means that any program on your computer " "can reconfigure your Tor. That's bad! You should upgrade your " @@ -3292,7 +3291,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, + expect_log_msg( "CookieAuthFileGroupReadable is set, but will have no effect: you " "must specify an explicit CookieAuthFile to have it " "group-readable.\n"); @@ -3306,7 +3305,7 @@ test_options_validate__control(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "CookieAuthFileGroupReadable is set, but will have no effect: you " "must specify an explicit CookieAuthFile to have it " "group-readable.\n"); @@ -3343,7 +3342,7 @@ test_options_validate__families(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, + expect_log_msg( "Listing a family for a bridge relay is not supported: it can " "reveal bridge fingerprints to censors. You should also make sure " "you aren't listing this bridge's fingerprint in any other " @@ -3357,7 +3356,7 @@ test_options_validate__families(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "Listing a family for a bridge relay is not supported: it can " "reveal bridge fingerprints to censors. You should also make sure " "you aren't listing this bridge's fingerprint in any other " @@ -3438,7 +3437,7 @@ test_options_validate__dir_auth(void *ignored) tt_str_op(msg, OP_EQ, "Directory authority/fallback line did not parse. See logs for " "details."); - tt_str_op(mock_saved_log_at(2), OP_EQ, + expect_log_msg( "You cannot set both DirAuthority and Alternate*Authority.\n"); tor_free(msg); @@ -3524,7 +3523,7 @@ test_options_validate__transport(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_str_op(msg, OP_EQ, "Invalid client transport line. See logs for details."); - tt_str_op(mock_saved_log_at(3), OP_EQ, + expect_log_msg( "Too few arguments on ClientTransportPlugin line.\n"); tor_free(msg); @@ -3546,7 +3545,7 @@ test_options_validate__transport(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_str_op(msg, OP_EQ, "Invalid server transport line. See logs for details."); - tt_str_op(mock_saved_log_at(3), OP_EQ, + expect_log_msg( "Too few arguments on ServerTransportPlugin line.\n"); tor_free(msg); @@ -3557,7 +3556,7 @@ test_options_validate__transport(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_EQ, + expect_log_msg( "Tor is not configured as a relay but you specified a " "ServerTransportPlugin line (\"foo exec bar\"). The " "ServerTransportPlugin line will be ignored.\n"); @@ -3575,7 +3574,7 @@ test_options_validate__transport(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_NE, + expect_no_log_msg( "Tor is not configured as a relay but you specified a " "ServerTransportPlugin line (\"foo exec bar\"). The " "ServerTransportPlugin line will be ignored.\n"); @@ -3599,7 +3598,7 @@ test_options_validate__transport(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_EQ, + expect_log_msg( "You need at least a single managed-proxy to specify a transport " "listen address. The ServerTransportListenAddr line will be " "ignored.\n"); @@ -3618,7 +3617,7 @@ test_options_validate__transport(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_NE, + expect_no_log_msg( "You need at least a single managed-proxy to specify a transport " "listen address. The ServerTransportListenAddr line will be " "ignored.\n"); @@ -3687,7 +3686,7 @@ test_options_validate__constrained_sockets(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, "You have requested constrained " + expect_log_msg("You have requested constrained " "socket buffers while also serving directory entries via DirPort." " It is strongly suggested that you disable serving directory" " requests when system TCP buffer resources are scarce.\n"); @@ -3701,7 +3700,7 @@ test_options_validate__constrained_sockets(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, + expect_no_log_msg( "You have requested constrained socket buffers while also serving" " directory entries via DirPort. It is strongly suggested that " "you disable serving directory requests when system TCP buffer " @@ -3824,7 +3823,7 @@ test_options_validate__v3_auth(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, "V3AuthVotingInterval does not divide" + expect_log_msg("V3AuthVotingInterval does not divide" " evenly into 24 hours.\n"); tor_free(msg); @@ -3837,7 +3836,7 @@ test_options_validate__v3_auth(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, "V3AuthVotingInterval does not divide" + expect_no_log_msg("V3AuthVotingInterval does not divide" " evenly into 24 hours.\n"); tor_free(msg); @@ -3852,7 +3851,7 @@ test_options_validate__v3_auth(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(3), OP_EQ, "V3AuthVotingInterval is very low. " + expect_log_msg("V3AuthVotingInterval is very low. " "This may lead to failure to synchronise for a consensus.\n"); tor_free(msg); @@ -3985,7 +3984,7 @@ test_options_validate__exits(void *ignored) ); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_EQ, "You have set AllowSingleHopExits; " + expect_log_msg("You have set AllowSingleHopExits; " "now your relay will allow others to make one-hop exits. However," " since by default most clients avoid relays that set this option," " most clients will ignore you.\n"); @@ -3999,7 +3998,7 @@ test_options_validate__exits(void *ignored) mock_clean_saved_logs(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, 0); - tt_str_op(mock_saved_log_at(2), OP_NE, "You have set AllowSingleHopExits; " + expect_no_log_msg("You have set AllowSingleHopExits; " "now your relay will allow others to make one-hop exits. However," " since by default most clients avoid relays that set this option," " most clients will ignore you.\n"); @@ -4044,7 +4043,7 @@ test_options_validate__testing_options(void *ignored) mock_clean_saved_logs(); \ ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg);\ tt_int_op(ret, OP_EQ, 0); \ - tt_str_op(mock_saved_log_at(3), OP_EQ, #name " is insanely high.\n"); \ + expect_log_msg( #name " is insanely high.\n"); \ tor_free(msg); \ STMT_END From dbb5819e96e6f31a9ed5c46cda7d7ba1265a362c Mon Sep 17 00:00:00 2001 From: "teor (Tim Wilson-Brown)" Date: Fri, 29 Jan 2016 08:15:14 +1100 Subject: [PATCH 2/4] Report malformed options in options_validate unit tests --- src/test/test_options.c | 33 +++++++++++++++++++++++++++++---- 1 file changed, 29 insertions(+), 4 deletions(-) diff --git a/src/test/test_options.c b/src/test/test_options.c index da8bc2128a..ea5f29e216 100644 --- a/src/test/test_options.c +++ b/src/test/test_options.c @@ -338,22 +338,47 @@ typedef struct { or_options_t *def_opt; } options_test_data_t; +static void free_options_test_data(options_test_data_t *td); + static options_test_data_t * get_options_test_data(const char *conf) { + int rv = -1; + char *msg = NULL; config_line_t *cl=NULL; options_test_data_t *result = tor_malloc(sizeof(options_test_data_t)); result->opt = options_new(); result->old_opt = options_new(); result->def_opt = options_new(); - config_get_lines(conf, &cl, 1); - config_assign(&options_format, result->opt, cl, 0, 0, NULL); + rv = config_get_lines(conf, &cl, 1); + tt_assert(rv == 0); + rv = config_assign(&options_format, result->opt, cl, 0, 0, &msg); + if (msg) { + /* Display the parse error message by comparing it with an empty string */ + tt_str_op(msg, OP_EQ, ""); + } + tt_assert(rv == 0); config_free_lines(cl); result->opt->LogTimeGranularity = 1; result->opt->TokenBucketRefillInterval = 1; - config_get_lines(TEST_OPTIONS_OLD_VALUES, &cl, 1); - config_assign(&options_format, result->def_opt, cl, 0, 0, NULL); + rv = config_get_lines(TEST_OPTIONS_OLD_VALUES, &cl, 1); + tt_assert(rv == 0); + rv = config_assign(&options_format, result->def_opt, cl, 0, 0, &msg); + if (msg) { + /* Display the parse error message by comparing it with an empty string */ + tt_str_op(msg, OP_EQ, ""); + } + tt_assert(rv == 0); + +done: config_free_lines(cl); + if (rv != 0) { + free_options_test_data(result); + result = NULL; + /* Callers expect a non-NULL result, so just die if we can't provide one. + */ + tor_assert(0); + } return result; } From f7b2ae91e9e6c9d4c3d5c993cd146829d3f1f3d7 Mon Sep 17 00:00:00 2001 From: "teor (Tim Wilson-Brown)" Date: Mon, 1 Feb 2016 10:02:04 +1100 Subject: [PATCH 3/4] Make all unit tests independent of log message order and count --- src/test/log_test_helpers.c | 69 ++++++++++-------------- src/test/log_test_helpers.h | 29 ++++++++-- src/test/test_compat_libevent.c | 48 ++++++----------- src/test/test_options.c | 25 +++------ src/test/test_tortls.c | 95 ++++++++++++--------------------- src/test/test_util_process.c | 8 ++- 6 files changed, 116 insertions(+), 158 deletions(-) diff --git a/src/test/log_test_helpers.c b/src/test/log_test_helpers.c index 88d28e1cc0..bcf73a8437 100644 --- a/src/test/log_test_helpers.c +++ b/src/test/log_test_helpers.c @@ -35,48 +35,6 @@ mock_clean_saved_logs(void) saved_logs = NULL; } -static mock_saved_log_entry_t * -mock_get_log_entry(int ix) -{ - int saved_log_count = mock_saved_log_number(); - if (ix < 0) { - ix = saved_log_count + ix; - } - - if (saved_log_count <= ix) - return NULL; - - return smartlist_get(saved_logs, ix); -} - -const char * -mock_saved_log_at(int ix) -{ - mock_saved_log_entry_t *ent = mock_get_log_entry(ix); - if (ent) - return ent->generated_msg; - else - return ""; -} - -int -mock_saved_severity_at(int ix) -{ - mock_saved_log_entry_t *ent = mock_get_log_entry(ix); - if (ent) - return ent->severity; - else - return -1; -} - -int -mock_saved_log_number(void) -{ - if (!saved_logs) - return 0; - return smartlist_len(saved_logs); -} - const smartlist_t * mock_saved_logs(void) { @@ -100,6 +58,33 @@ mock_saved_log_has_message(const char *msg) return has_msg; } +/* Do the saved logs have any messages with severity? */ +int +mock_saved_log_has_severity(int severity) +{ + int has_sev = 0; + if (saved_logs) { + SMARTLIST_FOREACH(saved_logs, mock_saved_log_entry_t *, m, + { + if (m->severity == severity) { + has_sev = 1; + } + }); + } + + return has_sev; +} + +/* Do the saved logs have any messages? */ +int +mock_saved_log_has_entry(void) +{ + if (saved_logs) { + return smartlist_len(saved_logs) > 0; + } + return 0; +} + void mock_saving_logv(int severity, log_domain_mask_t domain, const char *funcname, const char *suffix, diff --git a/src/test/log_test_helpers.h b/src/test/log_test_helpers.h index 3a565c67c5..298237dddb 100644 --- a/src/test/log_test_helpers.h +++ b/src/test/log_test_helpers.h @@ -23,10 +23,33 @@ void mock_clean_saved_logs(void); const smartlist_t *mock_saved_logs(void); int setup_capture_of_logs(int new_level); void teardown_capture_of_logs(int prev); -const char *mock_saved_log_at(int ix); -int mock_saved_severity_at(int ix); -int mock_saved_log_number(void); int mock_saved_log_has_message(const char *msg); +int mock_saved_log_has_severity(int severity); +int mock_saved_log_has_entry(void); + +#define expect_log_msg(str) \ + tt_assert_msg(mock_saved_log_has_message(str), \ + "expected log to contain " # str); + +#define expect_no_log_msg(str) \ + tt_assert_msg(!mock_saved_log_has_message(str), \ + "expected log to not contain " # str); + +#define expect_log_severity(severity) \ + tt_assert_msg(mock_saved_log_has_severity(severity), \ + "expected log to contain severity " # severity); + +#define expect_no_log_severity(severity) \ + tt_assert_msg(!mock_saved_log_has_severity(severity), \ + "expected log to not contain severity " # severity); + +#define expect_log_entry() \ + tt_assert_msg(mock_saved_log_has_entry(), \ + "expected log to contain entries"); + +#define expect_no_log_entry() \ + tt_assert_msg(!mock_saved_log_has_entry(), \ + "expected log to not contain entries"); #endif diff --git a/src/test/test_compat_libevent.c b/src/test/test_compat_libevent.c index 96502df308..f3fe113012 100644 --- a/src/test/test_compat_libevent.c +++ b/src/test/test_compat_libevent.c @@ -30,38 +30,28 @@ test_compat_libevent_logging_callback(void *ignored) int previous_log = setup_capture_of_logs(LOG_DEBUG); libevent_logging_callback(_EVENT_LOG_DEBUG, "hello world"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Message from libevent: hello world\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_DEBUG); + expect_log_msg("Message from libevent: hello world\n"); + expect_log_severity(LOG_DEBUG); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_MSG, "hello world another time"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Message from libevent: hello world another time\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_msg("Message from libevent: hello world another time\n"); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_WARN, "hello world a third time"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Warning from libevent: hello world a third time\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_WARN); + expect_log_msg("Warning from libevent: hello world a third time\n"); + expect_log_severity(LOG_WARN); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_ERR, "hello world a fourth time"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Error from libevent: hello world a fourth time\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_ERR); + expect_log_msg("Error from libevent: hello world a fourth time\n"); + expect_log_severity(LOG_ERR); mock_clean_saved_logs(); libevent_logging_callback(42, "hello world a fifth time"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Message [42] from libevent: hello world a fifth time\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_WARN); + expect_log_msg("Message [42] from libevent: hello world a fifth time\n"); + expect_log_severity(LOG_WARN); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_DEBUG, @@ -78,8 +68,7 @@ test_compat_libevent_logging_callback(void *ignored) "012345678901234567890123456789" "012345678901234567890123456789" ); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Message from libevent: " + expect_log_msg("Message from libevent: " "012345678901234567890123456789" "012345678901234567890123456789" "012345678901234567890123456789" @@ -92,25 +81,22 @@ test_compat_libevent_logging_callback(void *ignored) "012345678901234567890123456789" "012345678901234567890123456789" "012345678901234567890123456789\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_DEBUG); + expect_log_severity(LOG_DEBUG); mock_clean_saved_logs(); libevent_logging_callback(42, "xxx\n"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "Message [42] from libevent: xxx\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_WARN); + expect_log_msg("Message [42] from libevent: xxx\n"); + expect_log_severity(LOG_WARN); suppress_libevent_log_msg("something"); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_MSG, "hello there"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Message from libevent: hello there\n"); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_msg("Message from libevent: hello there\n"); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); libevent_logging_callback(_EVENT_LOG_MSG, "hello there something else"); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_msg("hello there something else"); // No way of verifying the result of this, it seems =/ configure_libevent_logging(); diff --git a/src/test/test_options.c b/src/test/test_options.c index ea5f29e216..2d48cd17f5 100644 --- a/src/test/test_options.c +++ b/src/test/test_options.c @@ -392,14 +392,6 @@ free_options_test_data(options_test_data_t *td) tor_free(td); } -#define expect_log_msg(str) \ - tt_assert_msg(mock_saved_log_has_message(str), \ - "expected log to contain " # str); - -#define expect_no_log_msg(str) \ - tt_assert_msg(!mock_saved_log_has_message(str), \ - "expected log to not contain " # str); - static void test_options_validate__uname_for_server(void *ignored) { @@ -436,7 +428,7 @@ test_options_validate__uname_for_server(void *ignored) fixed_get_uname_result = "Windows 2000"; mock_clean_saved_logs(); options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); + expect_log_entry(); tor_free(msg); done: @@ -992,9 +984,9 @@ test_options_validate__relay_with_hidden_services(void *ignored) /* options_test_data_t *tdata = get_options_test_data(""); */ /* ret = options_validate(tdata->old_opt, tdata->opt, */ /* tdata->def_opt, 0, &msg); */ -/* tt_str_op(mock_saved_log_at(0), OP_EQ, */ -/* "SocksPort, TransPort, NATDPort, DNSPort, and ORPort are all " */ -/* "undefined, and there aren't any hidden services configured. " */ +/* expect_log_msg("SocksPort, TransPort, NATDPort, DNSPort, and ORPort " */ +/* "are all undefined, and there aren't any hidden services " */ +/* "configured. " */ /* " Tor will still run, but probably won't do anything.\n"); */ /* done: */ /* teardown_capture_of_logs(previous_log); */ @@ -1230,8 +1222,7 @@ test_options_validate__scheduler(void *ignored) /* ret = options_validate(tdata->old_opt, tdata->opt, */ /* tdata->def_opt, 0, &msg); */ /* tt_int_op(ret, OP_EQ, -1); */ - /* tt_str_op(mock_saved_log_at(1), OP_EQ, */ - /* "Bad SchedulerLowWaterMark__ option\n"); */ + /* expect_log_msg("Bad SchedulerLowWaterMark__ option\n"); */ free_options_test_data(tdata); tdata = get_options_test_data("SchedulerLowWaterMark__ 42\n" @@ -1513,7 +1504,7 @@ test_options_validate__paths_needed(void *ignored) tt_int_op(ret, OP_EQ, -1); tt_assert(tdata->opt->PathsNeededToBuildCircuits > 0.90 && tdata->opt->PathsNeededToBuildCircuits < 0.92); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); tor_free(msg); done: @@ -1684,7 +1675,7 @@ test_options_validate__reachable_addresses(void *ignored) tdata->opt->FirewallPorts = smartlist_new(); ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_int_op(mock_saved_log_number(), OP_EQ, 4); + expect_log_entry(); tt_str_op(tdata->opt->ReachableDirAddresses->value, OP_EQ, "*:81"); tt_str_op(tdata->opt->ReachableORAddresses->value, OP_EQ, "*:444"); tor_free(msg); @@ -1719,7 +1710,7 @@ test_options_validate__reachable_addresses(void *ignored) ret = options_validate(tdata->old_opt, tdata->opt, tdata->def_opt, 0, &msg); tt_int_op(ret, OP_EQ, -1); - tt_int_op(mock_saved_log_number(), OP_EQ, 4); + expect_log_entry(); tt_str_op(tdata->opt->ReachableAddresses->value, OP_EQ, "*:82"); tor_free(msg); diff --git a/src/test/test_tortls.c b/src/test/test_tortls.c index add020e9f4..cbbd7dd3f3 100644 --- a/src/test/test_tortls.c +++ b/src/test/test_tortls.c @@ -344,79 +344,67 @@ test_tortls_log_one_error(void *ignored) int previous_log = setup_capture_of_logs(LOG_INFO); tor_tls_log_one_error(NULL, 0, LOG_WARN, 0, "something"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error while something: " + expect_log_msg("TLS error while something: " "(null) (in (null):(null):---)\n"); mock_clean_saved_logs(); tor_tls_log_one_error(tls, 0, LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error: (null) " + expect_log_msg("TLS error: (null) " "(in (null):(null):---)\n"); mock_clean_saved_logs(); tls->address = tor_strdup("127.hello"); tor_tls_log_one_error(tls, 0, LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error with 127.hello: (null) " - "(in (null):(null):---)\n"); + expect_log_msg("TLS error with 127.hello: " + "(null) (in (null):(null):---)\n"); tor_free(tls->address); mock_clean_saved_logs(); tls->address = tor_strdup("127.hello"); tor_tls_log_one_error(tls, 0, LOG_WARN, 0, "blarg"); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error while blarg with " + expect_log_msg("TLS error while blarg with " "127.hello: (null) (in (null):(null):---)\n"); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, 3), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error with 127.hello: " + expect_log_msg("TLS error with 127.hello: " "BN lib (in unknown library:(null):---)\n"); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_HTTP_REQUEST), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_HTTPS_PROXY_REQUEST), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_RECORD_LENGTH_MISMATCH), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_RECORD_TOO_LARGE), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_UNKNOWN_PROTOCOL), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); mock_clean_saved_logs(); tor_tls_log_one_error(tls, ERR_PACK(1, 2, SSL_R_UNSUPPORTED_PROTOCOL), LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); tls->ssl = SSL_new(ctx); mock_clean_saved_logs(); tor_tls_log_one_error(tls, 0, LOG_WARN, 0, NULL); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error with 127.hello: (null)" + expect_log_msg("TLS error with 127.hello: (null)" " (in (null):(null):" SSL_STATE_STR ")\n"); done: @@ -450,27 +438,25 @@ test_tortls_get_error(void *ignored) ret = tor_tls_get_error(tls, 0, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, TOR_TLS_ERROR_IO); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error: unexpected close while" + expect_log_msg("TLS error: unexpected close while" " something (before/accept initialization)\n"); mock_clean_saved_logs(); ret = tor_tls_get_error(tls, 2, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, 0); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); mock_clean_saved_logs(); ret = tor_tls_get_error(tls, 0, 1, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, -11); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); mock_clean_saved_logs(); ERR_clear_error(); ERR_put_error(ERR_LIB_BN, 2, -1, "somewhere.c", 99); ret = tor_tls_get_error(tls, 0, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, TOR_TLS_ERROR_MISC); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error while something: (null)" + expect_log_msg("TLS error while something: (null)" " (in bignum routines:(null):before/accept initialization)\n"); mock_clean_saved_logs(); @@ -479,7 +465,7 @@ test_tortls_get_error(void *ignored) SSL_get_rbio(tls->ssl)->flags = BIO_FLAGS_READ; ret = tor_tls_get_error(tls, -1, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, TOR_TLS_WANTREAD); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); mock_clean_saved_logs(); ERR_clear_error(); @@ -487,7 +473,7 @@ test_tortls_get_error(void *ignored) SSL_get_rbio(tls->ssl)->flags = BIO_FLAGS_WRITE; ret = tor_tls_get_error(tls, -1, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, TOR_TLS_WANTWRITE); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); mock_clean_saved_logs(); ERR_clear_error(); @@ -496,20 +482,18 @@ test_tortls_get_error(void *ignored) tls->ssl->s3->warn_alert =SSL_AD_CLOSE_NOTIFY; ret = tor_tls_get_error(tls, 0, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, TOR_TLS_CLOSE); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); + expect_log_entry(); mock_clean_saved_logs(); ret = tor_tls_get_error(tls, 0, 2, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, -10); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); mock_clean_saved_logs(); ERR_put_error(ERR_LIB_SYS, 2, -1, "somewhere.c", 99); ret = tor_tls_get_error(tls, -1, 0, "something", LOG_WARN, 0); tt_int_op(ret, OP_EQ, -9); - tt_int_op(mock_saved_log_number(), OP_EQ, 2); - tt_str_op(mock_saved_log_at(1), OP_EQ, - "TLS error while something: (null) (in system library:" + expect_log_msg("TLS error while something: (null) (in system library:" "connect:before/accept initialization)\n"); done: @@ -1823,12 +1807,11 @@ test_tortls_debug_state_callback(void *ignored) ssl = tor_malloc_zero(sizeof(SSL)); tor_tls_debug_state_callback(ssl, 32, 45); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); + n = snprintf(buf, 1000, "SSL %p is now in state unknown" " state [type=32,val=45].\n", ssl); buf[n]='\0'; - if (strcasecmp(mock_saved_log_at(0), buf)) - tt_str_op(mock_saved_log_at(0), OP_EQ, buf); + expect_log_msg(buf); done: teardown_capture_of_logs(previous_log); @@ -1864,21 +1847,17 @@ test_tortls_server_info_callback(void *ignored) SSL_set_state(ssl, SSL3_ST_SW_SRVR_HELLO_A); mock_clean_saved_logs(); tor_tls_server_info_callback(ssl, SSL_CB_ACCEPT_LOOP, 0); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Couldn't look up the tls for an SSL*. How odd!\n"); + expect_log_msg("Couldn't look up the tls for an SSL*. How odd!\n"); SSL_set_state(ssl, SSL3_ST_SW_SRVR_HELLO_B); mock_clean_saved_logs(); tor_tls_server_info_callback(ssl, SSL_CB_ACCEPT_LOOP, 0); - tt_int_op(mock_saved_log_number(), OP_EQ, 1); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Couldn't look up the tls for an SSL*. How odd!\n"); + expect_log_msg("Couldn't look up the tls for an SSL*. How odd!\n"); SSL_set_state(ssl, 99); mock_clean_saved_logs(); tor_tls_server_info_callback(ssl, SSL_CB_ACCEPT_LOOP, 0); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); SSL_set_ex_data(tls->ssl, tor_tls_object_ex_data_index, tls); SSL_set_state(ssl, SSL3_ST_SW_SRVR_HELLO_B); @@ -2255,18 +2234,15 @@ test_tortls_handshake(void *ignored) tls->state = TOR_TLS_ST_HANDSHAKE; ret = tor_tls_handshake(tls); tt_int_op(ret, OP_EQ, TOR_TLS_ERROR_MISC); - tt_int_op(mock_saved_log_number(), OP_EQ, 2); + expect_log_entry(); /* This fails on jessie. Investigate why! */ #if 0 - tt_str_op(mock_saved_log_at(0), OP_EQ, - "TLS error while handshaking: (null) (in bignum routines:" + expect_log_msg("TLS error while handshaking: (null) (in bignum routines:" "(null):SSLv3 write client hello B)\n"); - tt_str_op(mock_saved_log_at(1), OP_EQ, - "TLS error while handshaking: (null) (in system library:" + expect_log_msg("TLS error while handshaking: (null) (in system library:" "connect:SSLv3 write client hello B)\n"); #endif - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_INFO); - tt_int_op(mock_saved_severity_at(1), OP_EQ, LOG_INFO); + expect_log_severity(LOG_INFO); tls->isServer = 0; method->ssl_connect = setting_error_ssl_connect; @@ -2276,16 +2252,15 @@ test_tortls_handshake(void *ignored) tls->state = TOR_TLS_ST_HANDSHAKE; ret = tor_tls_handshake(tls); tt_int_op(ret, OP_EQ, TOR_TLS_ERROR_MISC); - tt_int_op(mock_saved_log_number(), OP_EQ, 2); + expect_log_entry(); #if 0 /* See above */ - tt_str_op(mock_saved_log_at(0), OP_EQ, "TLS error while handshaking: " + expect_log_msg("TLS error while handshaking: " "(null) (in bignum routines:(null):SSLv3 write client hello B)\n"); - tt_str_op(mock_saved_log_at(1), OP_EQ, "TLS error while handshaking: " + expect_log_msg("TLS error while handshaking: " "(null) (in system library:connect:SSLv3 write client hello B)\n"); #endif - tt_int_op(mock_saved_severity_at(0), OP_EQ, LOG_WARN); - tt_int_op(mock_saved_severity_at(1), OP_EQ, LOG_WARN); + expect_log_severity(LOG_WARN); done: teardown_capture_of_logs(previous_log); diff --git a/src/test/test_util_process.c b/src/test/test_util_process.c index cb1d5b2ebb..0a4354c043 100644 --- a/src/test/test_util_process.c +++ b/src/test/test_util_process.c @@ -34,8 +34,7 @@ test_util_process_set_waitpid_callback(void *ignored) res2 = set_waitpid_callback(pid, temp_callback, NULL); tt_assert(res2); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Replaced a waitpid monitor on pid 42. That should be " + expect_log_msg("Replaced a waitpid monitor on pid 42. That should be " "impossible.\n"); done: @@ -56,13 +55,12 @@ test_util_process_clear_waitpid_callback(void *ignored) res = set_waitpid_callback(pid, temp_callback, NULL); clear_waitpid_callback(res); - tt_int_op(mock_saved_log_number(), OP_EQ, 0); + expect_no_log_entry(); #if 0 /* No. This is use-after-free. We don't _do_ that. XXXX */ clear_waitpid_callback(res); - tt_str_op(mock_saved_log_at(0), OP_EQ, - "Couldn't remove waitpid monitor for pid 43.\n"); + expect_log_msg("Couldn't remove waitpid monitor for pid 43.\n"); #endif done: From e3da5ad6e3bcee7cb9b639296e186fbeda5a6d9c Mon Sep 17 00:00:00 2001 From: "teor (Tim Wilson-Brown)" Date: Mon, 1 Feb 2016 10:07:19 +1100 Subject: [PATCH 4/4] Replace incorrect use of snprintf in unit tests with tor_snprintf This avoids a potential out of bounds write. --- src/test/test_tortls.c | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/test/test_tortls.c b/src/test/test_tortls.c index cbbd7dd3f3..98f5facc11 100644 --- a/src/test/test_tortls.c +++ b/src/test/test_tortls.c @@ -1808,9 +1808,10 @@ test_tortls_debug_state_callback(void *ignored) tor_tls_debug_state_callback(ssl, 32, 45); - n = snprintf(buf, 1000, "SSL %p is now in state unknown" + n = tor_snprintf(buf, 1000, "SSL %p is now in state unknown" " state [type=32,val=45].\n", ssl); - buf[n]='\0'; + /* tor's snprintf returns -1 on error */ + tt_int_op(n, OP_NE, -1); expect_log_msg(buf); done: