commit 9e6235d290fce3eac4b9aa39da21a4f4479292c6 Author: George Kadianakis desnacked@riseup.net Date: Tue Jul 17 11:00:18 2018 -0400

Fix time source bug in sr_state_get_start_time_of_current_protocol_run().

The following bug was causing many issues for this branch in chutney:

In sr_state_get_start_time_of_current_protocol_run() we were using the consensus valid-after to calculate beginning_of_current_round, but we were using time(NULL) to calculate the current_round slot. This was causing time sync issues when the consensus valid-after and time(NULL) were disagreeing on what the current round is. Our fix is to use the consensus valid-after in both places.

This also means that we are not using 'now' (aka time(NULL)) anymore in that function, and hence we can remove that argument from the function (and its callers). I'll do this in the next commit so that we keep things separated.

Furthermore, we fix a unittest that broke. --- src/or/hs_common.c | 3 +-- src/or/hs_service.c | 25 +++++++++---------------- src/or/shared_random_client.c | 27 +++++++++++++++++---------- src/or/shared_random_client.h | 4 ++-- src/test/test_hs_common.c | 9 +++++---- src/test/test_shared_random.c | 14 +++++--------- 6 files changed, 39 insertions(+), 43 deletions(-)

diff --git a/src/or/hs_common.c b/src/or/hs_common.c index e88a04620..0750785e4 100644 --- a/src/or/hs_common.c +++ b/src/or/hs_common.c @@ -1102,8 +1102,7 @@ hs_in_period_between_tp_and_srv,(const networkstatus_t *consensus, time_t now)) /* Get start time of next TP and of current SRV protocol run, and check if we * are between them. */ valid_after = consensus->valid_after; - srv_start_time = - sr_state_get_start_time_of_current_protocol_run(valid_after); + srv_start_time = sr_state_get_start_time_of_current_protocol_run(); tp_start_time = hs_get_start_time_of_next_time_period(srv_start_time);

if (valid_after >= srv_start_time && valid_after < tp_start_time) { diff --git a/src/or/hs_service.c b/src/or/hs_service.c index 5430ef4d8..b4460b2ac 100644 --- a/src/or/hs_service.c +++ b/src/or/hs_service.c @@ -1946,19 +1946,12 @@ cleanup_intro_points(hs_service_t *service, time_t now) /* Set the next rotation time of the descriptors for the given service for the * time now. */ static void -set_rotation_time(hs_service_t *service, time_t now) +set_rotation_time(hs_service_t *service) { - time_t valid_after; - const networkstatus_t *ns = networkstatus_get_live_consensus(now); - if (ns) { - valid_after = ns->valid_after; - } else { - valid_after = now; - } - tor_assert(service); + service->state.next_rotation_time = - sr_state_get_start_time_of_current_protocol_run(valid_after) + + sr_state_get_start_time_of_current_protocol_run() + sr_state_get_protocol_run_duration();

{ @@ -2025,7 +2018,7 @@ should_rotate_descriptors(hs_service_t *service, time_t now) * will be freed, the next one put in as the current and finally the next * descriptor pointer is NULLified. */ static void -rotate_service_descriptors(hs_service_t *service, time_t now) +rotate_service_descriptors(hs_service_t *service) { if (service->desc_current) { /* Close all IP circuits for the descriptor. */ @@ -2040,7 +2033,7 @@ rotate_service_descriptors(hs_service_t *service, time_t now) service->desc_next = NULL;

/* We've just rotated, set the next time for the rotation. */ - set_rotation_time(service, now); + set_rotation_time(service); }

/* Rotate descriptors for each service if needed. A non existing current @@ -2068,7 +2061,7 @@ rotate_all_descriptors(time_t now) service->desc_current, service->desc_next, safe_str_client(service->onion_address));

- rotate_service_descriptors(service, now); + rotate_service_descriptors(service); } FOR_EACH_SERVICE_END; }

@@ -2090,7 +2083,7 @@ run_housekeeping_event(time_t now) /* Set the next rotation time of the descriptors. If it's Oct 25th * 23:47:00, the next rotation time is when the next SRV is computed * which is at Oct 26th 00:00:00 that is in 13 minutes. */ - set_rotation_time(service, now); + set_rotation_time(service); }

/* Cleanup invalid intro points from the service descriptor. */ @@ -2390,9 +2383,9 @@ set_descriptor_revision_counter(hs_service_descriptor_t *hs_desc, time_t now, * time of the current protocol run. */ if (is_current) { - srv_start = sr_state_get_start_time_of_previous_protocol_run(now); + srv_start = sr_state_get_start_time_of_previous_protocol_run(); } else { - srv_start = sr_state_get_start_time_of_current_protocol_run(now); + srv_start = sr_state_get_start_time_of_current_protocol_run(); }

log_info(LD_REND, "Setting rev counter for TP #%u: " diff --git a/src/or/shared_random_client.c b/src/or/shared_random_client.c index d787b6b2e..a03073b3d 100644 --- a/src/or/shared_random_client.c +++ b/src/or/shared_random_client.c @@ -223,33 +223,40 @@ sr_parse_srv(const smartlist_t *args) return srv; }

-/** Return the start time of the current SR protocol run. For example, if the - * time is 23/06/2017 23:47:08 and a full SR protocol run is 24 hours, this - * function should return 23/06/2017 00:00:00. */ +/** Return the start time of the current SR protocol run using the times from + * the current consensus. For example, if the latest consensus valid-after is + * 23/06/2017 23:00:00 and a full SR protocol run is 24 hours, this function + * returns 23/06/2017 00:00:00. */ time_t -sr_state_get_start_time_of_current_protocol_run(time_t now) +sr_state_get_start_time_of_current_protocol_run(void) { int total_rounds = SHARED_RANDOM_N_ROUNDS * SHARED_RANDOM_N_PHASES; int voting_interval = get_voting_interval(); /* Find the time the current round started. */ - time_t beginning_of_current_round = get_start_time_of_current_round(); + time_t beginning_of_curr_round = get_start_time_of_current_round();

/* Get current SR protocol round */ - int current_round = (now / voting_interval) % total_rounds; + int curr_round_slot; + curr_round_slot = (beginning_of_curr_round / voting_interval) % total_rounds;

/* Get start time by subtracting the time elapsed from the beginning of the protocol run */ - time_t time_elapsed_since_start_of_run = current_round * voting_interval; - return beginning_of_current_round - time_elapsed_since_start_of_run; + time_t time_elapsed_since_start_of_run = curr_round_slot * voting_interval; + + log_debug(LD_GENERAL, "Current SRV proto run: Start of current round: %u. " + "Time elapsed: %u (%d)", (unsigned) beginning_of_curr_round, + (unsigned) time_elapsed_since_start_of_run, voting_interval); + + return beginning_of_curr_round - time_elapsed_since_start_of_run; }

/** Return the start time of the previous SR protocol run. See * sr_state_get_start_time_of_current_protocol_run() for more details. */ time_t -sr_state_get_start_time_of_previous_protocol_run(time_t now) +sr_state_get_start_time_of_previous_protocol_run(void) { time_t start_time_of_current_run = - sr_state_get_start_time_of_current_protocol_run(now); + sr_state_get_start_time_of_current_protocol_run();

/* We get the start time of previous protocol run, by getting the start time * of current run and the subtracting a full protocol run from that. */ diff --git a/src/or/shared_random_client.h b/src/or/shared_random_client.h index 35ebb1bd5..826168633 100644 --- a/src/or/shared_random_client.h +++ b/src/or/shared_random_client.h @@ -34,8 +34,8 @@ sr_srv_t *sr_parse_srv(const smartlist_t *args); /* Number of phase we have in a protocol. */ #define SHARED_RANDOM_N_PHASES 2

-time_t sr_state_get_start_time_of_current_protocol_run(time_t now); -time_t sr_state_get_start_time_of_previous_protocol_run(time_t now); +time_t sr_state_get_start_time_of_current_protocol_run(void); +time_t sr_state_get_start_time_of_previous_protocol_run(void); unsigned int sr_state_get_phase_duration(void); unsigned int sr_state_get_protocol_run_duration(void); time_t get_start_time_of_current_round(void); diff --git a/src/test/test_hs_common.c b/src/test/test_hs_common.c index 47a021312..737c9ce5f 100644 --- a/src/test/test_hs_common.c +++ b/src/test/test_hs_common.c @@ -1338,6 +1338,10 @@ run_reachability_scenario(const reachability_cfg_t *cfg, int num_scenario) &mock_service_ns->fresh_until); voting_schedule_recalculate_timing(get_options(), mock_service_ns->valid_after); + /* Check that service is in the right time period point */ + tt_int_op(hs_in_period_between_tp_and_srv(mock_service_ns, 0), OP_EQ, + cfg->service_in_new_tp); + /* Set client consensus time. */ set_consensus_times(cfg->client_valid_after, &mock_client_ns->valid_after); @@ -1347,10 +1351,7 @@ run_reachability_scenario(const reachability_cfg_t *cfg, int num_scenario) &mock_client_ns->fresh_until); voting_schedule_recalculate_timing(get_options(), mock_client_ns->valid_after); - - /* New time period checks for this scenario. */ - tt_int_op(hs_in_period_between_tp_and_srv(mock_service_ns, 0), OP_EQ, - cfg->service_in_new_tp); + /* Check that client is in the right time period point */ tt_int_op(hs_in_period_between_tp_and_srv(mock_client_ns, 0), OP_EQ, cfg->client_in_new_tp);

diff --git a/src/test/test_shared_random.c b/src/test/test_shared_random.c index 55910a351..5b3fdbb10 100644 --- a/src/test/test_shared_random.c +++ b/src/test/test_shared_random.c @@ -249,8 +249,7 @@ test_get_start_time_of_current_run(void *arg) &current_time); tt_int_op(retval, OP_EQ, 0); voting_schedule_recalculate_timing(get_options(), current_time); - run_start_time = - sr_state_get_start_time_of_current_protocol_run(current_time); + run_start_time = sr_state_get_start_time_of_current_protocol_run();

/* Compare it with the correct result */ format_iso_time(tbuf, run_start_time); @@ -262,8 +261,7 @@ test_get_start_time_of_current_run(void *arg) &current_time); tt_int_op(retval, OP_EQ, 0); voting_schedule_recalculate_timing(get_options(), current_time); - run_start_time = - sr_state_get_start_time_of_current_protocol_run(current_time); + run_start_time = sr_state_get_start_time_of_current_protocol_run();

/* Compare it with the correct result */ format_iso_time(tbuf, run_start_time); @@ -275,8 +273,7 @@ test_get_start_time_of_current_run(void *arg) &current_time); tt_int_op(retval, OP_EQ, 0); voting_schedule_recalculate_timing(get_options(), current_time); - run_start_time = - sr_state_get_start_time_of_current_protocol_run(current_time); + run_start_time = sr_state_get_start_time_of_current_protocol_run();

/* Compare it with the correct result */ format_iso_time(tbuf, run_start_time); @@ -298,8 +295,7 @@ test_get_start_time_of_current_run(void *arg) &current_time); tt_int_op(retval, OP_EQ, 0); voting_schedule_recalculate_timing(get_options(), current_time); - run_start_time = - sr_state_get_start_time_of_current_protocol_run(current_time); + run_start_time = sr_state_get_start_time_of_current_protocol_run();

/* Compare it with the correct result */ format_iso_time(tbuf, run_start_time); @@ -332,7 +328,7 @@ test_get_start_time_functions(void *arg)

voting_schedule_recalculate_timing(get_options(), now); time_t start_time_of_protocol_run = - sr_state_get_start_time_of_current_protocol_run(now); + sr_state_get_start_time_of_current_protocol_run(); tt_assert(start_time_of_protocol_run);

/* Check that the round start time of the beginning of the run, is itself */