avocado.code.job fix job return code on timed out jobs

When a job is timed out during a test execution, we fail the test
and put status ERROR in the test. The job then exits with the rc
AVOCADO_TESTS_FAIL. This patch fixes this, making the test status
INTERRUPTED and the job to exit with AVOCADO_JOB_INTERRUPTED.

Also, when a job is timed out before a test, the test is skipped
and the job exits with rc AVOCADO_ALL_OK. For that case, this patch
makes the job to exit with AVOCADO_JOB_INTERRUPTED instead, keeping
the test status as SKIP.

Given this change, now we have the following combinations of test status
and job return code:

Case1:
    - Test1: PASS
    - Test2: SKIP (TestTimeoutSkip)

    Job RC: AVOCADO_JOB_INTERRUPTED

Case2:
    - Test1: PASS
    - Test2: INTERRUPTED (TestTimeoutInterrupted)
    - Test3: SKIP (TestTimeoutSkip)

    Job RC: AVOCADO_JOB_INTERRUPTED

Case3:
    - Test1: PASS
    - Test2: FAIL
    - Test3: INTERRUPTED (TestTimeoutInterrupted)
    - Test4: SKIP (TestTimeoutSkip)

    Job RC: AVOCADO_JOB_INTERRUPTED
Signed-off-by: NAmador Pahim <apahim@redhat.com>

avocado/core/exceptions.py

@@ -133,12 +133,20 @@ class TestNotFoundError(TestBaseException):
     status = "ERROR"
 
 
-class TestTimeoutError(TestBaseException):
+class TestTimeoutInterrupted(TestBaseException):
 
     """
     Indicates that the test did not finish before the timeout specified.
     """
-    status = "ERROR"
+    status = "INTERRUPTED"
+
+
+class TestTimeoutSkip(TestBaseException):
+
+    """
+    Indicates that the test is skipped due to a job timeout.
+    """
+    status = "SKIP"
 
 
 class TestInterruptedError(TestBaseException):

avocado/core/job.py

@@ -492,9 +492,9 @@ class Job(object):
         self._log_job_debug_info(mux)
         replay.record(self.args, self.logdir, mux, self.urls)
         replay_map = getattr(self.args, 'replay_map', None)
-        failures = self.test_runner.run_suite(test_suite, mux,
-                                              timeout=self.timeout,
-                                              replay_map=replay_map)
+        summary = self.test_runner.run_suite(test_suite, mux,
+                                             timeout=self.timeout,
+                                             replay_map=replay_map)
         self.__stop_job_logging()
         # If it's all good so far, set job status to 'PASS'
         if self.status == 'RUNNING':
@@ -505,11 +505,14 @@ class Job(object):
             archive.create(filename, self.logdir)
         _TEST_LOGGER.info('Test results available in %s', self.logdir)
 
-        tests_status = not bool(failures)
-        if tests_status:
-            return exit_codes.AVOCADO_ALL_OK
-        else:
+        if summary is None:
+            return exit_codes.AVOCADO_JOB_FAIL
+        elif 'INTERRUPTED' in summary:
+            return exit_codes.AVOCADO_JOB_INTERRUPTED
+        elif summary:
             return exit_codes.AVOCADO_TESTS_FAIL
+        else:
+            return exit_codes.AVOCADO_ALL_OK
 
     def run(self):
         """

avocado/core/remote/runner.py

@@ -186,13 +186,13 @@ class RemoteTestRunner(TestRunner):
         :param params_list: a list of param dicts.
         :param mux: A multiplex iterator (unused here)
 
-        :return: a list of test failures.
+        :return: a set with types of test failures.
         """
         del test_suite     # using self.job.urls instead
         del mux            # we're not using multiplexation here
         if not timeout:     # avoid timeout = 0
             timeout = None
-        failures = []
+        summary = set()
 
         stdout_backup = sys.stdout
         stderr_backup = sys.stderr
@@ -239,8 +239,10 @@ class RemoteTestRunner(TestRunner):
                 state = test.get_state()
                 self.result.start_test(state)
                 self.result.check_test(state)
-                if not status.mapping[state['status']]:
-                    failures.append(state['tagged_name'])
+                if state['status'] == "INTERRUPTED":
+                    summary.add("INTERRUPTED")
+                elif not status.mapping[state['status']]:
+                    summary.add("FAIL")
             local_log_dir = self.job.logdir
             zip_filename = remote_log_dir + '.zip'
             zip_path_filename = os.path.join(local_log_dir,
@@ -257,7 +259,7 @@ class RemoteTestRunner(TestRunner):
         finally:
             sys.stdout = stdout_backup
             sys.stderr = stderr_backup
-        return failures
+        return summary
 
 
 class VMTestRunner(RemoteTestRunner):

avocado/core/runner.py

@@ -28,8 +28,8 @@ import time
 from . import test
 from . import exceptions
 from . import output
-from . import status
 from .loader import loader
+from .status import mapping
 from ..utils import wait
 from ..utils import stacktrace
 from ..utils import runtime
@@ -251,7 +251,7 @@ class TestRunner(object):
 
         def timeout_handler(signum, frame):
             e_msg = "Timeout reached waiting for %s to end" % instance
-            raise exceptions.TestTimeoutError(e_msg)
+            raise exceptions.TestTimeoutInterrupted(e_msg)
 
         def interrupt_handler(signum, frame):
             e_msg = "Test %s interrupted by user" % instance
@@ -278,7 +278,7 @@ class TestRunner(object):
         """
         pass
 
-    def run_test(self, test_factory, queue, failures, job_deadline=0):
+    def run_test(self, test_factory, queue, summary, job_deadline=0):
         """
         Run a test instance inside a subprocess.
 
@@ -286,8 +286,8 @@ class TestRunner(object):
         :type test_factory: tuple of :class:`avocado.core.test.Test` and dict.
         :param queue: Multiprocess queue.
         :type queue: :class`multiprocessing.Queue` instance.
-        :param failures: Store tests failed.
-        :type failures: list.
+        :param summary: Contains types of test failures.
+        :type summary: set.
         :param job_deadline: Maximum time to execute.
         :type job_deadline: int.
         """
@@ -395,8 +395,10 @@ class TestRunner(object):
             self.job.log.debug('')
 
         self.result.check_test(test_state)
-        if not status.mapping[test_state['status']]:
-            failures.append(test_state['name'])
+        if test_state['status'] == "INTERRUPTED":
+            summary.add("INTERRUPTED")
+        elif not mapping[test_state['status']]:
+            summary.add("FAIL")
 
         if ctrl_c_count > 0:
             return False
@@ -409,9 +411,9 @@ class TestRunner(object):
         :param test_suite: a list of tests to run.
         :param mux: the multiplexer.
         :param timeout: maximum amount of time (in seconds) to execute.
-        :return: a list of test failures.
+        :return: a set with types of test failures.
         """
-        failures = []
+        summary = set()
         if self.job.sysinfo is not None:
             self.job.sysinfo.start_job_hook()
         self.result.start_tests()
@@ -431,11 +433,12 @@ class TestRunner(object):
                 index += 1
                 test_parameters = test_factory[1]
                 if deadline is not None and time.time() > deadline:
+                    summary.add('INTERRUPTED')
                     if 'methodName' in test_parameters:
                         del test_parameters['methodName']
                     test_factory = (test.TimeOutSkipTest, test_parameters)
                     break_loop = not self.run_test(test_factory, queue,
-                                                   failures)
+                                                   summary)
                     if break_loop:
                         break
                 else:
@@ -445,7 +448,7 @@ class TestRunner(object):
                         test_factory = (replay_map[index], test_parameters)
 
                     break_loop = not self.run_test(test_factory, queue,
-                                                   failures, deadline)
+                                                   summary, deadline)
                     if break_loop:
                         break
             runtime.CURRENT_TEST = None
@@ -456,4 +459,4 @@ class TestRunner(object):
         if self.job.sysinfo is not None:
             self.job.sysinfo.end_job_hook()
         signal.signal(signal.SIGTSTP, signal.SIG_IGN)
-        return failures
+        return summary

avocado/core/test.py

@@ -369,6 +369,9 @@ class Test(unittest.TestCase):
         except exceptions.TestSkipError as details:
             stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
             raise exceptions.TestSkipError(details)
+        except exceptions.TestTimeoutSkip as details:
+            stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
+            raise exceptions.TestTimeoutSkip(details)
         except:  # Old-style exceptions are not inherited from Exception()
             stacktrace.log_exc_info(sys.exc_info(), logger='avocado.test')
             details = sys.exc_info()[1]
@@ -751,6 +754,9 @@ class TimeOutSkipTest(SkipTest):
 
     _skip_reason = "Test skipped due a job timeout!"
 
+    def setUp(self):
+        raise exceptions.TestTimeoutSkip(self._skip_reason)
+
 
 class DryRunTest(SkipTest):
 

selftests/functional/test_basic.py

@@ -197,13 +197,13 @@ class RunnerOperationTest(unittest.TestCase):
         cmd_line = './scripts/avocado run --sysinfo=off --job-results-dir %s --xunit - timeouttest' % self.tmpdir
         result = process.run(cmd_line, ignore_status=True)
         output = result.stdout
-        expected_rc = exit_codes.AVOCADO_TESTS_FAIL
+        expected_rc = exit_codes.AVOCADO_JOB_INTERRUPTED
         unexpected_rc = exit_codes.AVOCADO_FAIL
         self.assertNotEqual(result.exit_status, unexpected_rc,
                             "Avocado crashed (rc %d):\n%s" % (unexpected_rc, result))
         self.assertEqual(result.exit_status, expected_rc,
                          "Avocado did not return rc %d:\n%s" % (expected_rc, result))
-        self.assertIn("TestTimeoutError: Timeout reached waiting for", output,
+        self.assertIn("TestTimeoutInterrupted: Timeout reached waiting for", output,
                       "Test did not fail with timeout exception:\n%s" % output)
         # Ensure no test aborted error messages show up
         self.assertNotIn("TestAbortedError: Test aborted unexpectedly", output)

selftests/functional/test_job_timeout.py

@@ -108,13 +108,13 @@ class JobTimeOutTest(unittest.TestCase):
         cmd_line = ('./scripts/avocado run --job-results-dir %s --sysinfo=off '
                     '--xunit - --job-timeout=1 %s examples/tests/passtest.py' %
                     (self.tmpdir, self.script.path))
-        self.run_and_check(cmd_line, exit_codes.AVOCADO_TESTS_FAIL, 2, 1, 0, 1)
+        self.run_and_check(cmd_line, exit_codes.AVOCADO_JOB_INTERRUPTED, 2, 1, 0, 1)
 
     def test_sleep_short_timeout_with_test_methods(self):
         cmd_line = ('./scripts/avocado run --job-results-dir %s --sysinfo=off '
                     '--xunit - --job-timeout=1 %s' %
                     (self.tmpdir, self.py.path))
-        self.run_and_check(cmd_line, exit_codes.AVOCADO_TESTS_FAIL, 3, 1, 0, 2)
+        self.run_and_check(cmd_line, exit_codes.AVOCADO_JOB_INTERRUPTED, 3, 1, 0, 2)
 
     def test_invalid_values(self):
         cmd_line = ('./scripts/avocado run --job-results-dir %s --sysinfo=off '