Defer reporting directory bootstrap progress

Existing cached directory information can cause misleadingly high
bootstrap percentages.  To improve user experience, defer reporting of
directory information progress until at least one connection has
succeeded to a relay or bridge.

Closes ticket 27169.
This commit is contained in:
Taylor Yu 2018-08-31 12:56:23 -05:00
parent 687bf3ea64
commit 617160895c
8 changed files with 124 additions and 8 deletions

6
changes/ticket27169 Normal file
View File

@ -0,0 +1,6 @@
o Minor features (bootstrap):
- Improve user experience by deferring directory progress
reporting until after a connection to a relay or bridge has
succeeded. This avoids reporting 80% progress based on cached
directory information when we can't even connect to a bridge or
relay. Closes ticket 27169.

View File

@ -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.", log_debug(LD_HANDSHAKE,"OR connect() to router at %s:%u finished.",
conn->address,conn->port); conn->address,conn->port);
control_event_bootstrap(BOOTSTRAP_STATUS_HANDSHAKE, 0); control_event_bootstrap(BOOTSTRAP_STATUS_HANDSHAKE, 0);
control_event_boot_first_orconn();
if (proxy_type != PROXY_NONE) { if (proxy_type != PROXY_NONE) {
/* start proxy handshake */ /* start proxy handshake */

View File

@ -1389,8 +1389,8 @@ connection_edge_process_relay_cell_not_open(
case DIR_PURPOSE_FETCH_SERVERDESC: case DIR_PURPOSE_FETCH_SERVERDESC:
case DIR_PURPOSE_FETCH_MICRODESC: case DIR_PURPOSE_FETCH_MICRODESC:
if (TO_DIR_CONN(dirconn)->router_purpose == ROUTER_PURPOSE_GENERAL) if (TO_DIR_CONN(dirconn)->router_purpose == ROUTER_PURPOSE_GENERAL)
control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS,
count_loading_descriptors_progress()); count_loading_descriptors_progress());
break; break;
} }
} }

View File

@ -7178,6 +7178,45 @@ control_event_bootstrap(bootstrap_status_t status, int progress)
} }
} }
/** 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 /** Called when Tor has failed to make bootstrapping progress in a way
* that indicates a problem. <b>warn</b> gives a human-readable hint * that indicates a problem. <b>warn</b> gives a human-readable hint
* as to why, and <b>reason</b> provides a controller-facing short * as to why, and <b>reason</b> provides a controller-facing short

View File

@ -195,6 +195,8 @@ void control_event_bootstrap(bootstrap_status_t status, int progress);
MOCK_DECL(void, control_event_bootstrap_prob_or,(const char *warn, MOCK_DECL(void, control_event_bootstrap_prob_or,(const char *warn,
int reason, int reason,
or_connection_t *or_conn)); 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, void control_event_bootstrap_problem(const char *warn, const char *reason,
const connection_t *conn, int dowarn); const connection_t *conn, int dowarn);

View File

@ -2226,8 +2226,8 @@ load_downloaded_routers(const char *body, smartlist_t *which,
added = router_load_routers_from_string(body, NULL, SAVED_NOWHERE, which, added = router_load_routers_from_string(body, NULL, SAVED_NOWHERE, which,
descriptor_digests, buf); descriptor_digests, buf);
if (added && general) if (added && general)
control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS,
count_loading_descriptors_progress()); count_loading_descriptors_progress());
return added; return added;
} }
@ -2949,8 +2949,8 @@ handle_response_fetch_microdesc(dir_connection_t *conn,
dir_microdesc_download_failed(which, status_code, conn->identity_digest); dir_microdesc_download_failed(which, status_code, conn->identity_digest);
} }
if (mds && smartlist_len(mds)) { if (mds && smartlist_len(mds)) {
control_event_bootstrap(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS, control_event_boot_dir(BOOTSTRAP_STATUS_LOADING_DESCRIPTORS,
count_loading_descriptors_progress()); count_loading_descriptors_progress());
directory_info_has_arrived(now, 0, 1); directory_info_has_arrived(now, 0, 1);
} }
SMARTLIST_FOREACH(which, char *, cp, tor_free(cp)); SMARTLIST_FOREACH(which, char *, cp, tor_free(cp));

View File

@ -2528,7 +2528,7 @@ update_router_have_minimum_dir_info(void)
(int)(paths*100), status); (int)(paths*100), status);
tor_free(status); tor_free(status);
res = 0; res = 0;
control_event_bootstrap(BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, 0); control_event_boot_dir(BOOTSTRAP_STATUS_REQUESTING_DESCRIPTORS, 0);
goto done; goto done;
} }
@ -2553,7 +2553,7 @@ update_router_have_minimum_dir_info(void)
/* If paths have just become available in this update. */ /* If paths have just become available in this update. */
if (res && !have_min_dir_info) { if (res && !have_min_dir_info) {
control_event_client_status(LOG_NOTICE, "ENOUGH_DIR_INFO"); control_event_client_status(LOG_NOTICE, "ENOUGH_DIR_INFO");
control_event_bootstrap(BOOTSTRAP_STATUS_CONN_OR, 0); control_event_boot_dir(BOOTSTRAP_STATUS_CONN_OR, 0);
log_info(LD_DIR, log_info(LD_DIR,
"We now have enough directory information to build circuits."); "We now have enough directory information to build circuits.");
} }

View File

@ -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) \ #define TEST(name, flags) \
{ #name, test_cntev_ ## name, flags, 0, NULL } { #name, test_cntev_ ## name, flags, 0, NULL }
@ -330,5 +396,7 @@ struct testcase_t controller_event_tests[] = {
TEST(append_cell_stats, TT_FORK), TEST(append_cell_stats, TT_FORK),
TEST(format_cell_stats, TT_FORK), TEST(format_cell_stats, TT_FORK),
TEST(event_mask, TT_FORK), TEST(event_mask, TT_FORK),
TEST(dirboot_defer_desc, TT_FORK),
TEST(dirboot_defer_orconn, TT_FORK),
END_OF_TESTCASES END_OF_TESTCASES
}; };