Fix timeout handling in Python tests (#72621)
* Fix timeout handling in Python tests
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Fix timeout handling in Python tests
* Implement post-review changes
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Don't add --timeout twice
* Update scripts/tests/run_python_test.py
Co-authored-by: Andrei Litvin <andy314@gmail.com>
* Annotate timeout durations as final
* Put back global `timeout` as internal test script timeout in TC_CLCTRL_*
* Handle TimeoutError thrown by Subprocess.wait()
* Fix mypy issue
* Add some slack time in the runner so that the test can handle timeouts by itself before being terminated
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Don't add --timeout to test script on your own, use --timeout script arg as source of run timeout if the 'timeout' key is not defined
* Restore TCs changed before
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Update docs
* Fix mypy
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Remove spurious file
* Restore mobile-device-test.py timeout flag
* Adjust TestMatterTestingSupport
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Rework to allow parse_known_args() to be used on the matter test arg parser
* Fix docs
* parse_known_args() returns a tuple
* Warn if script timeout is more than run timeout
* Make main_args names clearer
* [pre-commit.ci] auto fixes from pre-commit.com hooks
for more information, see https://pre-commit.ci
* Fix ruff errors
* Fix merge error
* update another rename conflict
---------
Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com>
Co-authored-by: Andrei Litvin <andy314@gmail.com>
diff --git a/docs/testing/python.md b/docs/testing/python.md
index 75f857a..c86bdc0 100644
--- a/docs/testing/python.md
+++ b/docs/testing/python.md
@@ -845,6 +845,7 @@
# app-args: <app_arguments>
# script-args: <script_arguments>
# factory-reset: <true|false>
+# timeout: <float> [optional]
# quiet: <true|false>
# === END CI TEST ARGUMENTS ===
```
@@ -863,6 +864,13 @@
- Example: `true`
+- `timeout`: Sets the timeout of the test script. When this timeout expires
+ the test run is considered failed. The value is in seconds.
+
+ - Example: `700.6`
+ - Default: Value of test script `--timeout` argument plus slack time,
+ otherwise `matter.testing.defaults.TestingDefaults.DEFAULT_TIMEOUT_S`
+
- `quiet`: Sets the verbosity level of the test run. When set to True, the
test run will be quieter.
diff --git a/scripts/tests/run_python_test.py b/scripts/tests/run_python_test.py
index 399a035..23af401 100755
--- a/scripts/tests/run_python_test.py
+++ b/scripts/tests/run_python_test.py
@@ -39,7 +39,9 @@
import coloredlogs
from colorama import Fore, Style
+from matter.testing.defaults import TestingDefaults
from matter.testing.metadata import Metadata, MetadataReader
+from matter.testing.runner import matter_test_args_parser
from matter.testing.tasks import Subprocess
log = logging.getLogger(__name__)
@@ -183,6 +185,27 @@
self.dump_filename.unlink(missing_ok=True)
+def run_timeout(run: Metadata) -> float:
+ script_timeout = None
+
+ if run.script_args is not None:
+ p = matter_test_args_parser()
+ (args, _) = p.parse_known_args(shlex.split(run.script_args))
+ script_timeout = args.timeout
+
+ if run.timeout is not None and script_timeout is not None:
+ if run.timeout < script_timeout:
+ log.warning("Run timeout for run '%s' (%f s) will expire earlier than script timeout (%d s)",
+ run.run, run.timeout, script_timeout)
+
+ if run.timeout is not None:
+ return run.timeout
+ if script_timeout is not None:
+ return script_timeout + TestingDefaults.TEST_RUNNER_SLACK_S
+
+ return TestingDefaults.DEFAULT_TIMEOUT_S
+
+
@click.command()
@click.option("--app", type=click.Path(exists=True), default=None,
help='Path to local application to use, omit to use external apps.')
@@ -266,7 +289,7 @@
log.info("Executing '%s' '%s'", run.py_script_path.split('/')[-1], run.run)
main_impl(run.app, run.factory_reset, run.factory_reset_app_only, run.app_args or "", run.app_ready_pattern,
run.app_stdin_pipe, run.py_script_path, run.script_args or "", run.script_gdb, ip_packet_capture,
- ip_packet_capture_dir, run.quiet, run.run)
+ ip_packet_capture_dir, run_timeout(run), run.quiet, run.run)
class AppRestartMonitor:
@@ -338,7 +361,7 @@
def main_impl(app: str, factory_reset: bool, factory_reset_app_only: bool, app_args: str,
app_ready_pattern: str, app_stdin_pipe: str, script: str, script_args: str,
script_gdb: bool, ip_packet_capture: bool, ip_packet_capture_dir: pathlib.Path,
- quiet: bool, run_name: str):
+ run_timeout: float, quiet: bool, run_name: str):
app_args = app_args.replace('{SCRIPT_BASE_NAME}', os.path.splitext(os.path.basename(script))[0])
script_args = script_args.replace('{SCRIPT_BASE_NAME}', os.path.splitext(os.path.basename(script))[0])
@@ -409,7 +432,11 @@
test_script_process.p.stdin.close()
try:
- test_script_exit_code = test_script_process.wait()
+ try:
+ test_script_exit_code = test_script_process.wait(run_timeout)
+ except TimeoutError as e:
+ log.exception("%r", e)
+ test_script_exit_code = -1 # Trigger error codepath
if test_script_exit_code != 0:
log.error("Test script exited with returncode %d", test_script_exit_code)
diff --git a/src/python_testing/matter_testing_infrastructure/matter/testing/defaults.py b/src/python_testing/matter_testing_infrastructure/matter/testing/defaults.py
index e60915b..80202ae 100644
--- a/src/python_testing/matter_testing_infrastructure/matter/testing/defaults.py
+++ b/src/python_testing/matter_testing_infrastructure/matter/testing/defaults.py
@@ -29,3 +29,8 @@
CONTROLLER_NODE_ID: final = 112233
DUT_NODE_ID: final = 0x12344321
TRUST_ROOT_INDEX: final = 1
+
+ # Subprocess handling
+ DEFAULT_TIMEOUT_S: final = 300.0 # Default timeout when waiting for a subprocess to finish its job
+ TERMINATION_TIMEOUT_S: final = 5.0 # Default timeout for subprocess termination
+ TEST_RUNNER_SLACK_S: final = 60 # Slack time to allow a testcase to timeout itself before it's killed
diff --git a/src/python_testing/matter_testing_infrastructure/matter/testing/metadata.py b/src/python_testing/matter_testing_infrastructure/matter/testing/metadata.py
index 3bdaa1e..680a452 100644
--- a/src/python_testing/matter_testing_infrastructure/matter/testing/metadata.py
+++ b/src/python_testing/matter_testing_infrastructure/matter/testing/metadata.py
@@ -33,6 +33,7 @@
factory_reset: bool = False
factory_reset_app_only: bool = False
script_gdb: bool = False
+ timeout: float | None = None
quiet: bool = False
@@ -153,6 +154,7 @@
app_stdin_pipe=attr.get("app-stdin-pipe"),
script_args=attr.get("script-args"),
factory_reset=str(attr.get("factory-reset", False)).lower() == 'true',
+ timeout=float(attr["timeout"]) if "timeout" in attr else None,
quiet=str(attr.get("quiet", True)).lower() == 'true',
))
diff --git a/src/python_testing/matter_testing_infrastructure/matter/testing/runner.py b/src/python_testing/matter_testing_infrastructure/matter/testing/runner.py
index 25bcc06..397dcfc 100644
--- a/src/python_testing/matter_testing_infrastructure/matter/testing/runner.py
+++ b/src/python_testing/matter_testing_infrastructure/matter/testing/runner.py
@@ -336,7 +336,8 @@
default_matter_test_main()
"""
- matter_test_config = parse_matter_test_args()
+ p = matter_test_args_parser()
+ matter_test_config = convert_args_to_matter_config(p.parse_args())
# Find the test class in the test script.
test_class = _find_test_class()
@@ -942,7 +943,7 @@
return root_index
-def parse_matter_test_args(argv: list[str] | None = None):
+def matter_test_args_parser() -> argparse.ArgumentParser:
parser = argparse.ArgumentParser(description='Matter standalone Python test')
basic_group = parser.add_argument_group(title="Basic arguments", description="Overall test execution arguments")
@@ -1081,7 +1082,4 @@
args_group.add_argument('--hex-arg', nargs='+', action='append', type=bytes_as_hex_named_arg, metavar="NAME:VALUE",
help="Add a named test argument for an octet string in hex (e.g. 0011cafe or 00:11:CA:FE)")
- if not argv:
- argv = sys.argv[1:]
-
- return convert_args_to_matter_config(parser.parse_args(argv))
+ return parser
diff --git a/src/python_testing/matter_testing_infrastructure/matter/testing/tasks.py b/src/python_testing/matter_testing_infrastructure/matter/testing/tasks.py
index 5621c22..7d1256c 100644
--- a/src/python_testing/matter_testing_infrastructure/matter/testing/tasks.py
+++ b/src/python_testing/matter_testing_infrastructure/matter/testing/tasks.py
@@ -24,6 +24,8 @@
from enum import StrEnum
from typing import BinaryIO, Self
+from matter.testing.defaults import TestingDefaults
+
LOGGER = logging.getLogger(__name__)
@@ -71,9 +73,6 @@
class Subprocess(threading.Thread):
"""Run a subprocess in a thread."""
- DEFAULT_TIMEOUT_S: float = 300.0
- TERMINATION_TIMEOUT_S: float = 5.0
-
def __init__(self, program: str, *args: str, output_cb: Callable[[bytes, bool], bytes] | None = None,
f_stdout: BinaryIO = sys.stdout.buffer, f_stderr: BinaryIO = sys.stderr.buffer) -> None:
"""Initialize the subprocess.
@@ -154,16 +153,16 @@
self.returncode = -1
if forwarding_stdout_thread is not None:
- forwarding_stdout_thread.join(self.TERMINATION_TIMEOUT_S)
+ forwarding_stdout_thread.join(TestingDefaults.TERMINATION_TIMEOUT_S)
if forwarding_stdout_thread.is_alive():
LOGGER.warning("Forwarding stdout thread did not finish within timeout")
if forwarding_stderr_thread is not None:
- forwarding_stderr_thread.join(self.TERMINATION_TIMEOUT_S)
+ forwarding_stderr_thread.join(TestingDefaults.TERMINATION_TIMEOUT_S)
if forwarding_stderr_thread.is_alive():
LOGGER.warning("Forwarding stderr thread did not finish within timeout")
- def start(self, expected_output: str | re.Pattern | None = None, timeout: float = DEFAULT_TIMEOUT_S) -> None:
+ def start(self, expected_output: str | re.Pattern | None = None, timeout: float = TestingDefaults.DEFAULT_TIMEOUT_S) -> None:
"""Start a subprocess and optionally wait for a specific output."""
if expected_output is not None:
@@ -183,7 +182,7 @@
raise TimeoutError(f"Expected output {expected_output!r} not found within {timeout} seconds")
def send(self, message: str, end: str = "\n", expected_output: str | re.Pattern | None = None,
- timeout: float = DEFAULT_TIMEOUT_S) -> None:
+ timeout: float = TestingDefaults.DEFAULT_TIMEOUT_S) -> None:
"""Send a message to a process and optionally wait for a response."""
if expected_output is not None:
@@ -205,17 +204,20 @@
return
self.p.terminate()
- self.join(self.TERMINATION_TIMEOUT_S)
+ self.join(TestingDefaults.TERMINATION_TIMEOUT_S)
if not self.is_alive() and self.returncode is not None:
return
LOGGER.warning("Subprocess or controller thread did not terminate within timeout. Killing the process instead")
self.p.kill()
- self.join(self.TERMINATION_TIMEOUT_S)
+ self.join(TestingDefaults.TERMINATION_TIMEOUT_S)
if self.is_alive() or self.returncode is None:
LOGGER.warning("Failed to kill subprocess within timeout. We may be leaving a zombie process")
- def wait(self, timeout: float = DEFAULT_TIMEOUT_S) -> int | None:
+ def wait(self, timeout: float = TestingDefaults.DEFAULT_TIMEOUT_S) -> int | None:
"""Wait for the subprocess to finish."""
self.join(timeout)
+ if self.is_alive():
+ self.terminate()
+ raise TimeoutError(f"Subprocess `{self.program} {shlex.join(self.args)}` did not finish within {timeout} seconds")
return self.returncode
diff --git a/src/python_testing/test_testing/TestMatterTestingSupport.py b/src/python_testing/test_testing/TestMatterTestingSupport.py
index 7e8b7c7..1976df5 100644
--- a/src/python_testing/test_testing/TestMatterTestingSupport.py
+++ b/src/python_testing/test_testing/TestMatterTestingSupport.py
@@ -27,7 +27,7 @@
from matter.testing.decorators import async_test_body
from matter.testing.matter_testing import MatterBaseTest
from matter.testing.pics import parse_pics, parse_pics_xml
-from matter.testing.runner import default_matter_test_main, parse_matter_test_args
+from matter.testing.runner import convert_args_to_matter_config, default_matter_test_main, matter_test_args_parser
from matter.testing.taglist_and_topology_test import (TagProblem, build_tree_for_graph, create_device_type_list_for_root,
create_device_type_lists, find_tag_list_problems, find_tree_roots,
flat_list_ok, get_all_children, get_direct_children_of_root,
@@ -730,7 +730,8 @@
"--json-arg", "PIXIT.TEST.JSON:{\"key\":\"value\"}",
]
- parsed = parse_matter_test_args(args)
+ p = matter_test_args_parser()
+ parsed = convert_args_to_matter_config(p.parse_args(args))
asserts.assert_equal(parsed.tests, ["TC_1", "TC_2"])
asserts.assert_equal(parsed.global_test_params.get("PIXIT.TEST.DEC"), 42)
asserts.assert_equal(parsed.global_test_params.get("PIXIT.TEST.HEX"), 0x1234)
