kunit: tool: internal refactor of parser input handling

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 LineStream 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.

[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.

Now we could easily add this to trace all the lines consumed and why
+import inspect
...
        def pop(self) -> str:
                n = self._next
+               print(f'popping {n[0]}: {n[1].ljust(40, " ")}| caller={inspect.stack()[1].function}')

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@google.com>
Reviewed-by: David Gow <davidgow@google.com>
Acked-by: Brendan Higgins <brendanhiggins@google.com>
Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
This commit is contained in:
Daniel Latypov 2021-05-26 01:22:17 -07:00 committed by Shuah Khan
parent ebd09577be
commit b29b14f11d
2 changed files with 99 additions and 55 deletions

View File

@ -47,22 +47,63 @@ class TestStatus(Enum):
NO_TESTS = auto()
FAILURE_TO_PARSE_TESTS = auto()
class LineStream:
"""Provides a peek()/pop() interface over an iterator of (line#, text)."""
_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:|reboot: System halted)')
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 extract_tap_lines(kernel_output: Iterable[str]) -> LineStream:
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 LineStream(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: LineStream) -> 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: LineStream, 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: LineStream, 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: LineStream, 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: LineStream) -> 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: LineStream) -> 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: LineStream) -> 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: LineStream,
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: LineStream, 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: LineStream) -> 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: LineStream) -> 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: LineStream) -> 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 = extract_tap_lines(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:

View File

@ -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.LineStream):
# 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.extract_tap_lines(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.extract_tap_lines(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.extract_tap_lines(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.extract_tap_lines(file.readlines()))
print_mock.assert_any_call(StrContains('no tests run!'))
print_mock.stop()
file.close()