diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/core/or/circuitbuild.c | 12 | ||||
| -rw-r--r-- | src/core/or/connection_or.c | 1 | ||||
| -rw-r--r-- | src/core/or/relay.c | 4 | ||||
| -rw-r--r-- | src/feature/control/control.c | 139 | ||||
| -rw-r--r-- | src/feature/control/control.h | 4 | ||||
| -rw-r--r-- | src/feature/dircache/directory.c | 8 | ||||
| -rw-r--r-- | src/feature/nodelist/nodelist.c | 9 | ||||
| -rw-r--r-- | src/test/test_controller_events.c | 68 |
8 files changed, 181 insertions, 64 deletions
diff --git a/src/core/or/circuitbuild.c b/src/core/or/circuitbuild.c index 7d8052397f..3693b8b2ca 100644 --- a/src/core/or/circuitbuild.c +++ b/src/core/or/circuitbuild.c @@ -1051,14 +1051,10 @@ circuit_build_no_more_hops(origin_circuit_t *circ) const or_options_t *options = get_options(); note_that_we_completed_a_circuit(); /* FFFF Log a count of known routers here */ - log_notice(LD_GENERAL, - "Tor has successfully opened a circuit. " - "Looks like client functionality is working."); - if (control_event_bootstrap(BOOTSTRAP_STATUS_DONE, 0) == 0) { - log_notice(LD_GENERAL, - "Tor has successfully opened a circuit. " - "Looks like client functionality is working."); - } + log_info(LD_GENERAL, + "Tor has successfully opened a circuit. " + "Looks like client functionality is working."); + control_event_bootstrap(BOOTSTRAP_STATUS_DONE, 0); control_event_client_status(LOG_NOTICE, "CIRCUIT_ESTABLISHED"); clear_broken_connection_map(1); if (server_mode(options) && !check_whether_orport_reachable(options)) { diff --git a/src/core/or/connection_or.c b/src/core/or/connection_or.c index 08371d1ad7..e6b2354012 100644 --- a/src/core/or/connection_or.c +++ b/src/core/or/connection_or.c @@ -705,6 +705,7 @@ connection_or_finished_connecting(or_connection_t *or_conn) log_debug(LD_HANDSHAKE,"OR connect() to router at %s:%u finished.", conn->address,conn->port); control_event_bootstrap(BOOTSTRAP_STATUS_HANDSHAKE, 0); + control_event_boot_first_orconn(); if (proxy_type != PROXY_NONE) { /* start proxy handshake */ diff --git a/src/core/or/relay.c b/src/core/or/relay.c index 6e1adfaff3..1d0be0c894 100644 --- a/src/core/or/relay.c +++ b/src/core/or/relay.c @@ -1389,8 +1389,8 @@ connection_edge_process_relay_cell_not_open( case DIR_PURPOSE_FETCH_SERVERDESC: case DIR_PURPOSE_FETCH_MICRODESC: if (TO_DIR_CONN(dirconn)->router_purpose == ROUTER_PURPOSE_GENERAL) - control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, - count_loading_descriptors_progress()); + control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, + count_loading_descriptors_progress()); break; } } diff --git a/src/feature/control/control.c b/src/feature/control/control.c index 9e7d21308e..2fac3bd6de 100644 --- a/src/feature/control/control.c +++ b/src/feature/control/control.c @@ -7073,6 +7073,11 @@ bootstrap_status_to_string(bootstrap_status_t s, const char **tag, * Tor initializes. */ static int bootstrap_percent = BOOTSTRAP_STATUS_UNDEF; +/** Like bootstrap_percent, but only takes on the enumerated values in + * bootstrap_status_t. + */ +static int bootstrap_phase = BOOTSTRAP_STATUS_UNDEF; + /** As bootstrap_percent, but holds the bootstrapping level at which we last * logged a NOTICE-level message. We use this, plus BOOTSTRAP_PCT_INCREMENT, * to avoid flooding the log with a new message every time we get a few more @@ -7095,23 +7100,46 @@ static int bootstrap_problems = 0; */ #define BOOTSTRAP_PCT_INCREMENT 5 +/** Do the actual logging and notifications for + * control_event_bootstrap(). Doesn't change any state beyond that. + */ +static void +control_event_bootstrap_core(int loglevel, bootstrap_status_t status, + int progress) +{ + char buf[BOOTSTRAP_MSG_LEN]; + const char *tag, *summary; + + bootstrap_status_to_string(status, &tag, &summary); + /* Locally reset status if there's incremental progress */ + if (progress) + status = progress; + + tor_log(loglevel, LD_CONTROL, + "Bootstrapped %d%%: %s", status, summary); + tor_snprintf(buf, sizeof(buf), + "BOOTSTRAP PROGRESS=%d TAG=%s SUMMARY=\"%s\"", + status, tag, summary); + tor_snprintf(last_sent_bootstrap_message, + sizeof(last_sent_bootstrap_message), + "NOTICE %s", buf); + control_event_client_status(LOG_NOTICE, "%s", buf); +} + /** Called when Tor has made progress at bootstrapping its directory * information and initial circuits. * * <b>status</b> is the new status, that is, what task we will be doing * next. <b>progress</b> is zero if we just started this task, else it * represents progress on the task. - * - * Return true if we logged a message at level NOTICE, and false otherwise. */ -int +void control_event_bootstrap(bootstrap_status_t status, int progress) { - const char *tag, *summary; - char buf[BOOTSTRAP_MSG_LEN]; + int loglevel = LOG_NOTICE; if (bootstrap_percent == BOOTSTRAP_STATUS_DONE) - return 0; /* already bootstrapped; nothing to be done here. */ + return; /* already bootstrapped; nothing to be done here. */ /* special case for handshaking status, since our TLS handshaking code * can't distinguish what the connection is going to be for. */ @@ -7123,45 +7151,70 @@ control_event_bootstrap(bootstrap_status_t status, int progress) } } - if (status > bootstrap_percent || - (progress && progress > bootstrap_percent)) { - int loglevel = LOG_NOTICE; - bootstrap_status_to_string(status, &tag, &summary); - - if (status <= bootstrap_percent && - (progress < notice_bootstrap_percent + BOOTSTRAP_PCT_INCREMENT)) { - /* We log the message at info if the status hasn't advanced, and if less - * than BOOTSTRAP_PCT_INCREMENT progress has been made. - */ + if (status <= bootstrap_percent) { + /* If there's no new progress, return early. */ + if (!progress || progress <= bootstrap_percent) + return; + /* Log at INFO if not enough progress happened. */ + if (progress < notice_bootstrap_percent + BOOTSTRAP_PCT_INCREMENT) loglevel = LOG_INFO; - } + } - tor_log(loglevel, LD_CONTROL, - "Bootstrapped %d%%: %s", progress ? progress : status, summary); - tor_snprintf(buf, sizeof(buf), - "BOOTSTRAP PROGRESS=%d TAG=%s SUMMARY=\"%s\"", - progress ? progress : status, tag, summary); - tor_snprintf(last_sent_bootstrap_message, - sizeof(last_sent_bootstrap_message), - "NOTICE %s", buf); - control_event_client_status(LOG_NOTICE, "%s", buf); - if (status > bootstrap_percent) { - bootstrap_percent = status; /* new milestone reached */ - } - if (progress > bootstrap_percent) { - /* incremental progress within a milestone */ - bootstrap_percent = progress; - bootstrap_problems = 0; /* Progress! Reset our problem counter. */ - } - if (loglevel == LOG_NOTICE && - bootstrap_percent > notice_bootstrap_percent) { - /* Remember that we gave a notice at this level. */ - notice_bootstrap_percent = bootstrap_percent; - } - return loglevel == LOG_NOTICE; + control_event_bootstrap_core(loglevel, status, progress); + + if (status > bootstrap_percent) { + bootstrap_phase = status; /* new milestone reached */ + bootstrap_percent = status; + } + if (progress > bootstrap_percent) { + /* incremental progress within a milestone */ + bootstrap_percent = progress; + bootstrap_problems = 0; /* Progress! Reset our problem counter. */ } + if (loglevel == LOG_NOTICE && + bootstrap_percent > notice_bootstrap_percent) { + /* Remember that we gave a notice at this level. */ + notice_bootstrap_percent = bootstrap_percent; + } +} - return 0; +/** Flag whether we've opened an OR_CONN yet */ +static int bootstrap_first_orconn = 0; + +/** Like bootstrap_phase, but for (possibly deferred) directory progress */ +static int bootstrap_dir_phase = BOOTSTRAP_STATUS_UNDEF; + +/** Like bootstrap_problems, but for (possibly deferred) directory progress */ +static int bootstrap_dir_progress = BOOTSTRAP_STATUS_UNDEF; + +/** Defer directory info bootstrap events until we have successfully + * completed our first connection to a router. */ +void +control_event_boot_dir(bootstrap_status_t status, int progress) +{ + if (status > bootstrap_dir_progress) { + bootstrap_dir_progress = status; + bootstrap_dir_phase = status; + } + if (progress && progress >= bootstrap_dir_progress) { + bootstrap_dir_progress = progress; + } + + /* Don't report unless we have successfully opened at least one OR_CONN */ + if (!bootstrap_first_orconn) + return; + + control_event_bootstrap(status, progress); +} + +/** Set a flag to allow reporting of directory bootstrap progress. + * (Code that reports completion of an OR_CONN calls this.) Also, + * report directory progress so far. */ +void +control_event_boot_first_orconn(void) +{ + bootstrap_first_orconn = 1; + control_event_bootstrap(bootstrap_dir_phase, bootstrap_dir_progress); } /** Called when Tor has failed to make bootstrapping progress in a way @@ -7198,9 +7251,7 @@ control_event_bootstrap_problem(const char *warn, const char *reason, if (we_are_hibernating()) 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 */ + tor_assert(bootstrap_status_to_string(bootstrap_phase, &tag, &summary) == 0); severity = dowarn ? LOG_WARN : LOG_INFO; diff --git a/src/feature/control/control.h b/src/feature/control/control.h index 5c5fe8a917..3445eb0a9d 100644 --- a/src/feature/control/control.h +++ b/src/feature/control/control.h @@ -191,10 +191,12 @@ void enable_control_logging(void); void monitor_owning_controller_process(const char *process_spec); -int control_event_bootstrap(bootstrap_status_t status, int progress); +void control_event_bootstrap(bootstrap_status_t status, int progress); MOCK_DECL(void, control_event_bootstrap_prob_or,(const char *warn, int reason, or_connection_t *or_conn)); +void control_event_boot_dir(bootstrap_status_t status, int progress); +void control_event_boot_first_orconn(void); void control_event_bootstrap_problem(const char *warn, const char *reason, const connection_t *conn, int dowarn); diff --git a/src/feature/dircache/directory.c b/src/feature/dircache/directory.c index de0bcdbfa7..b94c5317af 100644 --- a/src/feature/dircache/directory.c +++ b/src/feature/dircache/directory.c @@ -2226,8 +2226,8 @@ load_downloaded_routers(const char *body, smartlist_t *which, added = router_load_routers_from_string(body, NULL, SAVED_NOWHERE, which, descriptor_digests, buf); if (added && general) - control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, - count_loading_descriptors_progress()); + control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, + count_loading_descriptors_progress()); return added; } @@ -2949,8 +2949,8 @@ handle_response_fetch_microdesc(dir_connection_t *conn, dir_microdesc_download_failed(which, status_code, conn->identity_digest); } if (mds && smartlist_len(mds)) { - control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, - count_loading_descriptors_progress()); + control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, + count_loading_descriptors_progress()); directory_info_has_arrived(now, 0, 1); } SMARTLIST_FOREACH(which, char *, cp, tor_free(cp)); diff --git a/src/feature/nodelist/nodelist.c b/src/feature/nodelist/nodelist.c index e62e87ea70..50dc8f7d3c 100644 --- a/src/feature/nodelist/nodelist.c +++ b/src/feature/nodelist/nodelist.c @@ -2528,7 +2528,7 @@ update_router_have_minimum_dir_info(void) (int)(paths*100), status); tor_free(status); res = 0; - control_event_bootstrap(BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, 0); + control_event_boot_dir(BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, 0); goto done; } @@ -2553,10 +2553,9 @@ update_router_have_minimum_dir_info(void) /* If paths have just become available in this update. */ if (res && !have_min_dir_info) { control_event_client_status(LOG_NOTICE, "ENOUGH_DIR_INFO"); - if (control_event_bootstrap(BOOTSTRAP_STATUS_CONN_OR, 0) == 0) { - log_notice(LD_DIR, - "We now have enough directory information to build circuits."); - } + control_event_boot_dir(BOOTSTRAP_STATUS_CONN_OR, 0); + log_info(LD_DIR, + "We now have enough directory information to build circuits."); } /* If paths have just become unavailable in this update. */ diff --git a/src/test/test_controller_events.c b/src/test/test_controller_events.c index e935b70428..4c404876b0 100644 --- a/src/test/test_controller_events.c +++ b/src/test/test_controller_events.c @@ -322,6 +322,72 @@ test_cntev_event_mask(void *arg) ; } +static char *saved_event_str = NULL; + +static void +mock_queue_control_event_string(uint16_t event, char *msg) +{ + (void)event; + + tor_free(saved_event_str); + saved_event_str = msg; +} + +/* Helper macro for checking bootstrap control event strings */ +#define assert_bootmsg(s) \ + tt_ptr_op(strstr(saved_event_str, "650 STATUS_CLIENT NOTICE " \ + "BOOTSTRAP PROGRESS=" s), OP_EQ, saved_event_str) + +/* Test deferral of directory bootstrap messages (requesting_descriptors) */ +static void +test_cntev_dirboot_defer_desc(void *arg) +{ + (void)arg; + + MOCK(queue_control_event_string, mock_queue_control_event_string); + control_testing_set_global_event_mask(EVENT_MASK_(EVENT_STATUS_CLIENT)); + control_event_bootstrap(BOOTSTRAP_STATUS_STARTING, 0); + assert_bootmsg("0 TAG=starting"); + /* This event should get deferred */ + control_event_boot_dir(BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, 0); + assert_bootmsg("0 TAG=starting"); + control_event_bootstrap(BOOTSTRAP_STATUS_CONN_DIR, 0); + assert_bootmsg("5 TAG=conn_dir"); + control_event_bootstrap(BOOTSTRAP_STATUS_HANDSHAKE, 0); + assert_bootmsg("10 TAG=handshake_dir"); + /* The deferred event should appear */ + control_event_boot_first_orconn(); + assert_bootmsg("45 TAG=requesting_descriptors"); + done: + tor_free(saved_event_str); + UNMOCK(queue_control_event_string); +} + +/* Test deferral of directory bootstrap messages (conn_or) */ +static void +test_cntev_dirboot_defer_orconn(void *arg) +{ + (void)arg; + + MOCK(queue_control_event_string, mock_queue_control_event_string); + control_testing_set_global_event_mask(EVENT_MASK_(EVENT_STATUS_CLIENT)); + control_event_bootstrap(BOOTSTRAP_STATUS_STARTING, 0); + assert_bootmsg("0 TAG=starting"); + /* This event should get deferred */ + control_event_boot_dir(BOOTSTRAP_STATUS_CONN_OR, 0); + assert_bootmsg("0 TAG=starting"); + control_event_bootstrap(BOOTSTRAP_STATUS_CONN_DIR, 0); + assert_bootmsg("5 TAG=conn_dir"); + control_event_bootstrap(BOOTSTRAP_STATUS_HANDSHAKE, 0); + assert_bootmsg("10 TAG=handshake_dir"); + /* The deferred event should appear */ + control_event_boot_first_orconn(); + assert_bootmsg("80 TAG=conn_or"); + done: + tor_free(saved_event_str); + UNMOCK(queue_control_event_string); +} + #define TEST(name, flags) \ { #name, test_cntev_ ## name, flags, 0, NULL } @@ -330,5 +396,7 @@ struct testcase_t controller_event_tests[] = { TEST(append_cell_stats, TT_FORK), TEST(format_cell_stats, TT_FORK), TEST(event_mask, TT_FORK), + TEST(dirboot_defer_desc, TT_FORK), + TEST(dirboot_defer_orconn, TT_FORK), END_OF_TESTCASES }; |