diff --git a/avocado/core/test.py b/avocado/core/test.py index 763cf705bb..fedac7d772 100644 --- a/avocado/core/test.py +++ b/avocado/core/test.py @@ -22,6 +22,8 @@ import functools import inspect import logging +import multiprocessing +import multiprocessing.pool import os import shutil import sys @@ -654,14 +656,26 @@ def _setup_environment_variables(self): def _catch_test_status(self, method): """Wrapper around test methods for catching and logging failures.""" - try: + + def set_new_event_loop_for_method(method): + asyncio.set_event_loop(asyncio.new_event_loop()) method() - if self.__log_warn_used and self.__status not in STATUSES_NOT_OK: - raise exceptions.TestWarn( - "Test passed but there were warnings " - "during execution. Check the log for " - "details." - ) + + try: + pool = multiprocessing.pool.ThreadPool(1) + res = pool.apply_async(set_new_event_loop_for_method, [method]) + pool.close() + try: + res.get(self.timeout) + if self.__log_warn_used and self.__status not in STATUSES_NOT_OK: + raise exceptions.TestWarn( + "Test passed but there were warnings " + "during execution. Check the log for " + "details." + ) + except multiprocessing.TimeoutError: + raise exceptions.TestInterrupt("Test interrupted: Timeout reached") + except exceptions.TestBaseException as detail: self.__status = detail.status self.__fail_class = detail.__class__.__name__ @@ -686,6 +700,8 @@ def _catch_test_status(self, method): ) for e_line in tb_info: self.log.error(e_line) + finally: + pool.terminate() def run_avocado(self): """ diff --git a/avocado/plugins/runners/avocado_instrumented.py b/avocado/plugins/runners/avocado_instrumented.py index a08ecceaa2..5aa779bd7e 100644 --- a/avocado/plugins/runners/avocado_instrumented.py +++ b/avocado/plugins/runners/avocado_instrumented.py @@ -8,11 +8,7 @@ from avocado.core.exceptions import TestInterrupt from avocado.core.nrunner.app import BaseRunnerApp -from avocado.core.nrunner.runner import ( - RUNNER_RUN_CHECK_INTERVAL, - RUNNER_RUN_STATUS_INTERVAL, - BaseRunner, -) +from avocado.core.nrunner.runner import RUNNER_RUN_CHECK_INTERVAL, BaseRunner from avocado.core.test import TestID from avocado.core.tree import TreeNodeEnvOnly from avocado.core.utils import loader, messages @@ -138,23 +134,14 @@ def _run_avocado(runnable, queue): ) @staticmethod - def _monitor(proc, time_started, queue): - timeout = float("inf") - next_status_time = None + def _monitor(queue): while True: time.sleep(RUNNER_RUN_CHECK_INTERVAL) - now = time.monotonic() if queue.empty(): - if next_status_time is None or now > next_status_time: - next_status_time = now + RUNNER_RUN_STATUS_INTERVAL - yield messages.RunningMessage.get() - if (now - time_started) > timeout: - proc.terminate() + yield messages.RunningMessage.get() else: message = queue.get() - if message.get("type") == "early_state": - timeout = float(message.get("timeout") or float("inf")) - else: + if message.get("type") != "early_state": yield message if message.get("status") == "finished": break @@ -172,13 +159,12 @@ def run(self, runnable): process.start() - time_started = time.monotonic() - for message in self._monitor(process, time_started, queue): + for message in self._monitor(queue): yield message except TestInterrupt: process.terminate() - for message in self._monitor(process, time_started, queue): + for message in self._monitor(queue): yield message except Exception as e: yield messages.StderrMessage.get(traceback.format_exc()) diff --git a/selftests/check.py b/selftests/check.py index d24009bd49..da86be24ce 100755 --- a/selftests/check.py +++ b/selftests/check.py @@ -29,7 +29,7 @@ "nrunner-requirement": 28, "unit": 678, "jobs": 11, - "functional-parallel": 313, + "functional-parallel": 314, "functional-serial": 7, "optional-plugins": 0, "optional-plugins-golang": 2, diff --git a/selftests/functional/plugin/runners/avocado_instrumented.py b/selftests/functional/plugin/runners/avocado_instrumented.py index efcddba787..ed8e9c1390 100644 --- a/selftests/functional/plugin/runners/avocado_instrumented.py +++ b/selftests/functional/plugin/runners/avocado_instrumented.py @@ -1,8 +1,30 @@ +import json +import os + from avocado import Test from avocado.core.exit_codes import AVOCADO_JOB_INTERRUPTED -from avocado.utils import process +from avocado.utils import process, script from selftests.utils import AVOCADO, TestCaseTmpDir +TIMEOU_TEST_WITH_EXCEPTION = """ +import time + +from avocado import Test + +class TimeoutTest(Test): + + timeout = 3 + + def test(self): + try: + time.sleep(5) + except Exception: + pass + + def tearDown(self): + self.log.info("TearDown") +""" + class AvocadoInstrumentedRunnerTest(TestCaseTmpDir, Test): def test_timeout(self): @@ -16,3 +38,30 @@ def test_timeout(self): "examples/tests/timeouttest.py:TimeoutTest.test: INTERRUPTED: Test interrupted: Timeout reached", result.stdout_text, ) + + def test_timeout_with_exception(self): + with script.TemporaryScript( + "test_timeout.py", + TIMEOU_TEST_WITH_EXCEPTION, + "avocado_timeout_test", + ) as tst: + res = process.run( + ( + f"{AVOCADO} run --disable-sysinfo " + f"--job-results-dir {self.tmpdir.name} {tst} " + f"--json -" + ), + ignore_status=True, + ) + results = json.loads(res.stdout_text) + self.assertIn( + "Test interrupted: Timeout reached", + results["tests"][0]["fail_reason"], + ) + debug_log_path = results["tests"][0]["logfile"] + self.assertTrue(os.path.exists(debug_log_path)) + with open(debug_log_path, encoding="utf-8") as file: + self.assertIn( + "INFO | TearDown", + file.read(), + )