Merge branch 'bug28229_diag_035' into maint-0.3.5

2 files changed, 15 insertions, 4 deletions

diff --git a/changes/ticket28229_diag b/changes/ticket28229_diag
new file mode 100644
index 0000000000..cd02b81faa
--- /dev/null
+++ b/changes/ticket28229_diag
@@ -0,0 +1,3 @@
+  o Testing:
+    - Increase logging and tag all log entries with timestamps
+      in test_rebind.py. Provides diagnostics for issue 28229.
diff --git a/src/test/test_rebind.py b/src/test/test_rebind.py
index c63341a681..2215b42253 100644
--- a/src/test/test_rebind.py
+++ b/src/test/test_rebind.py
@@ -1,6 +1,7 @@
 from __future__ import print_function
 
 import errno
+import logging
 import os
 import random
 import socket
@@ -13,7 +14,7 @@ LOG_WAIT = 0.1
 LOG_CHECK_LIMIT = LOG_TIMEOUT / LOG_WAIT
 
 def fail(msg):
-    print('FAIL')
+    logging.error('FAIL')
     sys.exit(msg)
 
 def try_connecting_to_socksport():
@@ -29,8 +30,9 @@ def wait_for_log(s):
         l = tor_process.stdout.readline()
         l = l.decode('utf8')
         if s in l:
+            logging.info('Tor logged: "{}"'.format(l.strip()))
             return
-        print('Tor logged: "{}", waiting for "{}"'.format(l.strip(), s))
+        logging.info('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:
@@ -55,6 +57,10 @@ def pick_random_port():
 
     return port
 
+logging.basicConfig(level=logging.DEBUG,
+                    format='%(asctime)s.%(msecs)03d %(message)s',
+                    datefmt='%Y-%m-%d %H:%M:%S')
+
 if sys.hexversion < 0x02070000:
     fail("ERROR: unsupported Python version (should be >= 2.7)")
 
@@ -75,6 +81,8 @@ tor_path = sys.argv[1]
 tor_process = subprocess.Popen([tor_path,
                                '-ControlPort', '127.0.0.1:{}'.format(control_port),
                                '-SOCKSPort', '127.0.0.1:{}'.format(socks_port),
+                               '-Log', 'debug stdout',
+                               '-LogTimeGranularity', '1',
                                '-FetchServerDescriptors', '0'],
                                stdout=subprocess.PIPE,
                                stderr=subprocess.PIPE)
@@ -108,13 +116,13 @@ try_connecting_to_socksport()
 control_socket.sendall('SIGNAL HALT\r\n'.encode('utf8'))
 
 wait_for_log('exiting cleanly')
-print('OK')
+logging.info('OK')
 
 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")
+        logging.warn("Tor has already exited")
     else:
         raise