Update run_tests.py.

diff --git a/exec_utils.py b/exec_utils.py
index 7f23ecd16a40bcad9be70fe42c274eb4f0482369..7e45d92377d553ad5c5343158f49c5366faf12b6 100644 (file)
--- 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 2b2d2389f3f0c5a53fd7d160d6e21d406f6934c6..7e7bad593da9f8b453626ef018393b9436548833 100755 (executable)
--- 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)