From 11f8eba52154d14a05df6e64067b6645e3dca3b2 Mon Sep 17 00:00:00 2001 From: Scott Gasch Date: Thu, 2 Jun 2022 10:57:38 -0700 Subject: [PATCH] Update run_tests.py. --- exec_utils.py | 4 +- tests/run_tests.py | 211 ++++++++++++++++++++------------------------- 2 files changed, 96 insertions(+), 119 deletions(-) diff --git a/exec_utils.py b/exec_utils.py index 7f23ecd..7e45d92 100644 --- a/exec_utils.py +++ b/exec_utils.py @@ -123,7 +123,9 @@ def cmd(command: str, timeout_seconds: Optional[float] = None) -> str: ret = subprocess.run( command, shell=True, - capture_output=True, + # capture_output=True, + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, check=True, timeout=timeout_seconds, ).stdout diff --git a/tests/run_tests.py b/tests/run_tests.py index 2b2d238..7e7bad5 100755 --- a/tests/run_tests.py +++ b/tests/run_tests.py @@ -45,11 +45,10 @@ class TestingParameters: @dataclass class TestResults: name: str - num_tests_executed: int - num_tests_succeeded: int - num_tests_failed: int - normal_exit: bool - output: str + tests_executed: List[str] + tests_succeeded: List[str] + tests_failed: List[str] + tests_timed_out: List[str] class TestRunner(ABC, thread_utils.ThreadWithReturnValue): @@ -58,19 +57,17 @@ class TestRunner(ABC, thread_utils.ThreadWithReturnValue): self.params = params self.test_results = TestResults( name=f"All {self.get_name()} tests", - num_tests_executed=0, - num_tests_succeeded=0, - num_tests_failed=0, - normal_exit=True, - output="", + tests_executed=[], + tests_succeeded=[], + tests_failed=[], + tests_timed_out=[], ) def aggregate_test_results(self, result: TestResults): - self.test_results.num_tests_executed += result.num_tests_executed - self.test_results.num_tests_succeeded += result.num_tests_succeeded - self.test_results.num_tests_failed += result.num_tests_failed - self.test_results.normal_exit = self.test_results.normal_exit and result.normal_exit - self.test_results.output += "\n\n\n" + result.output + self.test_results.tests_executed.extend(result.tests_executed) + self.test_results.tests_succeeded.extend(result.tests_succeeded) + self.test_results.tests_failed.extend(result.tests_failed) + self.test_results.tests_timed_out.extend(result.tests_timed_out) @abstractmethod def get_name(self) -> str: @@ -94,8 +91,8 @@ class TemplatedTestRunner(TestRunner, ABC): if self.params.halt_event.is_set(): logger.debug('Thread %s saw halt event; exiting.', self.get_name()) raise Exception("Kill myself!") - if not self.test_results.normal_exit: - if self.params.halt_on_error: + if self.params.halt_on_error: + if len(self.test_results.tests_failed) > 0: logger.error('Thread %s saw abnormal results; exiting.', self.get_name()) raise Exception("Kill myself!") @@ -110,6 +107,58 @@ class TemplatedTestRunner(TestRunner, ABC): total, ) + def persist_output(self, test_name: str, message: str, output: str) -> None: + basename = file_utils.without_path(test_name) + dest = f'{basename}-output.txt' + with open(f'./test_output/{dest}', 'w') as wf: + print(message, file=wf) + print('-' * len(message), file=wf) + wf.write(output) + + def execute_commandline( + self, + test_name: str, + cmdline: str, + *, + timeout: float = 120.0, + ) -> TestResults: + + try: + logger.debug('%s: Running %s (%s)', self.get_name(), test_name, cmdline) + output = exec_utils.cmd( + cmdline, + timeout_seconds=timeout, + ) + self.persist_output(test_name, f'{test_name} ({cmdline}) succeeded.', output) + logger.debug('%s (%s) succeeded', test_name, cmdline) + return TestResults(test_name, [test_name], [test_name], [], []) + except subprocess.TimeoutExpired as e: + msg = f'{self.get_name()}: {test_name} ({cmdline}) timed out after {e.timeout:.1f} seconds.' + logger.error(msg) + logger.debug( + '%s: %s output when it timed out: %s', self.get_name(), test_name, e.output + ) + self.persist_output(test_name, msg, e.output) + return TestResults( + test_name, + [test_name], + [], + [], + [test_name], + ) + except subprocess.CalledProcessError as e: + msg = f'{self.get_name()}: {test_name} ({cmdline}) failed; exit code {e.returncode}' + logger.error(msg) + logger.debug('%s: %s output when it failed: %s', self.get_name(), test_name, e.output) + self.persist_output(test_name, msg, e.output) + return TestResults( + test_name, + [test_name], + [], + [test_name], + [], + ) + @overrides def begin(self, params: TestingParameters) -> TestResults: logger.debug('Thread %s started.', self.get_name()) @@ -151,37 +200,10 @@ class UnittestTestRunner(TemplatedTestRunner): @par.parallelize def run_test(self, test: Any) -> TestResults: if config.config['coverage']: - cmdline = f'coverage run --source {HOME}/lib --append {test} --unittests_ignore_perf' + cmdline = f'coverage run --source {HOME}/lib {test} --unittests_ignore_perf' else: cmdline = test - - try: - logger.debug('Running unittest %s (%s)', test, cmdline) - output = exec_utils.cmd( - cmdline, - timeout_seconds=120.0, - ) - except TimeoutError: - logger.error('Unittest %s timed out; ran for > 120.0 seconds', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Unittest {test} timed out.", - ) - except subprocess.CalledProcessError: - logger.error('Unittest %s failed.', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Unittest {test} failed.", - ) - return TestResults(test, 1, 1, 0, True, output) + return self.execute_commandline(test, cmdline) class DoctestTestRunner(TemplatedTestRunner): @@ -202,43 +224,10 @@ class DoctestTestRunner(TemplatedTestRunner): @par.parallelize def run_test(self, test: Any) -> TestResults: if config.config['coverage']: - cmdline = f'coverage run --source {HOME}/lib --append {test} 2>&1' + cmdline = f'coverage run --source {HOME}/lib {test} 2>&1' else: cmdline = f'python3 {test}' - try: - logger.debug('Running doctest %s (%s).', test, cmdline) - output = exec_utils.cmd( - cmdline, - timeout_seconds=120.0, - ) - except TimeoutError: - logger.error('Doctest %s timed out; ran for > 120.0 seconds', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Doctest {test} timed out.", - ) - except subprocess.CalledProcessError: - logger.error('Doctest %s failed.', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Docttest {test} failed.", - ) - return TestResults( - test, - 1, - 1, - 0, - True, - "", - ) + return self.execute_commandline(test, cmdline) class IntegrationTestRunner(TemplatedTestRunner): @@ -253,51 +242,34 @@ class IntegrationTestRunner(TemplatedTestRunner): @par.parallelize def run_test(self, test: Any) -> TestResults: if config.config['coverage']: - cmdline = f'coverage run --source {HOME}/lib --append {test}' + cmdline = f'coverage run --source {HOME}/lib {test}' else: cmdline = test - try: - logger.debug('Running integration test %s (%s).', test, cmdline) - output = exec_utils.cmd( - cmdline, - timeout_seconds=240.0, - ) - except TimeoutError: - logger.error('Integration Test %s timed out; ran for > 240.0 seconds', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Integration Test {test} timed out.", - ) - except subprocess.CalledProcessError: - logger.error('Integration Test %s failed.', test) - return TestResults( - test, - 1, - 0, - 1, - False, - f"Integration Test {test} failed.", - ) - return TestResults( - test, - 1, - 1, - 0, - True, - "", - ) + return self.execute_commandline(test, cmdline) def test_results_report(results: Dict[str, TestResults]): - print(results) + for type, result in results.items(): + print(text_utils.header(f'{result.name}')) + print(f' Ran {len(result.tests_executed)} tests.') + print(f' ..{len(result.tests_succeeded)} tests succeeded.') + if len(result.tests_failed) > 0: + print(f' ..{len(result.tests_failed)} tests failed:') + for test in result.tests_failed: + print(f' {test}') + + if len(result.tests_timed_out) > 0: + print(f' ..{len(result.tests_timed_out)} tests timed out:') + for test in result.tests_failed: + print(f' {test}') + + if len(result.tests_failed) + len(result.tests_timed_out): + print('Reminder: look in ./test_output to view test output logs') def code_coverage_report(): text_utils.header('Code Coverage') + out = exec_utils.cmd('coverage combine .coverage*') out = exec_utils.cmd('coverage report --omit=config-3.8.py,*_test.py,*_itest.py --sort=-cover') print(out) print( @@ -358,7 +330,10 @@ def main() -> Optional[int]: result = thread.join() if result: results[tid] = result - if not result.normal_exit: + if len(result.tests_failed) > 0: + logger.error( + 'Thread %s returned abnormal results; killing the others.', tid + ) halt_event.set() time.sleep(1.0) -- 2.47.1