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

@@ -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) {

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: "

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. */

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);

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);
 

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 */