commit 0fe4010bc3c3851239c3dec2800e0ce0899dcdc0 Author: teor teor@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,