From d2b5b3a67b0ca88b1804da30ed619cc5ba954eca Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Mon, 28 Aug 2023 20:02:45 +0900 Subject: [PATCH 1/8] add a dumb timeout logic https://github.com/WebAssembly/wasi-testsuite/issues/42 --- .../wasi_test_runner/reporters/console.py | 47 +++++++++++-------- .../wasi_test_runner/reporters/json.py | 8 +++- .../wasi_test_runner/runtime_adapter.py | 1 + test-runner/wasi_test_runner/test_case.py | 8 ++++ test-runner/wasi_test_runner/test_suite.py | 12 +++-- .../wasi_test_runner/test_suite_runner.py | 13 +++-- 6 files changed, 60 insertions(+), 29 deletions(-) diff --git a/test-runner/wasi_test_runner/reporters/console.py b/test-runner/wasi_test_runner/reporters/console.py index 8a849c2e..8c23d42c 100644 --- a/test-runner/wasi_test_runner/reporters/console.py +++ b/test-runner/wasi_test_runner/reporters/console.py @@ -2,7 +2,7 @@ from colorama import Fore, init from . import TestReporter -from ..test_case import TestCase +from ..test_case import TestCase, SkippedResult, TimedoutResult from ..test_suite import TestSuite from ..runtime_adapter import RuntimeVersion @@ -20,18 +20,21 @@ def __init__(self, colored: bool = True) -> None: self._colored = colored def report_test(self, test: TestCase) -> None: - if test.result.failed: - self._print_fail(f"Test {test.name} failed") - for reason in test.result.failures: - self._print_fail(f" [{reason.type}] {reason.message}") - print("STDOUT:") - print(test.result.output.stdout) - print("STDERR:") - print(test.result.output.stderr) - elif test.result.is_executed: - self._print_pass(f"Test {test.name} passed") - else: + if isinstance(test.result, TimedoutResult): + self._print_fail(f"Test {test.name} timed out") + elif isinstance(test.result, SkippedResult): self._print_skip(f"Test {test.name} skipped") + else: + if test.result.failed: + self._print_fail(f"Test {test.name} failed") + for reason in test.result.failures: + self._print_fail(f" [{reason.type}] {reason.message}") + print("STDOUT:") + print(test.result.output.stdout) + print("STDERR:") + print(test.result.output.stderr) + else: + self._print_pass(f"Test {test.name} passed") def report_test_suite(self, test_suite: TestSuite) -> None: self._test_suites.append(test_suite) @@ -41,29 +44,31 @@ def finalize(self, version: RuntimeVersion) -> None: print("===== Test results =====") print(f"Runtime: {version.name} {version.version}") - total_skip = total_pass = total_fail = pass_suite = 0 + total_skip = total_pass = total_fail = total_timedout = pass_suite = 0 for suite in self._test_suites: total_pass += suite.pass_count total_fail += suite.fail_count total_skip += suite.skip_count + total_timedout += suite.timedout_count - if suite.fail_count == 0: + if suite.fail_count == 0 and suite.timedout_count == 0: pass_suite += 1 print(f"Suite: {suite.name}") print(f" Total: {suite.test_count}") - self._print_pass(f" Passed: {suite.pass_count}") - self._print_fail(f" Failed: {suite.fail_count}") - self._print_skip(f" Skipped: {suite.skip_count}") + self._print_pass(f" Passed: {suite.pass_count}") + self._print_fail(f" Failed: {suite.fail_count}") + self._print_skip(f" Skipped: {suite.skip_count}") + self._print_fail(f" Timed out: {suite.timedout_count}") print("") print( - f"Test suites: {self._get_summary(len(self._test_suites) - pass_suite, pass_suite, 0)}" + f"Test suites: {self._get_summary(len(self._test_suites) - pass_suite, pass_suite, 0, 0)}" ) - print(f"Tests: {self._get_summary(total_fail, total_pass, total_skip)}") + print(f"Tests: {self._get_summary(total_fail, total_pass, total_skip, total_timedout)}") - def _get_summary(self, fail_count: int, pass_count: int, skip_count: int) -> str: + def _get_summary(self, fail_count: int, pass_count: int, skip_count: int, timedout_count: int) -> str: items: List[str] = [] if fail_count: @@ -72,6 +77,8 @@ def _get_summary(self, fail_count: int, pass_count: int, skip_count: int) -> str items.append(f"{self._pass_color}{pass_count} passed") if skip_count: items.append(f"{self._skip_color}{skip_count} skipped") + if timedout_count: + items.append(f"{self._fail_color}{timedout_count} timed out") total = fail_count + pass_count + skip_count items.append(f"{self._reset_color}{total} total") diff --git a/test-runner/wasi_test_runner/reporters/json.py b/test-runner/wasi_test_runner/reporters/json.py index 023f5563..3a4e9606 100644 --- a/test-runner/wasi_test_runner/reporters/json.py +++ b/test-runner/wasi_test_runner/reporters/json.py @@ -5,6 +5,7 @@ from . import TestReporter from ..test_suite import TestSuite +from ..test_case import Result, SkippedResult, TimedoutResult from ..runtime_adapter import RuntimeVersion @@ -28,16 +29,19 @@ def finalize(self, version: RuntimeVersion) -> None: "duration_s": suite.duration_s, "failed": suite.fail_count, "skipped": suite.skip_count, + "timedout": suite.timedout_count, "passed": suite.pass_count, "tests": [ { "name": test.name, - "executed": test.result.is_executed, + "executed": isinstance(test.result, Result), + "skipped": isinstance(test.result, SkippedResult), + "timedout": isinstance(test.result, TimedoutResult), "duration_s": test.duration_s, "wasi_functions": test.config.wasi_functions, "failures": [ failure.message for failure in test.result.failures - ], + ] if isinstance(test.result, Result) else [], } for test in suite.test_cases ], diff --git a/test-runner/wasi_test_runner/runtime_adapter.py b/test-runner/wasi_test_runner/runtime_adapter.py index 940c2e2c..dbc50a9a 100644 --- a/test-runner/wasi_test_runner/runtime_adapter.py +++ b/test-runner/wasi_test_runner/runtime_adapter.py @@ -48,6 +48,7 @@ def run_test( text=True, check=False, cwd=Path(test_path).parent, + timeout=3. ) return Output(result.returncode, result.stdout, result.stderr) diff --git a/test-runner/wasi_test_runner/test_case.py b/test-runner/wasi_test_runner/test_case.py index eebb95d3..d6cbae93 100644 --- a/test-runner/wasi_test_runner/test_case.py +++ b/test-runner/wasi_test_runner/test_case.py @@ -24,6 +24,14 @@ def failed(self) -> bool: return len(self.failures) > 0 +class TimedoutResult(NamedTuple): + pass + + +class SkippedResult(NamedTuple): + pass + + T = TypeVar("T", bound="Config") diff --git a/test-runner/wasi_test_runner/test_suite.py b/test-runner/wasi_test_runner/test_suite.py index 4681cd9a..09b1b9d3 100644 --- a/test-runner/wasi_test_runner/test_suite.py +++ b/test-runner/wasi_test_runner/test_suite.py @@ -1,6 +1,6 @@ from typing import NamedTuple, List from datetime import datetime -from .test_case import TestCase +from .test_case import TestCase, Result, SkippedResult, TimedoutResult class TestSuite(NamedTuple): @@ -19,7 +19,7 @@ def pass_count(self) -> int: [ 1 for test in self.test_cases - if test.result.is_executed and test.result.failed is False + if isinstance(test.result, Result) and test.result.failed is False ] ) @@ -29,10 +29,14 @@ def fail_count(self) -> int: [ 1 for test in self.test_cases - if test.result.is_executed and test.result.failed + if isinstance(test.result, Result) and test.result.failed ] ) @property def skip_count(self) -> int: - return len([1 for test in self.test_cases if not test.result.is_executed]) + return len([1 for test in self.test_cases if isinstance(test.result, SkippedResult)]) + + @property + def timedout_count(self) -> int: + return len([1 for test in self.test_cases if isinstance(test.result, TimedoutResult)]) diff --git a/test-runner/wasi_test_runner/test_suite_runner.py b/test-runner/wasi_test_runner/test_suite_runner.py index c9a26b14..32360dda 100644 --- a/test-runner/wasi_test_runner/test_suite_runner.py +++ b/test-runner/wasi_test_runner/test_suite_runner.py @@ -3,6 +3,7 @@ import os import re import shutil +import subprocess import time from datetime import datetime @@ -12,6 +13,8 @@ from .runtime_adapter import RuntimeAdapter from .test_case import ( Result, + SkippedResult, + TimedoutResult, Config, Output, TestCase, @@ -67,7 +70,7 @@ def _skip_single_test( return TestCase( name=os.path.splitext(os.path.basename(test_path))[0], config=config, - result=Result(output=Output(0, "", ""), is_executed=False, failures=[]), + result=SkippedResult(), duration_s=0, ) @@ -77,13 +80,17 @@ def _execute_single_test( ) -> TestCase: config = _read_test_config(test_path) test_start = time.time() - test_output = runtime.run_test(test_path, config.args, config.env, config.dirs) + try: + test_output = runtime.run_test(test_path, config.args, config.env, config.dirs) + result=_validate(validators, config, test_output) + except subprocess.TimeoutExpired: + result=TimedoutResult() elapsed = time.time() - test_start return TestCase( name=os.path.splitext(os.path.basename(test_path))[0], config=config, - result=_validate(validators, config, test_output), + result=result, duration_s=elapsed, ) From 6dbcca3217ffad53db31608b3183ba13dd21ac49 Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 13:25:49 +0900 Subject: [PATCH 2/8] update after total fix --- test-runner/wasi_test_runner/reporters/console.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test-runner/wasi_test_runner/reporters/console.py b/test-runner/wasi_test_runner/reporters/console.py index 8c23d42c..a5225b2e 100644 --- a/test-runner/wasi_test_runner/reporters/console.py +++ b/test-runner/wasi_test_runner/reporters/console.py @@ -80,7 +80,7 @@ def _get_summary(self, fail_count: int, pass_count: int, skip_count: int, timedo if timedout_count: items.append(f"{self._fail_color}{timedout_count} timed out") - total = fail_count + pass_count + skip_count + total = fail_count + pass_count + skip_count + timedout_count items.append(f"{self._reset_color}{total} total") return ", ".join(items) From 8781de976b8c3fdf530de6cb06e17484f14cb6a3 Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 14:57:16 +0900 Subject: [PATCH 3/8] runtime_adapter.py: on timeout, use SIGTERM to stop the child XXX what to do for non-unix platforms? --- test-runner/wasi_test_runner/runtime_adapter.py | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/test-runner/wasi_test_runner/runtime_adapter.py b/test-runner/wasi_test_runner/runtime_adapter.py index dbc50a9a..5994610b 100644 --- a/test-runner/wasi_test_runner/runtime_adapter.py +++ b/test-runner/wasi_test_runner/runtime_adapter.py @@ -42,15 +42,20 @@ def run_test( + [e for env in self._env_to_list(env_variables) for e in ("--env", env)] ) - result = subprocess.run( + p = subprocess.Popen( args, - capture_output=True, + stdout=subprocess.PIPE, + stderr=subprocess.PIPE, text=True, - check=False, cwd=Path(test_path).parent, - timeout=3. ) - return Output(result.returncode, result.stdout, result.stderr) + try: + out, err = p.communicate(timeout=3) + except subprocess.TimeoutExpired: + p.terminate() + p.wait() + raise + return Output(p.returncode, out, err) @staticmethod def _abs(path: str) -> str: From f0c8b3b3cd6a4d1412e2c92e933723d70cdca992 Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 15:01:16 +0900 Subject: [PATCH 4/8] doc/adapters.md: mention timeout note: the end of file change is an unrelated editor artifact. (nvi2) --- doc/adapters.md | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/doc/adapters.md b/doc/adapters.md index 84010f29..a1cb25be 100644 --- a/doc/adapters.md +++ b/doc/adapters.md @@ -32,6 +32,11 @@ The adapter must return exit code to the environment that was passed as an argum and check if the exit code is equal to `13`. There are also two test cases in Assembly Script test suite that verify the behavior: * [proc_exit-failure](../tests/assemblyscript/testsuite/proc_exit-failure.ts) * [proc_exit-success](../tests/assemblyscript/testsuite/proc_exit-success.ts) + +On a timeout, the test runner sends SIGTERM singal to the adapter process. +When receiving the signal, the adapter process should clean up and exit +as soon as possible. + ### Examples: Print runtime version: @@ -61,4 +66,4 @@ See the [`adapters`](../adapters) directory for example adapters. We prefer runtime maintainers to maintain adapters in their own repository We'll only maintain adapters for [Bytecode Alliance](https://bytecodealliance.org/) projects and we'll aim for compatibility with the most recent stable version. -We'll accept pull requests for new adapters in this repository, but we can't guarantee we'll have the capacity to maintain them (so they might stop working with the new runtime release). \ No newline at end of file +We'll accept pull requests for new adapters in this repository, but we can't guarantee we'll have the capacity to maintain them (so they might stop working with the new runtime release). From 48930f384c4df2c323e89fc3c91bbcdd8ef4aad4 Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 15:28:04 +0900 Subject: [PATCH 5/8] fix mypy complaints --- test-runner/wasi_test_runner/test_case.py | 4 ++-- test-runner/wasi_test_runner/test_suite_runner.py | 6 +++--- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/test-runner/wasi_test_runner/test_case.py b/test-runner/wasi_test_runner/test_case.py index d6cbae93..c2953607 100644 --- a/test-runner/wasi_test_runner/test_case.py +++ b/test-runner/wasi_test_runner/test_case.py @@ -1,6 +1,6 @@ import logging import json -from typing import List, NamedTuple, TypeVar, Type, Dict, Any, Optional +from typing import List, NamedTuple, TypeVar, Type, Dict, Any, Optional, Union class Output(NamedTuple): @@ -71,5 +71,5 @@ def _validate_dict(cls: Type[T], dict_config: Dict[str, Any]) -> None: class TestCase(NamedTuple): name: str config: Config - result: Result + result: Union[Result | SkippedResult | TimedoutResult] duration_s: float diff --git a/test-runner/wasi_test_runner/test_suite_runner.py b/test-runner/wasi_test_runner/test_suite_runner.py index 32360dda..269b4ef5 100644 --- a/test-runner/wasi_test_runner/test_suite_runner.py +++ b/test-runner/wasi_test_runner/test_suite_runner.py @@ -7,7 +7,7 @@ import time from datetime import datetime -from typing import List, cast +from typing import List, cast, Union from .filters import TestFilter from .runtime_adapter import RuntimeAdapter @@ -82,9 +82,9 @@ def _execute_single_test( test_start = time.time() try: test_output = runtime.run_test(test_path, config.args, config.env, config.dirs) - result=_validate(validators, config, test_output) + result: Union[Result | TimedoutResult] = _validate(validators, config, test_output) except subprocess.TimeoutExpired: - result=TimedoutResult() + result = TimedoutResult() elapsed = time.time() - test_start return TestCase( From fbe0e1d768b3b12070fe1f56b6e70d7b3ee8541c Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 15:41:43 +0900 Subject: [PATCH 6/8] pylint, black --- .../wasi_test_runner/runtime_adapter.py | 22 ++++++++++--------- 1 file changed, 12 insertions(+), 10 deletions(-) diff --git a/test-runner/wasi_test_runner/runtime_adapter.py b/test-runner/wasi_test_runner/runtime_adapter.py index 5994610b..9a8c8885 100644 --- a/test-runner/wasi_test_runner/runtime_adapter.py +++ b/test-runner/wasi_test_runner/runtime_adapter.py @@ -17,7 +17,9 @@ def __init__(self, adapter_path: str) -> None: def get_version(self) -> RuntimeVersion: output = ( - subprocess.check_output([sys.executable, self._adapter_path, "--version"], encoding="UTF-8") + subprocess.check_output( + [sys.executable, self._adapter_path, "--version"], encoding="UTF-8" + ) .strip() .split(" ") ) @@ -42,20 +44,20 @@ def run_test( + [e for env in self._env_to_list(env_variables) for e in ("--env", env)] ) - p = subprocess.Popen( + with subprocess.Popen( args, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, cwd=Path(test_path).parent, - ) - try: - out, err = p.communicate(timeout=3) - except subprocess.TimeoutExpired: - p.terminate() - p.wait() - raise - return Output(p.returncode, out, err) + ) as proc: + try: + out, err = proc.communicate(timeout=3) + except subprocess.TimeoutExpired: + proc.terminate() + proc.wait() + raise + return Output(proc.returncode, out, err) @staticmethod def _abs(path: str) -> str: From 26eb7babdaf9695e0df6853fe1941b83c3c3a9ab Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 19:28:16 +0900 Subject: [PATCH 7/8] remove Result::is_executed --- test-runner/wasi_test_runner/test_case.py | 1 - test-runner/wasi_test_runner/test_suite_runner.py | 2 +- 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/test-runner/wasi_test_runner/test_case.py b/test-runner/wasi_test_runner/test_case.py index c2953607..f091c213 100644 --- a/test-runner/wasi_test_runner/test_case.py +++ b/test-runner/wasi_test_runner/test_case.py @@ -16,7 +16,6 @@ class Failure(NamedTuple): class Result(NamedTuple): output: Output - is_executed: bool failures: List[Failure] @property diff --git a/test-runner/wasi_test_runner/test_suite_runner.py b/test-runner/wasi_test_runner/test_suite_runner.py index 269b4ef5..c3ee9c56 100644 --- a/test-runner/wasi_test_runner/test_suite_runner.py +++ b/test-runner/wasi_test_runner/test_suite_runner.py @@ -102,7 +102,7 @@ def _validate(validators: List[Validator], config: Config, output: Output) -> Re if result is not None ] - return Result(failures=failures, is_executed=True, output=output) + return Result(failures=failures, output=output) def _read_test_config(test_path: str) -> Config: From 7d2796f89e56786635fc57820b94fc5ed78b6de6 Mon Sep 17 00:00:00 2001 From: YAMAMOTO Takashi Date: Tue, 29 Aug 2023 19:28:39 +0900 Subject: [PATCH 8/8] tests: minimum updates --- test-runner/tests/test_test_case.py | 4 ++-- test-runner/tests/test_test_suite.py | 2 +- test-runner/tests/test_test_suite_runner.py | 6 +++--- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/test-runner/tests/test_test_case.py b/test-runner/tests/test_test_case.py index ad87ab91..8fef8839 100644 --- a/test-runner/tests/test_test_case.py +++ b/test-runner/tests/test_test_case.py @@ -42,12 +42,12 @@ def test_test_config_should_warn_when_unknown_field(_mock_file: Mock) -> None: def test_test_results_should_mark_failed_if_multiple_failures() -> None: - results = Result(Output(0, "", ""), True, [Failure("type", "message")]) + results = Result(Output(0, "", ""), [Failure("type", "message")]) assert results.failed is True def test_test_results_should_not_mark_failed_if_no_failure() -> None: - results = Result(Output(0, "", ""), True, []) + results = Result(Output(0, "", ""), []) assert results.failed is False diff --git a/test-runner/tests/test_test_suite.py b/test-runner/tests/test_test_suite.py index 530ed6c2..06884b48 100644 --- a/test-runner/tests/test_test_suite.py +++ b/test-runner/tests/test_test_suite.py @@ -9,7 +9,7 @@ def create_test_case(name: str, is_executed: bool, is_failed: bool) -> tc.TestCa return tc.TestCase( name, tc.Config(), - tc.Result(tc.Output(0, "", ""), is_executed, failures), + tc.Result(tc.Output(0, "", ""), failures) if is_executed else tc.SkippedResult(), 1.0, ) diff --git a/test-runner/tests/test_test_suite_runner.py b/test-runner/tests/test_test_suite_runner.py index d73438de..cc39a7c4 100644 --- a/test-runner/tests/test_test_suite_runner.py +++ b/test-runner/tests/test_test_suite_runner.py @@ -35,9 +35,9 @@ def test_runner_end_to_end() -> None: tc.Output(2, "test3", ""), ] expected_results = [ - tc.Result(outputs[0], True, []), - tc.Result(outputs[1], True, [failures[1]]), - tc.Result(outputs[2], True, [failures[0], failures[2]]), + tc.Result(outputs[0], []), + tc.Result(outputs[1], [failures[1]]), + tc.Result(outputs[2], [failures[0], failures[2]]), ] expected_config = [ tc.Config(dirs=[".", "deep/dir"]),