On Wed, May 26, 2021 at 7:43 AM Daniel Latypov <dlatypov@xxxxxxxxxx> wrote:
>
> Note: this does not change the parser behavior at all (except for making
> one error message more useful). This is just an internal refactor.
>
> The TAP output parser currently operates over a List[str].
> This works, but we only ever need to be able to "peek" at the current
> line and the ability to "pop" it off.
>
> Also, using a List means we need to wait for all the output before we
> can start parsing. While this is not an issue for most tests which are
> really lightweight, we do have some longer (~5 minutes) tests.
>
> This patch introduces an Input wrapper class that
> * Exposes a peek()/pop() interface instead of manipulating an array
> * this allows us to more easily add debugging code [1]
> * Can consume an input from a generator
> * we can now parse results as tests are running (the parser code
> currently doesn't print until the end, so no impact yet).
> * Tracks the current line number to print better error messages
> * Would allow us to add additional features more easily, e.g. storing
> N previous lines so we can print out invalid lines in context, etc.
I do like this design of having a test input stream which tracks line
numbers, etc. The peek()/pop() interface does match TAP reasonably
nicely, too: particularly since it's line based. Thumbs up from me!
> [1] The parsing logic is currently quite fragile.
> E.g. it'll often say the kernel "CRASHED" if there's something slightly
> wrong with the output format. When debugging a test that had some memory
> corruption issues, it resulted in very misleading errors from the parser.
Alas, this is very true. The plan is to do a significant rework of the
parser to make it more resilient to input which doesn't exactly match
what we expect (it doesn't even handle all valid TAP streams
correctly).
> Now we could easily add this to trace all the lines consumed and why
> def pop(self) -> str:
> n = self._next
> + print(f'popping {n[0]}: {n[1].ljust(40, " ")}| caller={inspect.stack()[1].function}')
I tried this, and it's very nice. I did need to add an "import
inspect" line for the inspect.stack() function. Not sure if that's
worth mentioning here.
>
> Example output:
> popping 77: TAP version 14 | caller=parse_tap_header
> popping 78: 1..1 | caller=parse_test_plan
> popping 79: # Subtest: kunit_executor_test | caller=parse_subtest_header
> popping 80: 1..2 | caller=parse_subtest_plan
> popping 81: ok 1 - parse_filter_test | caller=parse_ok_not_ok_test_case
> popping 82: ok 2 - filter_subsuite_test | caller=parse_ok_not_ok_test_case
> popping 83: ok 1 - kunit_executor_test | caller=parse_ok_not_ok_test_suite
>
> If we introduce an invalid line, we can see the parser go down the wrong path:
> popping 77: TAP version 14 | caller=parse_tap_header
> popping 78: 1..1 | caller=parse_test_plan
> popping 79: # Subtest: kunit_executor_test | caller=parse_subtest_header
> popping 80: 1..2 | caller=parse_subtest_plan
> popping 81: 1..2 # this is invalid! | caller=parse_ok_not_ok_test_case
> popping 82: ok 1 - parse_filter_test | caller=parse_ok_not_ok_test_case
> popping 83: ok 2 - filter_subsuite_test | caller=parse_ok_not_ok_test_case
> popping 84: ok 1 - kunit_executor_test | caller=parse_ok_not_ok_test_case
> [ERROR] ran out of lines before end token
>
> Signed-off-by: Daniel Latypov <dlatypov@xxxxxxxxxx>
> ---
This looks good. The only issues I have are with the names "Input" and
"get_input", which are a little bit confusing: comments below.
Apart from those, though, this is:
Reviewed-by: David Gow <davidgow@xxxxxxxxxx>
Cheers,
-- David
> tools/testing/kunit/kunit_parser.py | 136 ++++++++++++++++---------
> tools/testing/kunit/kunit_tool_test.py | 18 ++--
> 2 files changed, 99 insertions(+), 55 deletions(-)
>
> diff --git a/tools/testing/kunit/kunit_parser.py b/tools/testing/kunit/kunit_parser.py
> index e8bcc139702e..65adb386364a 100644
> --- a/tools/testing/kunit/kunit_parser.py
> +++ b/tools/testing/kunit/kunit_parser.py
> @@ -47,22 +47,63 @@ class TestStatus(Enum):
> NO_TESTS = auto()
> FAILURE_TO_PARSE_TESTS = auto()
>
> +class Input:
This class name is a little bit confusing, particularly with the
description below of it being an interface around
isolate_kunit_output(). While, on the whole, I agree that this is
"input" from the parser's point of view, the fact that what we're
parsing is kernel output makes the nomenclature here a bit messy.
Maybe name this "ParserInput" or even "TAPTestStream" (which appears
to be the name used for TAP formatted results on the testanything.org
page)?
> + """Provides a more convenient interface over isolate_kunit_output()."""
> + _lines: Iterator[Tuple[int, str]]
> + _next: Tuple[int, str]
> + _done: bool
> +
> + def __init__(self, lines: Iterator[Tuple[int, str]]):
> + self._lines = lines
> + self._done = False
> + self._next = (0, '')
> + self._get_next()
> +
> + def _get_next(self) -> None:
> + try:
> + self._next = next(self._lines)
> + except StopIteration:
> + self._done = True
> +
> + def peek(self) -> str:
> + return self._next[1]
> +
> + def pop(self) -> str:
> + n = self._next
> + self._get_next()
> + return n[1]
> +
> + def __bool__(self) -> bool:
> + return not self._done
> +
> + # Only used by kunit_tool_test.py.
> + def __iter__(self) -> Iterator[str]:
> + while bool(self):
> + yield self.pop()
> +
> + def line_number(self) -> int:
> + return self._next[0]
> +
> kunit_start_re = re.compile(r'TAP version [0-9]+$')
> kunit_end_re = re.compile('(List of all partitions:|'
> 'Kernel panic - not syncing: VFS:)')
>
> -def isolate_kunit_output(kernel_output) -> Iterator[str]:
> - started = False
> - for line in kernel_output:
> - line = line.rstrip() # line always has a trailing \n
> - if kunit_start_re.search(line):
> - prefix_len = len(line.split('TAP version')[0])
> - started = True
> - yield line[prefix_len:] if prefix_len > 0 else line
> - elif kunit_end_re.search(line):
> - break
> - elif started:
> - yield line[prefix_len:] if prefix_len > 0 else line
> +def get_input(kernel_output: Iterable[str]) -> Input:
Again, I think we need a clearer name for "get_input" here.
"extract_tap_stream"/"get_parser_input_from_kernel_log" or something?
Ideally it'd specify that we're doing the isolation/extraction of the
TAP data from the kernel log, to distinguish it from parsing already
isolated TAP, which is something we may wish to do.
> + def isolate_kunit_output(kernel_output: Iterable[str]) -> Iterator[Tuple[int, str]]:
> + line_num = 0
> + started = False
> + for line in kernel_output:
> + line_num += 1
> + line = line.rstrip() # line always has a trailing \n
> + if kunit_start_re.search(line):
> + prefix_len = len(line.split('TAP version')[0])
> + started = True
> + yield line_num, line[prefix_len:]
> + elif kunit_end_re.search(line):
> + break
> + elif started:
> + yield line_num, line[prefix_len:]
> + return Input(lines=isolate_kunit_output(kernel_output))
>
> def raw_output(kernel_output) -> None:
> for line in kernel_output:
> @@ -97,14 +138,14 @@ def print_log(log) -> None:
>
> TAP_ENTRIES = re.compile(r'^(TAP|[\s]*ok|[\s]*not ok|[\s]*[0-9]+\.\.[0-9]+|[\s]*#).*$')
>
> -def consume_non_diagnostic(lines: List[str]) -> None:
> - while lines and not TAP_ENTRIES.match(lines[0]):
> - lines.pop(0)
> +def consume_non_diagnostic(lines: Input) -> None:
> + while lines and not TAP_ENTRIES.match(lines.peek()):
> + lines.pop()
>
> -def save_non_diagnostic(lines: List[str], test_case: TestCase) -> None:
> - while lines and not TAP_ENTRIES.match(lines[0]):
> - test_case.log.append(lines[0])
> - lines.pop(0)
> +def save_non_diagnostic(lines: Input, test_case: TestCase) -> None:
> + while lines and not TAP_ENTRIES.match(lines.peek()):
> + test_case.log.append(lines.peek())
> + lines.pop()
>
> OkNotOkResult = namedtuple('OkNotOkResult', ['is_ok','description', 'text'])
>
> @@ -112,18 +153,18 @@ OK_NOT_OK_SUBTEST = re.compile(r'^[\s]+(ok|not ok) [0-9]+ - (.*)$')
>
> OK_NOT_OK_MODULE = re.compile(r'^(ok|not ok) ([0-9]+) - (.*)$')
>
> -def parse_ok_not_ok_test_case(lines: List[str], test_case: TestCase) -> bool:
> +def parse_ok_not_ok_test_case(lines: Input, test_case: TestCase) -> bool:
> save_non_diagnostic(lines, test_case)
> if not lines:
> test_case.status = TestStatus.TEST_CRASHED
> return True
> - line = lines[0]
> + line = lines.peek()
> match = OK_NOT_OK_SUBTEST.match(line)
> while not match and lines:
> - line = lines.pop(0)
> + line = lines.pop()
> match = OK_NOT_OK_SUBTEST.match(line)
> if match:
> - test_case.log.append(lines.pop(0))
> + test_case.log.append(lines.pop())
> test_case.name = match.group(2)
> if test_case.status == TestStatus.TEST_CRASHED:
> return True
> @@ -138,14 +179,14 @@ def parse_ok_not_ok_test_case(lines: List[str], test_case: TestCase) -> bool:
> SUBTEST_DIAGNOSTIC = re.compile(r'^[\s]+# (.*)$')
> DIAGNOSTIC_CRASH_MESSAGE = re.compile(r'^[\s]+# .*?: kunit test case crashed!$')
>
> -def parse_diagnostic(lines: List[str], test_case: TestCase) -> bool:
> +def parse_diagnostic(lines: Input, test_case: TestCase) -> bool:
> save_non_diagnostic(lines, test_case)
> if not lines:
> return False
> - line = lines[0]
> + line = lines.peek()
> match = SUBTEST_DIAGNOSTIC.match(line)
> if match:
> - test_case.log.append(lines.pop(0))
> + test_case.log.append(lines.pop())
> crash_match = DIAGNOSTIC_CRASH_MESSAGE.match(line)
> if crash_match:
> test_case.status = TestStatus.TEST_CRASHED
> @@ -153,7 +194,7 @@ def parse_diagnostic(lines: List[str], test_case: TestCase) -> bool:
> else:
> return False
>
> -def parse_test_case(lines: List[str]) -> Optional[TestCase]:
> +def parse_test_case(lines: Input) -> Optional[TestCase]:
> test_case = TestCase()
> save_non_diagnostic(lines, test_case)
> while parse_diagnostic(lines, test_case):
> @@ -165,24 +206,24 @@ def parse_test_case(lines: List[str]) -> Optional[TestCase]:
>
> SUBTEST_HEADER = re.compile(r'^[\s]+# Subtest: (.*)$')
>
> -def parse_subtest_header(lines: List[str]) -> Optional[str]:
> +def parse_subtest_header(lines: Input) -> Optional[str]:
> consume_non_diagnostic(lines)
> if not lines:
> return None
> - match = SUBTEST_HEADER.match(lines[0])
> + match = SUBTEST_HEADER.match(lines.peek())
> if match:
> - lines.pop(0)
> + lines.pop()
> return match.group(1)
> else:
> return None
>
> SUBTEST_PLAN = re.compile(r'[\s]+[0-9]+\.\.([0-9]+)')
>
> -def parse_subtest_plan(lines: List[str]) -> Optional[int]:
> +def parse_subtest_plan(lines: Input) -> Optional[int]:
> consume_non_diagnostic(lines)
> - match = SUBTEST_PLAN.match(lines[0])
> + match = SUBTEST_PLAN.match(lines.peek())
> if match:
> - lines.pop(0)
> + lines.pop()
> return int(match.group(1))
> else:
> return None
> @@ -199,17 +240,17 @@ def max_status(left: TestStatus, right: TestStatus) -> TestStatus:
> else:
> return TestStatus.SUCCESS
>
> -def parse_ok_not_ok_test_suite(lines: List[str],
> +def parse_ok_not_ok_test_suite(lines: Input,
> test_suite: TestSuite,
> expected_suite_index: int) -> bool:
> consume_non_diagnostic(lines)
> if not lines:
> test_suite.status = TestStatus.TEST_CRASHED
> return False
> - line = lines[0]
> + line = lines.peek()
> match = OK_NOT_OK_MODULE.match(line)
> if match:
> - lines.pop(0)
> + lines.pop()
> if match.group(1) == 'ok':
> test_suite.status = TestStatus.SUCCESS
> else:
> @@ -231,7 +272,7 @@ def bubble_up_test_case_errors(test_suite: TestSuite) -> TestStatus:
> max_test_case_status = bubble_up_errors(x.status for x in test_suite.cases)
> return max_status(max_test_case_status, test_suite.status)
>
> -def parse_test_suite(lines: List[str], expected_suite_index: int) -> Optional[TestSuite]:
> +def parse_test_suite(lines: Input, expected_suite_index: int) -> Optional[TestSuite]:
> if not lines:
> return None
> consume_non_diagnostic(lines)
> @@ -257,26 +298,26 @@ def parse_test_suite(lines: List[str], expected_suite_index: int) -> Optional[Te
> print_with_timestamp(red('[ERROR] ') + 'ran out of lines before end token')
> return test_suite
> else:
> - print('failed to parse end of suite' + lines[0])
> + print(f'failed to parse end of suite "{name}", at line {lines.line_number()}: {lines.peek()}')
> return None
>
> TAP_HEADER = re.compile(r'^TAP version 14$')
>
> -def parse_tap_header(lines: List[str]) -> bool:
> +def parse_tap_header(lines: Input) -> bool:
> consume_non_diagnostic(lines)
> - if TAP_HEADER.match(lines[0]):
> - lines.pop(0)
> + if TAP_HEADER.match(lines.peek()):
> + lines.pop()
> return True
> else:
> return False
>
> TEST_PLAN = re.compile(r'[0-9]+\.\.([0-9]+)')
>
> -def parse_test_plan(lines: List[str]) -> Optional[int]:
> +def parse_test_plan(lines: Input) -> Optional[int]:
> consume_non_diagnostic(lines)
> - match = TEST_PLAN.match(lines[0])
> + match = TEST_PLAN.match(lines.peek())
> if match:
> - lines.pop(0)
> + lines.pop()
> return int(match.group(1))
> else:
> return None
> @@ -284,7 +325,7 @@ def parse_test_plan(lines: List[str]) -> Optional[int]:
> def bubble_up_suite_errors(test_suites: Iterable[TestSuite]) -> TestStatus:
> return bubble_up_errors(x.status for x in test_suites)
>
> -def parse_test_result(lines: List[str]) -> TestResult:
> +def parse_test_result(lines: Input) -> TestResult:
> consume_non_diagnostic(lines)
> if not lines or not parse_tap_header(lines):
> return TestResult(TestStatus.NO_TESTS, [], lines)
> @@ -338,11 +379,12 @@ def print_and_count_results(test_result: TestResult) -> Tuple[int, int, int]:
> print_with_timestamp('')
> return total_tests, failed_tests, crashed_tests
>
> -def parse_run_tests(kernel_output) -> TestResult:
> +def parse_run_tests(kernel_output: Iterable[str]) -> TestResult:
> total_tests = 0
> failed_tests = 0
> crashed_tests = 0
> - test_result = parse_test_result(list(isolate_kunit_output(kernel_output)))
> + lines = get_input(kernel_output)
> + test_result = parse_test_result(lines)
> if test_result.status == TestStatus.NO_TESTS:
> print(red('[ERROR] ') + yellow('no tests run!'))
> elif test_result.status == TestStatus.FAILURE_TO_PARSE_TESTS:
> diff --git a/tools/testing/kunit/kunit_tool_test.py b/tools/testing/kunit/kunit_tool_test.py
> index 2e809dd956a7..e82678a25bef 100755
> --- a/tools/testing/kunit/kunit_tool_test.py
> +++ b/tools/testing/kunit/kunit_tool_test.py
> @@ -11,6 +11,7 @@ from unittest import mock
>
> import tempfile, shutil # Handling test_tmpdir
>
> +import itertools
> import json
> import signal
> import os
> @@ -92,17 +93,18 @@ class KconfigTest(unittest.TestCase):
>
> class KUnitParserTest(unittest.TestCase):
>
> - def assertContains(self, needle, haystack):
> - for line in haystack:
> + def assertContains(self, needle: str, haystack: kunit_parser.Input):
> + # Clone the iterator so we can print the contents on failure.
> + copy, backup = itertools.tee(haystack)
> + for line in copy:
> if needle in line:
> return
> - raise AssertionError('"' +
> - str(needle) + '" not found in "' + str(haystack) + '"!')
> + raise AssertionError(f'"{needle}" not found in {list(backup)}!')
>
> def test_output_isolated_correctly(self):
> log_path = test_data_path('test_output_isolated_correctly.log')
> with open(log_path) as file:
> - result = kunit_parser.isolate_kunit_output(file.readlines())
> + result = kunit_parser.get_input(file.readlines())
> self.assertContains('TAP version 14', result)
> self.assertContains(' # Subtest: example', result)
> self.assertContains(' 1..2', result)
> @@ -113,7 +115,7 @@ class KUnitParserTest(unittest.TestCase):
> def test_output_with_prefix_isolated_correctly(self):
> log_path = test_data_path('test_pound_sign.log')
> with open(log_path) as file:
> - result = kunit_parser.isolate_kunit_output(file.readlines())
> + result = kunit_parser.get_input(file.readlines())
> self.assertContains('TAP version 14', result)
> self.assertContains(' # Subtest: kunit-resource-test', result)
> self.assertContains(' 1..5', result)
> @@ -159,7 +161,7 @@ class KUnitParserTest(unittest.TestCase):
> empty_log = test_data_path('test_is_test_passed-no_tests_run.log')
> with open(empty_log) as file:
> result = kunit_parser.parse_run_tests(
> - kunit_parser.isolate_kunit_output(file.readlines()))
> + kunit_parser.get_input(file.readlines()))
> self.assertEqual(0, len(result.suites))
> self.assertEqual(
> kunit_parser.TestStatus.NO_TESTS,
> @@ -170,7 +172,7 @@ class KUnitParserTest(unittest.TestCase):
> print_mock = mock.patch('builtins.print').start()
> with open(crash_log) as file:
> result = kunit_parser.parse_run_tests(
> - kunit_parser.isolate_kunit_output(file.readlines()))
> + kunit_parser.get_input(file.readlines()))
> print_mock.assert_any_call(StrContains('no tests run!'))
> print_mock.stop()
> file.close()
>
> base-commit: c3d0e3fd41b7f0f5d5d5b6022ab7e813f04ea727
> --
> 2.31.1.818.g46aad6cb9e-goog
>
