Unverified Commit cf2b00d3 authored by teor's avatar teor
Browse files

test/rebind: Make control formatting and log parsing more robust 

* actually sleep when tor has not logged anything
* log at debug level when waiting for tor to log something
* backslash-replace bad UTF-8 characters in logs
* format control messages as ASCII: tor does not accept UTF-8 control commands

Fixes bug 31837; bugfix on 0.3.5.1-alpha.
parent 02840169

changes/bug31837

0 → 100644
+5 −0
Original line number Diff line number Diff line 
  o Minor bugfixes (testing):

    - When testing port rebinding, don't busy-wait for tor to log. Instead,

      actually sleep for a short time before polling again. Also improve the

      formatting of control commands and log messages.

      Fixes bug 31837; bugfix on 0.3.5.1-alpha.

src/test/test_rebind.py

+9 −7
Original line number Diff line number Diff line
@@ -31,15 +31,17 @@ def wait_for_log(s): 
    cutoff = time.time() + LOG_TIMEOUT

    while time.time() < cutoff:

        l = tor_process.stdout.readline()

        l = l.decode('utf8')

        l = l.decode('utf8', 'backslashreplace')

        if s in l:

            logging.info('Tor logged: "{}"'.format(l.strip()))

            return

        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:

        if len(l) == 0:

            logging.debug('Tor has not logged anything, waiting for "{}"'.format(s))

            time.sleep(LOG_WAIT)

        else:

            logging.info('Tor logged: "{}", waiting for "{}"'.format(l.strip(), s))

    fail('Could not find "{}" in logs after {} seconds'.format(s, LOG_TIMEOUT))



def pick_random_port():
@@ -119,18 +121,18 @@ if control_socket.connect_ex(('127.0.0.1', control_port)): 
    tor_process.terminate()

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

control_socket.sendall('AUTHENTICATE \r\n'.encode('ascii'))

control_socket.sendall('SETCONF SOCKSPort=0.0.0.0:{}\r\n'.format(socks_port).encode('ascii'))

wait_for_log('Opened Socks listener')



try_connecting_to_socksport()



control_socket.sendall('SETCONF SOCKSPort=127.0.0.1:{}\r\n'.format(socks_port).encode('utf8'))

control_socket.sendall('SETCONF SOCKSPort=127.0.0.1:{}\r\n'.format(socks_port).encode('ascii'))

wait_for_log('Opened Socks listener')



try_connecting_to_socksport()



control_socket.sendall('SIGNAL HALT\r\n'.encode('utf8'))

control_socket.sendall('SIGNAL HALT\r\n'.encode('ascii'))



wait_for_log('exiting cleanly')

logging.info('OK')