Skip to content

Commit

Permalink
Merge pull request avocado-framework#5820 from clebergnu/timeout_factor
Browse files Browse the repository at this point in the history 
Signed-off-by: Jan Richter <[email protected]>
  • Loading branch information
@richtja
richtja authored Dec 7, 2023
2 parents 96078b2 + f8e9cc4 commit 5a3381a
Show file tree
Hide file tree
Showing 4 changed files with 80 additions and 37 deletions.
10 changes: 9 additions & 1 deletion avocado/core/test.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -318,7 +318,12 @@ def record_and_warn(*args, **kwargs):
elif isinstance(params, tuple):
params, paths = params[0], params[1]
self.__params = parameters.AvocadoParams(params, paths, self.__log.name)
self.timeout = self.params.get("timeout", default=self.timeout)
self.timeout = original_timeout = self.params.get(
"timeout", default=self.timeout
)
timeout_factor = float(self.params.get("timeout_factor", default=1.0))
if original_timeout is not None:
self.timeout = float(original_timeout) * timeout_factor

self.__status = None
self.__fail_reason = None
Expand Down Expand Up @@ -346,6 +351,9 @@ def record_and_warn(*args, **kwargs):
pass
else:
self.log.debug(" teststmpdir: %s", teststmpdir)
self.log.debug(" original timeout: %s", original_timeout)
self.log.debug(" timeout factor: %s", timeout_factor)
self.log.debug(" actual timeout: %s", self.timeout)

unittest.TestCase.__init__(self, methodName=methodName)
TestData.__init__(self)
Expand Down
81 changes: 46 additions & 35 deletions docs/source/guides/writer/chapters/writing.rst
View file
Original file line number Diff line number Diff line change
Expand Up @@ -793,53 +793,64 @@ Setting a Test Timeout
Sometimes your test suite/test might get stuck forever, and this might
impact your test grid. You can account for that possibility and set up a
``timeout`` parameter for your test. The test timeout can be set through
the test parameters, as shown below.
test parameters. The included example "sleep test" contains a default
sleep time of 1 second.
::
.. literalinclude:: ../../../../../examples/tests/sleeptest.py
sleep_length: 5
timeout: 3
Which can be run with a timeout (shorter the sleep time) with::
$ avocado run -p timeout=0.5 examples/tests/sleeptest.py
JOB ID : 01f7e7e9ee82a331c1c6a6b3a939f694d9c0c948
JOB LOG : $HOME/avocado/job-results/job-2016-11-02T11.13-01f7e7e/job.log
(1/1) examples/tests/sleeptest.py:SleepTest.test: STARTED
(1/1) examples/tests/sleeptest.py:SleepTest.test: INTERRUPTED: Test interrupted: Timeout reached (0.53 s)
RESULTS : PASS 0 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 1
JOB TIME : 2.14 s
JOB HTML : $HOME/avocado/job-results/job-2016-11-02T11.13-01f7e7e/html/results.html
::
When the timeout is reached, the spawner will terminate the test
runner task, making it raise a
:class:`avocado.core.exceptions.TestInterruptedError`. The termination
process is specific to spawner implementation, for more information
see :class:`avocado.core.plugin_interfaces.Spawner.terminate_task`.
$ avocado run examples/tests/sleeptest.py --mux-yaml /tmp/sleeptest-example.yaml
JOB ID : c78464bde9072a0b5601157989a99f0ba32a288e
JOB LOG : $HOME/avocado/job-results/job-2016-11-02T11.13-c78464b/job.log
(1/1) examples/tests/sleeptest.py:SleepTest.test;run-0fc1: STARTED
(1/1) examples/tests/sleeptest.py:SleepTest.test;run-0fc1: INTERRUPTED: timeout (3.01 s)
RESULTS : PASS 0 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 1
JOB TIME : 3.14 s
JOB HTML : $HOME/avocado/job-results/job-2016-11-02T11.13-c78464b/html/results.html
Timeout Factor
~~~~~~~~~~~~~~
Like it was mentioned before, a test may have an (adequate) timeout,
set as a class attribute, such as in the following included example
test:
::
.. literalinclude:: ../../../../../examples/tests/timeouttest.py
$ cat $HOME/avocado/job-results/job-2016-11-02T11.13-c78464b/job.log
2021-10-01 15:44:53,622 job L0319 INFO | Multiplex tree representation:
2021-10-01 15:44:53,622 job L0319 INFO | \-- run
2021-10-01 15:44:53,622 job L0319 INFO |
2021-10-01 15:44:53,622 job L0319 INFO | Multiplex variants (1):
2021-10-01 15:44:53,622 job L0319 INFO | Variant run-0fc1: /run
2021-10-01 15:44:53,622 job L0312 INFO | Temporary dir: /tmp/avocado_tmp_hp4cswyn/avocado_job_pmn___6i
2021-10-01 15:44:53,622 job L0313 INFO |
2021-10-01 15:44:53,622 job L0306 INFO | Job ID: 927fdc4143e9e093a485319820825faacc0f36a3
2021-10-01 15:44:53,622 job L0309 INFO |
2021-10-01 15:44:54,165 selector_events L0059 DEBUG| Using selector: EpollSelector
2021-10-01 15:44:54,622 testlogs L0094 INFO | examples/tests/sleeptest.py:SleepTest.test;run-0fc1: STARTED
2021-10-01 15:44:57,653 testlogs L0101 INFO | examples/tests/sleeptest.py:SleepTest.test;run-0fc1: INTERRUPTED
2021-10-01 15:44:57,654 testlogs L0103 INFO | More information in /home/jarichte/avocado/job-results/job-2021-10-01T15.44-927fdc4/test-results/1-examples_tests_sleeptest.py_SleepTest.test_run-0fc1
2021-10-01 15:44:57,762 job L0643 INFO | Test results available in /home/jarichte/avocado/job-results/job-2021-10-01T15.44-927fdc4
But, depending on the environment it may be executed (maybe by a
different user, on a slower machine or more limited network), the
hardcoded timeout won't be adequate anymore.
On those circumstances, it's possible to set a "timeout factor". This
can be given as a parameter, and is pretty much a multiplier to the
timeout. Example::
$ avocado run -p timeout_factor=2.0 examples/tests/timeouttest.py
JOB ID : 55722574664b01077dffd5504e329ad5e0062cc8
JOB LOG : $HOME/avocado/job-results/job-2023-11-29T11.16-5572257/job.log
(1/1) examples/tests/timeouttest.py:TimeoutTest.test: STARTED
(1/1) examples/tests/timeouttest.py:TimeoutTest.test: PASS (5.01 s)
RESULTS : PASS 1 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0 | CANCEL 0
JOB HTML : $HOME/avocado/job-results/job-2023-11-29T11.16-5572257/results.html
JOB TIME : 7.77 s
The YAML file defines a test parameter ``timeout`` which overrides
the default test timeout. When the timeout is reached, the spawner
will terminate the test runner task, making it raise a
:class:`avocado.core.exceptions.TestInterruptedError`. The termination
process is specific to spawner implementation, for more information see
:class:`avocado.core.plugin_interfaces.Spawner.terminate_task`.
Notice how, under normal circumstances, the test would have timed out,
due to the sleep time (5.0 seconds) being larger than the timeout set
in the class attribute (``timeout = 3``).
The actual timeout will be given in the "Test metadata" section in
test logs. For the previous test execution it shows::
[stdlog] 2023-11-29 11:16:23,745 test L0345 DEBUG| Test metadata:
...
[stdlog] 2023-11-29 11:16:23,746 test L0354 DEBUG| actual timeout: 6.0
Skipping Tests
--------------
Expand Down
2 changes: 1 addition & 1 deletion examples/tests/timeouttest.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,6 @@ def test(self):
"""
This should throw a TestTimeoutError.
"""
sleep_time = self.params.get("sleep_time", default=5)
sleep_time = float(self.params.get("sleep_time", default=5.0))
self.log.info("Sleeping for %.2f seconds (2 more than the timeout)", sleep_time)
time.sleep(sleep_time)
24 changes: 24 additions & 0 deletions selftests/functional/basic.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -511,6 +511,30 @@ def test_runner_timeout(self):
# Ensure no test aborted error messages show up
self.assertNotIn(b"TestAbortError: Test aborted unexpectedly", output)

def test_runner_timeout_factor(self):
cmd_line = (
f"{AVOCADO} run --disable-sysinfo --job-results-dir "
f"{self.tmpdir.name} -p sleep_time=7 -p timeout_factor=3.0"
" -- examples/tests/timeouttest.py"
)
result = process.run(cmd_line, ignore_status=True)
json_path = os.path.join(self.tmpdir.name, "latest", "results.json")
with open(json_path, encoding="utf-8") as json_file:
result_json = json.load(json_file)
expected_rc = exit_codes.AVOCADO_ALL_OK
unexpected_rc = exit_codes.AVOCADO_JOB_INTERRUPTED
self.assertNotEqual(
result.exit_status,
unexpected_rc,
f"Avocado result not expected (rc {unexpected_rc}):\n{result}",
)
self.assertEqual(
result.exit_status,
expected_rc,
f"Avocado did not return rc {expected_rc}:\n{result}",
)
self.assertNotIn("timeout", result_json["tests"][0]["fail_reason"])

def test_silent_output(self):
cmd_line = (
f"{AVOCADO} --show=none run --disable-sysinfo "
Expand Down

0 comments on commit 5a3381a

Please sign in to comment.