From 8f43b8fb477e0fe538336fd0e1cb772d1686fb47 Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 6 Oct 2018 16:05:04 -0500 Subject: [PATCH 1/4] Avoid a race condition in test_rebind.py If tor terminates due to SIGNAL HALT before test_rebind.py calls tor_process.terminate(), an OSError 3 (no such process) is thrown. Fixes part of bug 27968 on 0.3.5.1-alpha. --- changes/bug27968 | 3 +++ src/test/test_rebind.py | 13 +++++++++++-- 2 files changed, 14 insertions(+), 2 deletions(-) create mode 100644 changes/bug27968 diff --git a/changes/bug27968 b/changes/bug27968 new file mode 100644 index 0000000000..78c8eee33a --- /dev/null +++ b/changes/bug27968 @@ -0,0 +1,3 @@ + o Minor bugfixes (testing): + - Avoid hangs and race conditions in test_rebind.py. + Fixes bug 27968; bugfix on 0.3.5.1-alpha. diff --git a/src/test/test_rebind.py b/src/test/test_rebind.py index 7ba3a5796d..13e4446cec 100644 --- a/src/test/test_rebind.py +++ b/src/test/test_rebind.py @@ -6,6 +6,7 @@ import socket import os import time import random +import errno def try_connecting_to_socksport(): socks_socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM) @@ -88,6 +89,14 @@ try_connecting_to_socksport() control_socket.sendall('SIGNAL HALT\r\n'.encode('utf8')) -time.sleep(0.1) +wait_for_log('exiting cleanly') print('OK') -tor_process.terminate() + +try: + tor_process.terminate() +except OSError as e: + if e.errno == errno.ESRCH: # errno 3: No such process + # assume tor has already exited due to SIGNAL HALT + print("Tor has already exited") + else: + raise From cd674a10ad989120e7b8060ebe6d8f2626bf4a65 Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 6 Oct 2018 16:09:20 -0500 Subject: [PATCH 2/4] Refactor test_rebind.py to consistently print FAIL on failure Part of #27968. --- src/test/test_rebind.py | 23 ++++++++++++++--------- 1 file changed, 14 insertions(+), 9 deletions(-) diff --git a/src/test/test_rebind.py b/src/test/test_rebind.py index 13e4446cec..3600dd5d58 100644 --- a/src/test/test_rebind.py +++ b/src/test/test_rebind.py @@ -8,12 +8,15 @@ import time import random import errno +def fail(msg): + print('FAIL') + sys.exit(msg) + def try_connecting_to_socksport(): socks_socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM) if socks_socket.connect_ex(('127.0.0.1', socks_port)): tor_process.terminate() - print('FAIL') - sys.exit('Cannot connect to SOCKSPort') + fail('Cannot connect to SOCKSPort') socks_socket.close() def wait_for_log(s): @@ -34,13 +37,16 @@ def pick_random_port(): else: break + if port == 0: + fail('Could not find a random free port between 10000 and 60000') + return port if sys.hexversion < 0x02070000: - sys.exit("ERROR: unsupported Python version (should be >= 2.7)") + fail("ERROR: unsupported Python version (should be >= 2.7)") if sys.hexversion > 0x03000000 and sys.hexversion < 0x03010000: - sys.exit("ERROR: unsupported Python3 version (should be >= 3.1)") + fail("ERROR: unsupported Python3 version (should be >= 3.1)") control_port = pick_random_port() socks_port = pick_random_port() @@ -49,7 +55,7 @@ assert control_port != 0 assert socks_port != 0 if not os.path.exists(sys.argv[1]): - sys.exit('ERROR: cannot find tor at %s' % sys.argv[1]) + fail('ERROR: cannot find tor at %s' % sys.argv[1]) tor_path = sys.argv[1] @@ -61,10 +67,10 @@ tor_process = subprocess.Popen([tor_path, stderr=subprocess.PIPE) if tor_process == None: - sys.exit('ERROR: running tor failed') + fail('ERROR: running tor failed') if len(sys.argv) < 2: - sys.exit('Usage: %s ' % sys.argv[0]) + fail('Usage: %s ' % sys.argv[0]) wait_for_log('Opened Control listener on') @@ -73,8 +79,7 @@ try_connecting_to_socksport() control_socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM) if control_socket.connect_ex(('127.0.0.1', control_port)): tor_process.terminate() - print('FAIL') - sys.exit('Cannot connect to ControlPort') + fail('Cannot connect to ControlPort') control_socket.sendall('AUTHENTICATE \r\n'.encode('utf8')) control_socket.sendall('SETCONF SOCKSPort=0.0.0.0:{}\r\n'.format(socks_port).encode('utf8')) From a02d6c560d8b574003b4c34907c1656f8c57e857 Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 6 Oct 2018 16:10:37 -0500 Subject: [PATCH 3/4] Make test_rebind.py timeout when waiting for a log message Closes #27968. --- src/test/test_rebind.py | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/src/test/test_rebind.py b/src/test/test_rebind.py index 3600dd5d58..5e671de308 100644 --- a/src/test/test_rebind.py +++ b/src/test/test_rebind.py @@ -8,6 +8,10 @@ import time import random import errno +LOG_TIMEOUT = 60.0 +LOG_WAIT = 0.1 +LOG_CHECK_LIMIT = LOG_TIMEOUT / LOG_WAIT + def fail(msg): print('FAIL') sys.exit(msg) @@ -20,10 +24,19 @@ def try_connecting_to_socksport(): socks_socket.close() def wait_for_log(s): - while True: + log_checked = 0 + while log_checked < LOG_CHECK_LIMIT: l = tor_process.stdout.readline() - if s in l.decode('utf8'): + l = l.decode('utf8') + if s in l: return + print('Tor logged: "{}", waiting for "{}"'.format(l.strip(), s)) + # readline() returns a blank string when there is no output + # avoid busy-waiting + if len(s) == 0: + time.sleep(LOG_WAIT) + log_checked += 1 + fail('Could not find "{}" in logs after {} seconds'.format(s, LOG_TIMEOUT)) def pick_random_port(): port = 0 From e36e4a9671e2dc066fbc0f51c845a9941414b08f Mon Sep 17 00:00:00 2001 From: teor Date: Mon, 22 Oct 2018 12:31:32 +1000 Subject: [PATCH 4/4] Sort the imports in test_rebind.py Cleanup after #27968. --- src/test/test_rebind.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/test/test_rebind.py b/src/test/test_rebind.py index 5e671de308..c63341a681 100644 --- a/src/test/test_rebind.py +++ b/src/test/test_rebind.py @@ -1,12 +1,12 @@ from __future__ import print_function -import sys -import subprocess -import socket -import os -import time -import random import errno +import os +import random +import socket +import subprocess +import sys +import time LOG_TIMEOUT = 60.0 LOG_WAIT = 0.1