[tor-commits] [chutney/master] TorNet: Fail bootstrap if times are incorrect

[teor at torproject.org]

commit 0fe4010bc3c3851239c3dec2800e0ce0899dcdc0
Author: teor <teor at torproject.org>
Date:   Mon Mar 16 15:51:16 2020 +1000

    TorNet: Fail bootstrap if times are incorrect
    
    If there is a time calculation bug, or a large clock skew, fail
    bootstrap.
    
    Diagnostics for macOS Travis hangs.
---
 lib/chutney/TorNet.py | 43 ++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 40 insertions(+), 3 deletions(-)

diff --git a/lib/chutney/TorNet.py b/lib/chutney/TorNet.py
index 9857968..efea40e 100644
--- a/lib/chutney/TorNet.py
+++ b/lib/chutney/TorNet.py
@@ -2212,6 +2212,7 @@ class Network(object):
 
     CHECK_NETWORK_STATUS_DELAY = 1.0
     PRINT_NETWORK_STATUS_DELAY = V3_AUTH_VOTING_INTERVAL/2.0
+    CHECKS_PER_PRINT = PRINT_NETWORK_STATUS_DELAY / CHECK_NETWORK_STATUS_DELAY
 
     def wait_for_bootstrap(self):
         print("Waiting for nodes to bootstrap...\n")
@@ -2225,6 +2226,8 @@ class Network(object):
         wait_time_list = [c.getUncheckedDirInfoWaitTime() for c in controllers]
         wait_time = max(wait_time_list)
 
+        checks_since_last_print = 0
+
         most_recent_bootstrap_status = [ None ] * len(controllers)
         most_recent_desc_status = dict()
         while True:
@@ -2290,12 +2293,46 @@ class Network(object):
             if now >= limit:
                 break
             if now >= next_print_status:
+                if checks_since_last_print <= Network.CHECKS_PER_PRINT/2:
+                    self.print_bootstrap_status(controllers,
+                                                most_recent_bootstrap_status,
+                                                most_recent_desc_status,
+                                                elapsed=elapsed,
+                                                msg="Internal timing error")
+                    print("checks_since_last_print: {} (expected: {})"
+                          .format(checks_since_last_print,
+                                  Network.CHECKS_PER_PRINT))
+                    print("start: {} limit: {}".format(start, limit))
+                    print("next_print_status: {} now: {}"
+                          .format(next_print_status, time.time()))
+                    return False
+                else:
+                    self.print_bootstrap_status(controllers,
+                                                most_recent_bootstrap_status,
+                                                most_recent_desc_status,
+                                                elapsed=elapsed)
+                    next_print_status = (now +
+                                         Network.PRINT_NETWORK_STATUS_DELAY)
+                    checks_since_last_print = 0
+
+            time.sleep(Network.CHECK_NETWORK_STATUS_DELAY)
+
+            # macOS Travis has some weird hangs, make sure we're not hanging
+            # in this loop due to clock skew
+            checks_since_last_print += 1
+            if checks_since_last_print >= Network.CHECKS_PER_PRINT*2:
                 self.print_bootstrap_status(controllers,
                                             most_recent_bootstrap_status,
                                             most_recent_desc_status,
-                                            elapsed=elapsed)
-                next_print_status = now + Network.PRINT_NETWORK_STATUS_DELAY
-            time.sleep(Network.CHECK_NETWORK_STATUS_DELAY)
+                                            elapsed=elapsed,
+                                            msg="Internal timing error")
+                print("checks_since_last_print: {} (expected: {})"
+                      .format(checks_since_last_print,
+                              Network.CHECKS_PER_PRINT))
+                print("start: {} limit: {}".format(start, limit))
+                print("next_print_status: {} now: {}"
+                      .format(next_print_status, time.time()))
+                return False
 
         self.print_bootstrap_status(controllers,
                                     most_recent_bootstrap_status,