diff --git a/changes/bug23506 b/changes/bug23506 new file mode 100644 index 0000000000..f2efad4e7e --- /dev/null +++ b/changes/bug23506 @@ -0,0 +1,4 @@ + o Major bugfixes (usability, control port): + - Report trusted clock skew indications as bootstrap errors, so + controllers can more easily alert users. Fixes bug 23506; + bugfix on 0.1.2.6-alpha. diff --git a/src/or/connection.c b/src/or/connection.c index 5c675acca4..b831d231b0 100644 --- a/src/or/connection.c +++ b/src/or/connection.c @@ -5221,7 +5221,7 @@ clock_skew_warning(const connection_t *conn, long apparent_skew, int trusted, const char *source) { char dbuf[64]; - char *ext_source = NULL; + char *ext_source = NULL, *warn = NULL; format_time_interval(dbuf, sizeof(dbuf), apparent_skew); if (conn) tor_asprintf(&ext_source, "%s:%s:%d", source, conn->address, conn->port); @@ -5235,9 +5235,14 @@ clock_skew_warning(const connection_t *conn, long apparent_skew, int trusted, apparent_skew > 0 ? "ahead" : "behind", dbuf, apparent_skew > 0 ? "behind" : "ahead", (!conn || trusted) ? "" : ", or they are sending us the wrong time"); - if (trusted) + if (trusted) { control_event_general_status(LOG_WARN, "CLOCK_SKEW SKEW=%ld SOURCE=%s", apparent_skew, ext_source); + tor_asprintf(&warn, "Clock skew %ld in %s from %s", apparent_skew, + received, source); + control_event_bootstrap_problem(warn, "CLOCK_SKEW", conn, 1); + } + tor_free(warn); tor_free(ext_source); } diff --git a/src/or/connection_or.c b/src/or/connection_or.c index d890b58da6..e4fda7ce78 100644 --- a/src/or/connection_or.c +++ b/src/or/connection_or.c @@ -727,7 +727,7 @@ connection_or_about_to_close(or_connection_t *or_conn) control_event_or_conn_status(or_conn, OR_CONN_EVENT_FAILED, reason); if (!authdir_mode_tests_reachability(options)) - control_event_bootstrap_problem( + control_event_bootstrap_prob_or( orconn_end_reason_to_control_string(reason), reason, or_conn); } @@ -1113,7 +1113,7 @@ connection_or_connect_failed(or_connection_t *conn, { control_event_or_conn_status(conn, OR_CONN_EVENT_FAILED, reason); if (!authdir_mode_tests_reachability(get_options())) - control_event_bootstrap_problem(msg, reason, conn); + control_event_bootstrap_prob_or(msg, reason, conn); } /** conn got an error in connection_handle_read_impl() or @@ -1236,7 +1236,7 @@ connection_or_connect, (const tor_addr_t *_addr, uint16_t port, fmt_addrport(&TO_CONN(conn)->addr, TO_CONN(conn)->port), transport_name, transport_name); - control_event_bootstrap_problem( + control_event_bootstrap_prob_or( "Can't connect to bridge", END_OR_CONN_REASON_PT_MISSING, conn); @@ -1714,7 +1714,7 @@ connection_or_client_learned_peer_id(or_connection_t *conn, control_event_or_conn_status(conn, OR_CONN_EVENT_FAILED, END_OR_CONN_REASON_OR_IDENTITY); if (!authdir_mode_tests_reachability(options)) - control_event_bootstrap_problem( + control_event_bootstrap_prob_or( "Unexpected identity in router certificate", END_OR_CONN_REASON_OR_IDENTITY, conn); diff --git a/src/or/control.c b/src/or/control.c index c11193f397..ce2a4c8cfd 100644 --- a/src/or/control.c +++ b/src/or/control.c @@ -6754,80 +6754,112 @@ control_event_bootstrap(bootstrap_status_t status, int progress) } /** Called when Tor has failed to make bootstrapping progress in a way - * that indicates a problem. warn gives a hint as to why, and - * reason provides an "or_conn_end_reason" tag. or_conn - * is the connection that caused this problem. + * that indicates a problem. warn gives a human-readable hint + * as to why, and reason provides a controller-facing short + * tag. conn is the connection that caused this problem and + * can be NULL if a connection cannot be easily identified. */ -MOCK_IMPL(void, -control_event_bootstrap_problem, (const char *warn, int reason, - or_connection_t *or_conn)) +void +control_event_bootstrap_problem(const char *warn, const char *reason, + const connection_t *conn, int dowarn) { int status = bootstrap_percent; const char *tag = "", *summary = ""; char buf[BOOTSTRAP_MSG_LEN]; const char *recommendation = "ignore"; int severity; + char *or_id = NULL, *hostaddr = NULL; + or_connection_t *or_conn = NULL; /* bootstrap_percent must not be in "undefined" state here. */ tor_assert(status >= 0); - if (or_conn->have_noted_bootstrap_problem) - return; - - or_conn->have_noted_bootstrap_problem = 1; - if (bootstrap_percent == 100) return; /* already bootstrapped; nothing to be done here. */ bootstrap_problems++; if (bootstrap_problems >= BOOTSTRAP_PROBLEM_THRESHOLD) - recommendation = "warn"; - - if (reason == END_OR_CONN_REASON_NO_ROUTE) - recommendation = "warn"; - - /* If we are using bridges and all our OR connections are now - closed, it means that we totally failed to connect to our - bridges. Throw a warning. */ - if (get_options()->UseBridges && !any_other_active_or_conns(or_conn)) - recommendation = "warn"; + dowarn = 1; if (we_are_hibernating()) - recommendation = "ignore"; + dowarn = 0; while (status>=0 && bootstrap_status_to_string(status, &tag, &summary) < 0) status--; /* find a recognized status string based on current progress */ status = bootstrap_percent; /* set status back to the actual number */ - severity = !strcmp(recommendation, "warn") ? LOG_WARN : LOG_INFO; + severity = dowarn ? LOG_WARN : LOG_INFO; + + if (dowarn) + recommendation = "warn"; + + if (conn && conn->type == CONN_TYPE_OR) { + /* XXX TO_OR_CONN can't deal with const */ + or_conn = TO_OR_CONN((connection_t *)conn); + or_id = tor_strdup(hex_str(or_conn->identity_digest, DIGEST_LEN)); + } else { + or_id = tor_strdup("?"); + } + + if (conn) + tor_asprintf(&hostaddr, "%s:%d", conn->address, (int)conn->port); + else + hostaddr = tor_strdup("?"); log_fn(severity, LD_CONTROL, "Problem bootstrapping. Stuck at %d%%: %s. (%s; %s; " - "count %d; recommendation %s; host %s at %s:%d)", - status, summary, warn, - orconn_end_reason_to_control_string(reason), + "count %d; recommendation %s; host %s at %s)", + status, summary, warn, reason, bootstrap_problems, recommendation, - hex_str(or_conn->identity_digest, DIGEST_LEN), - or_conn->base_.address, - or_conn->base_.port); + or_id, hostaddr); connection_or_report_broken_states(severity, LD_HANDSHAKE); tor_snprintf(buf, sizeof(buf), "BOOTSTRAP PROGRESS=%d TAG=%s SUMMARY=\"%s\" WARNING=\"%s\" REASON=%s " - "COUNT=%d RECOMMENDATION=%s HOSTID=\"%s\" HOSTADDR=\"%s:%d\"", - bootstrap_percent, tag, summary, warn, - orconn_end_reason_to_control_string(reason), bootstrap_problems, + "COUNT=%d RECOMMENDATION=%s HOSTID=\"%s\" HOSTADDR=\"%s\"", + bootstrap_percent, tag, summary, warn, reason, bootstrap_problems, recommendation, - hex_str(or_conn->identity_digest, DIGEST_LEN), - or_conn->base_.address, - (int)or_conn->base_.port); + or_id, hostaddr); tor_snprintf(last_sent_bootstrap_message, sizeof(last_sent_bootstrap_message), "WARN %s", buf); control_event_client_status(LOG_WARN, "%s", buf); + + tor_free(hostaddr); + tor_free(or_id); +} + +/** Called when Tor has failed to make bootstrapping progress in a way + * that indicates a problem. warn gives a hint as to why, and + * reason provides an "or_conn_end_reason" tag. or_conn + * is the connection that caused this problem. + */ +MOCK_IMPL(void, +control_event_bootstrap_prob_or, (const char *warn, int reason, + or_connection_t *or_conn)) +{ + int dowarn = 0; + + if (or_conn->have_noted_bootstrap_problem) + return; + + or_conn->have_noted_bootstrap_problem = 1; + + if (reason == END_OR_CONN_REASON_NO_ROUTE) + dowarn = 1; + + /* If we are using bridges and all our OR connections are now + closed, it means that we totally failed to connect to our + bridges. Throw a warning. */ + if (get_options()->UseBridges && !any_other_active_or_conns(or_conn)) + dowarn = 1; + + control_event_bootstrap_problem(warn, + orconn_end_reason_to_control_string(reason), + TO_CONN(or_conn), dowarn); } /** We just generated a new summary of which countries we've seen clients diff --git a/src/or/control.h b/src/or/control.h index 5f6dcc352b..8003126f3e 100644 --- a/src/or/control.h +++ b/src/or/control.h @@ -99,9 +99,11 @@ void enable_control_logging(void); void monitor_owning_controller_process(const char *process_spec); int control_event_bootstrap(bootstrap_status_t status, int progress); -MOCK_DECL(void, control_event_bootstrap_problem,(const char *warn, +MOCK_DECL(void, control_event_bootstrap_prob_or,(const char *warn, int reason, or_connection_t *or_conn)); +void control_event_bootstrap_problem(const char *warn, const char *reason, + const connection_t *conn, int dowarn); void control_event_clients_seen(const char *controller_str); void control_event_transport_launched(const char *mode, diff --git a/src/or/networkstatus.c b/src/or/networkstatus.c index 8b07a88853..7953af1cc7 100644 --- a/src/or/networkstatus.c +++ b/src/or/networkstatus.c @@ -1989,14 +1989,16 @@ networkstatus_set_current_consensus(const char *consensus, char tbuf[ISO_TIME_LEN+1]; char dbuf[64]; long delta = now - c->valid_after; + char *flavormsg = NULL; format_iso_time(tbuf, c->valid_after); format_time_interval(dbuf, sizeof(dbuf), delta); log_warn(LD_GENERAL, "Our clock is %s behind the time published in the " "consensus network status document (%s UTC). Tor needs an " "accurate clock to work correctly. Please check your time and " "date settings!", dbuf, tbuf); - control_event_general_status(LOG_WARN, - "CLOCK_SKEW MIN_SKEW=%ld SOURCE=CONSENSUS", delta); + tor_asprintf(&flavormsg, "%s flavor consensus", flavor); + clock_skew_warning(NULL, delta, 1, LD_GENERAL, flavormsg, "CONSENSUS"); + tor_free(flavormsg); } router_dir_info_changed(); diff --git a/src/test/test_extorport.c b/src/test/test_extorport.c index 9e8721ee36..e18deb2700 100644 --- a/src/test/test_extorport.c +++ b/src/test/test_extorport.c @@ -497,14 +497,14 @@ test_ext_or_handshake(void *arg) "te road There is always another ", 64); /* Send the wrong response. */ WRITE("not with a bang but a whimper...", 32); - MOCK(control_event_bootstrap_problem, ignore_bootstrap_problem); + MOCK(control_event_bootstrap_prob_or, ignore_bootstrap_problem); tt_int_op(-1, OP_EQ, connection_ext_or_process_inbuf(conn)); CONTAINS("\x00", 1); tt_assert(TO_CONN(conn)->marked_for_close); /* XXXX Hold-open-until-flushed. */ close_closeable_connections(); conn = NULL; - UNMOCK(control_event_bootstrap_problem); + UNMOCK(control_event_bootstrap_prob_or); MOCK(connection_start_reading, note_read_started); MOCK(connection_stop_reading, note_read_stopped); @@ -552,26 +552,26 @@ test_ext_or_handshake(void *arg) do_ext_or_handshake(conn); /* USERADDR command with an extra NUL byte */ WRITE("\x00\x01\x00\x0d""1.2.3.4:5678\x00", 17); - MOCK(control_event_bootstrap_problem, ignore_bootstrap_problem); + MOCK(control_event_bootstrap_prob_or, ignore_bootstrap_problem); tt_int_op(-1, OP_EQ, connection_ext_or_process_inbuf(conn)); CONTAINS("", 0); tt_assert(TO_CONN(conn)->marked_for_close); close_closeable_connections(); conn = NULL; - UNMOCK(control_event_bootstrap_problem); + UNMOCK(control_event_bootstrap_prob_or); /* Now fail the TRANSPORT command. */ conn = or_connection_new(CONN_TYPE_EXT_OR, AF_INET); do_ext_or_handshake(conn); /* TRANSPORT command with an extra NUL byte */ WRITE("\x00\x02\x00\x08""rfc1149\x00", 12); - MOCK(control_event_bootstrap_problem, ignore_bootstrap_problem); + MOCK(control_event_bootstrap_prob_or, ignore_bootstrap_problem); tt_int_op(-1, OP_EQ, connection_ext_or_process_inbuf(conn)); CONTAINS("", 0); tt_assert(TO_CONN(conn)->marked_for_close); close_closeable_connections(); conn = NULL; - UNMOCK(control_event_bootstrap_problem); + UNMOCK(control_event_bootstrap_prob_or); /* Now fail the TRANSPORT command. */ conn = or_connection_new(CONN_TYPE_EXT_OR, AF_INET); @@ -579,13 +579,13 @@ test_ext_or_handshake(void *arg) /* TRANSPORT command with transport name with symbols (not a C-identifier) */ WRITE("\x00\x02\x00\x07""rf*1149", 11); - MOCK(control_event_bootstrap_problem, ignore_bootstrap_problem); + MOCK(control_event_bootstrap_prob_or, ignore_bootstrap_problem); tt_int_op(-1, OP_EQ, connection_ext_or_process_inbuf(conn)); CONTAINS("", 0); tt_assert(TO_CONN(conn)->marked_for_close); close_closeable_connections(); conn = NULL; - UNMOCK(control_event_bootstrap_problem); + UNMOCK(control_event_bootstrap_prob_or); done: UNMOCK(connection_write_to_buf_impl_);