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.

diff --git a/src/or/hs_common.c b/src/or/hs_common.c
index e88a04620e8dae690082a97ed2c6f9eb8841b18a..0750785e4411de375b3423a22c60cb33ea3c703d 100644 (file)
--- 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 5430ef4d872e42db84bad5edec664b7d6ced2933..b4460b2ac4f26caba42698eac4bf4dbe9f207283 100644 (file)
--- 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 d787b6b2ec53f01decaee13eee5d85cfeeea65a3..a03073b3d96c263334c2245ccfc559a451e7d018 100644 (file)
--- 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 35ebb1bd57aebff3ae71521c3c2f08e35b59f9f1..8261686332d976af735b8aab7b408141d394adfe 100644 (file)
--- 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 47a021312aea6c76c14e61062de94f38476ed231..737c9ce5f5a0614b6ddf00174e7800f71c8e9439 100644 (file)
--- 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 55910a351e7ac9806809a1bebfe7c987213b27ad..5b3fdbb103d35062887629ffea6f176865bac6fa 100644 (file)
--- 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 */