commit 0b734b6a930d013f2cf3b816201e2f409cf5f774 Author: Damian Johnson atagar@torproject.org Date: Fri Sep 28 13:13:25 2018 -0700
Provide tor segfault output when testing
When our integ tests trigger a crash within tor our test output was pretty unhelpful. Runners could tell that something badly broke, but not much more than that.
https://trac.torproject.org/projects/tor/ticket/27717
When the tor process dies unexpectedly halting further tests and printing the final gasps from the process. Going back to tor commit b8a2bdb for example...
============================================================ Our tor process ended prematurely with exit status -6 ============================================================
Sep 28 13:13:09.000 [notice] Starting with guard context "default" Sep 28 13:13:09.000 [notice] Bootstrapped 45%: Asking for relay descriptors Sep 28 13:13:09.000 [notice] New control connection opened from 127.0.0.1. Sep 28 13:13:09.000 [notice] Your ContactInfo config option is not set. Please consider setting it, so we can contact you if your server is misconfigured or something else goes wrong. Sep 28 13:13:09.000 [warn] ControlPort is open, but no authentication method has been configured. This means that any program on your computer can reconfigure your Tor. That's bad! You should upgrade your Tor controller as soon as possible. Sep 28 13:13:09.000 [notice] Configured to measure directory request statistics, but no GeoIP database found. Please specify a GeoIP database using the GeoIPFile option. Sep 28 13:13:10.000 [notice] New control connection opened from 127.0.0.1. Sep 28 13:13:10.000 [notice] New control connection opened from 127.0.0.1. Sep 28 13:13:10.000 [notice] New control connection opened from 127.0.0.1. Sep 28 13:13:10.000 [err] tor_assertion_failed_(): Bug: src/core/mainloop/connection.c:5109: assert_connection_ok: Assertion or_conn->tls failed; aborting. (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: Assertion or_conn->tls failed in assert_connection_ok at src/core/mainloop/connection.c:5109. Stack trace: (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(log_backtrace_impl+0x47) [0x55cb6c227447] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(tor_assertion_failed_+0x94) [0x55cb6c222bb4] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(assert_connection_ok+0x575) [0x55cb6c1b60a5] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(connection_mark_for_close_internal_+0x27) [0x55cb6c1b66b7] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(connection_handle_read+0x517) [0x55cb6c1babb7] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(+0x5470e) [0x55cb6c09670e] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: /usr/lib/x86_64-linux-gnu/libevent-2.0.so.5(event_base_loop+0x819) [0x7f08790424c9] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(do_main_loop+0x1fa) [0x55cb6c0989aa] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(tor_run_main+0x11d5) [0x55cb6c09b065] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(tor_main+0x3a) [0x55cb6c0932fa] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(main+0x19) [0x55cb6c092e79] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0) [0x7f08783c1830] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) Sep 28 13:13:10.000 [err] Bug: tor(_start+0x29) [0x55cb6c092ec9] (on Tor 0.3.5.0-alpha-dev b8a2bdbdc8c46776) --- docs/change_log.rst | 1 + run_tests.py | 12 +++++++++--- stem/process.py | 25 ++++++++++++++++++------- test/runner.py | 19 +++++++++++++++++++ 4 files changed, 47 insertions(+), 10 deletions(-)
diff --git a/docs/change_log.rst b/docs/change_log.rst index c32af5df..4b49bb99 100644 --- a/docs/change_log.rst +++ b/docs/change_log.rst @@ -51,6 +51,7 @@ The following are only available within Stem's `git repository * Added the stem.control.MALFORMED_EVENTS event listener constant * Added support for limiting the maximum number of streams to :func:`~stem.control.Controller.create_ephemeral_hidden_service` (:spec:`2fcb1c2`) * Added a timeout argument to :class:`~stem.control.Controller` methods that could await a response (:trac:`26056`) + * Added a close_output argument to :class:`~stem.process.launch_tor` * Stacktrace if :func:`stem.connection.connect` had a string port argument * More reliable ExitPolicy resolution (:trac:`25739`) * Fixed cache invalidation when another contorller calls SETCONF (:trac:`25821`) diff --git a/run_tests.py b/run_tests.py index 36296f7e..564ab4dd 100755 --- a/run_tests.py +++ b/run_tests.py @@ -235,9 +235,15 @@ def main(): println('Running tests...\n', STATUS)
for test_class in get_integ_tests(args.specific_test): - run_result = _run_test(args, test_class, output_filters) - test.output.print_logging(logging_buffer) - skipped_tests += len(getattr(run_result, 'skipped', [])) + if integ_runner.assert_tor_is_running(): + run_result = _run_test(args, test_class, output_filters) + test.output.print_logging(logging_buffer) + skipped_tests += len(getattr(run_result, 'skipped', [])) + else: + # our tor process died + + error_tracker.register_error() + break except KeyboardInterrupt: println(' aborted starting tor: keyboard interrupt\n', ERROR) break diff --git a/stem/process.py b/stem/process.py index 2d3dfff6..e2b36ec0 100644 --- a/stem/process.py +++ b/stem/process.py @@ -34,7 +34,7 @@ NO_TORRC = '<no torrc>' DEFAULT_INIT_TIMEOUT = 90
-def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_percent = 100, init_msg_handler = None, timeout = DEFAULT_INIT_TIMEOUT, take_ownership = False, stdin = None): +def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_percent = 100, init_msg_handler = None, timeout = DEFAULT_INIT_TIMEOUT, take_ownership = False, close_output = True, stdin = None): """ Initializes a tor process. This blocks until initialization completes or we error out. @@ -54,6 +54,9 @@ def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_perce .. versionchanged:: 1.6.0 Allowing the timeout argument to be a float.
+ .. versionchanged:: 1.7.0 + Added the **close_output** argument. + :param str tor_cmd: command for starting tor :param list args: additional arguments for tor :param str torrc_path: location of the torrc for us to use @@ -66,6 +69,8 @@ def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_perce :param bool take_ownership: asserts ownership over the tor process so it aborts if this python process terminates or a :class:`~stem.control.Controller` we establish to it disconnects + :param bool close_output: closes tor's stdout and stderr streams when + bootstrapping is complete if true :param str stdin: content to provide on stdin
:returns: **subprocess.Popen** instance for the tor subprocess @@ -182,11 +187,12 @@ def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_perce if timeout: signal.alarm(0) # stop alarm
- if tor_process and tor_process.stdout: - tor_process.stdout.close() + if tor_process and close_output: + if tor_process.stdout: + tor_process.stdout.close()
- if tor_process and tor_process.stderr: - tor_process.stderr.close() + if tor_process.stderr: + tor_process.stderr.close()
if temp_file: try: @@ -195,7 +201,7 @@ def launch_tor(tor_cmd = 'tor', args = None, torrc_path = None, completion_perce pass
-def launch_tor_with_config(config, tor_cmd = 'tor', completion_percent = 100, init_msg_handler = None, timeout = DEFAULT_INIT_TIMEOUT, take_ownership = False): +def launch_tor_with_config(config, tor_cmd = 'tor', completion_percent = 100, init_msg_handler = None, timeout = DEFAULT_INIT_TIMEOUT, take_ownership = False, close_output = True): """ Initializes a tor process, like :func:`~stem.process.launch_tor`, but with a customized configuration. This writes a temporary torrc to disk, launches @@ -215,6 +221,9 @@ def launch_tor_with_config(config, tor_cmd = 'tor', completion_percent = 100, in }, )
+ .. versionchanged:: 1.7.0 + Added the **close_output** argument. + :param dict config: configuration options, such as "{'ControlPort': '9051'}", values can either be a **str** or **list of str** if for multiple values :param str tor_cmd: command for starting tor @@ -227,6 +236,8 @@ def launch_tor_with_config(config, tor_cmd = 'tor', completion_percent = 100, in :param bool take_ownership: asserts ownership over the tor process so it aborts if this python process terminates or a :class:`~stem.control.Controller` we establish to it disconnects + :param bool close_output: closes tor's stdout and stderr streams when + bootstrapping is complete if true
:returns: **subprocess.Popen** instance for the tor subprocess
@@ -271,7 +282,7 @@ def launch_tor_with_config(config, tor_cmd = 'tor', completion_percent = 100, in config_str += '%s %s\n' % (key, value)
if use_stdin: - return launch_tor(tor_cmd, ['-f', '-'], None, completion_percent, init_msg_handler, timeout, take_ownership, stdin = config_str) + return launch_tor(tor_cmd, ['-f', '-'], None, completion_percent, init_msg_handler, timeout, take_ownership, close_output, stdin = config_str) else: torrc_descriptor, torrc_path = tempfile.mkstemp(prefix = 'torrc-', text = True)
diff --git a/test/runner.py b/test/runner.py index 160e4827..9c2438a2 100644 --- a/test/runner.py +++ b/test/runner.py @@ -287,6 +287,9 @@ class Runner(object): except OSError: pass
+ self._tor_process.stdout.close() + self._tor_process.stderr.close() + self._tor_process.wait() # blocks until the process is done
# if we've made a temporary data directory then clean it up @@ -490,6 +493,21 @@ class Runner(object):
return os.path.basename(self._get('_tor_cmd')) if base_cmd else self._get('_tor_cmd')
+ def assert_tor_is_running(self): + """ + Checks if our tor process is running. If not, this prints an error and + provides **False**. + """ + + process_status = self._tor_process.poll() # None if running + + if process_status is None: + return True + else: + process_output = (self._tor_process.stdout.read() + '\n\n' + self._tor_process.stderr.read()).strip() + println('\n%s\nOur tor process ended prematurely with exit status %s\n%s\n\n%s' % ('=' * 60, process_status, '=' * 60, process_output), ERROR) + return False + def _get(self, attr): """ Fetches one of our attributes in a thread safe manner, raising if we aren't @@ -611,6 +629,7 @@ class Runner(object): completion_percent = 100 if test.Target.ONLINE in self.attribute_targets else 0, init_msg_handler = lambda line: println(' %s' % line, SUBSTATUS), take_ownership = True, + close_output = False, )
runtime = time.time() - start_time