Re: [PATCH v1 2/2] kunit: tool: parse KTAP compliant test output

Daniel Latypov
2022-11-07T22:59:00Z

On Fri, Nov 4, 2022 at 12:48 PM Rae Moar <rmoar@google.com> wrote:
>
> Change the KUnit parser to be able to parse test output that complies with
> the KTAP version 1 specification format found here:
> https://kernel.org/doc/html/latest/dev-tools/ktap.html. Ensure the parser
> is able to parse tests with the original KUnit test output format as
> well.
>
> KUnit parser now accepts any of the following test output formats:
>
> Original KUnit test output format:
>
> TAP version 14
> 1..1
> # Subtest: kunit-test-suite
> 1..3
> ok 1 - kunit_test_1
> ok 2 - kunit_test_2
> ok 3 - kunit_test_3
> # kunit-test-suite: pass:3 fail:0 skip:0 total:3
> # Totals: pass:3 fail:0 skip:0 total:3
> ok 1 - kunit-test-suite
>
> KTAP version 1 test output format:
>
> KTAP version 1
> 1..1
> KTAP version 1
> 1..3
> ok 1 kunit_test_1
> ok 2 kunit_test_2
> ok 3 kunit_test_3
> ok 1 kunit-test-suite
>
> New KUnit test output format (preferred for KUnit tests):
>
> KTAP version 1
> 1..1
> # Subtest: kunit-test-suite
> KTAP version 1
> 1..3
> ok 1 kunit_test_1
> ok 2 kunit_test_2
> ok 3 kunit_test_3
> # kunit-test-suite: pass:3 fail:0 skip:0 total:3
> # Totals: pass:3 fail:0 skip:0 total:3
> ok 1 kunit-test-suite
>
> Signed-off-by: Rae Moar <rmoar@google.com>

Reviewed-by: Daniel Latypov <dlatypov@google.com>

Looks good to me.
Some comments below, but nothing we have to address in this patch, IMO.

> ---
> Note: this patch is based on the linux-kselftest/kunit branch.
> ---
> tools/testing/kunit/kunit_parser.py | 69 ++++++++++++-------
> tools/testing/kunit/kunit_tool_test.py | 8 +++
> .../test_data/test_parse_ktap_output.log | 8 +++
> 3 files changed, 60 insertions(+), 25 deletions(-)
> create mode 100644 tools/testing/kunit/test_data/test_parse_ktap_output.log
>
> diff --git a/tools/testing/kunit/kunit_parser.py b/tools/testing/kunit/kunit_parser.py
> index a56c75a973b5..abb69f898263 100644
> --- a/tools/testing/kunit/kunit_parser.py
> +++ b/tools/testing/kunit/kunit_parser.py
> @@ -441,6 +441,7 @@ def parse_diagnostic(lines: LineStream) -> List[str]:
> - '# Subtest: [test name]'
> - '[ok|not ok] [test number] [-] [test name] [optional skip
> directive]'
> + - 'KTAP version [version number]'
>
> Parameters:
> lines - LineStream of KTAP output to parse
> @@ -449,8 +450,9 @@ def parse_diagnostic(lines: LineStream) -> List[str]:
> Log of diagnostic lines
> """
> log = [] # type: List[str]
> - while lines and not TEST_RESULT.match(lines.peek()) and not \
> - TEST_HEADER.match(lines.peek()):
> + non_diagnostic_lines = [TEST_RESULT, TEST_HEADER, KTAP_START]
> + while lines and not any(re.match(lines.peek())
> + for re in non_diagnostic_lines):
> log.append(lines.pop())
> return log
>
> @@ -496,6 +498,12 @@ def print_test_header(test: Test) -> None:
> test - Test object representing current test being printed
> """
> message = test.name
> + if message == "":
> + # KUnit tests print a Subtest header line that provides the name
> + # of the test suite. But the subtest header line isn't required
> + # by the KTAP spec, so use a placeholder name "Test suite" in that
> + # case.
> + message = "Test suite"

(something we can address in a later change)

Hmm, consider the following input

KTAP version 1
1..1
KTAP version 1
1..1
KTAP version 1
1..1
ok 1 - subtest1
ok 1 - test1
ok 1 - suite

$ ./tools/testing/kunit/kunit.py parse < /tmp/example_nested_ktap
============================================================
================== Test suite (1 subtest) ==================
================== Test suite (1 subtest) ==================
[PASSED] subtest1
====================== [PASSED] test1 ======================
====================== [PASSED] suite ======================
============================================================

I wonder if the duplicate "Test suite" line would be confusing.
This also points to a slightly bigger problem that kunit_parser.py
doesn't have a good way to format 3+ layers of tests atm.

I don't know if there's another placeholder name we can give that
might be less confusing.

> if test.expected_count:
> if test.expected_count == 1:
> message += ' (1 subtest)'
> @@ -647,13 +655,13 @@ def bubble_up_test_results(test: Test) -> None:
> elif test.counts.get_status() == TestStatus.TEST_CRASHED:
> test.status = TestStatus.TEST_CRASHED
>
> -def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> +def parse_test(lines: LineStream, expected_num: int, log: List[str], is_subtest: bool) -> Test:
> """
> Finds next test to parse in LineStream, creates new Test object,
> parses any subtests of the test, populates Test object with all
> information (status, name) about the test and the Test objects for
> any subtests, and then returns the Test object. The method accepts
> - three formats of tests:
> + four formats of tests:
>
> Accepted test formats:
>
> @@ -674,6 +682,16 @@ def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> [subtests]
> ok 1 name
>
> + - KTAP subtest header (in compliance with KTAP specification)
> +
> + Example:
> +
> + # May include subtest header line here
> + KTAP version 1
> + 1..3
> + [subtests]
> + ok 1 name
> +
> - Test result line
>
> Example:
> @@ -685,6 +703,7 @@ def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> expected_num - expected test number for test to be parsed
> log - list of strings containing any preceding diagnostic lines
> corresponding to the current test
> + is_subtest - boolean indicating whether test is a subtest
>
> Return:
> Test object populated with characteristics and any subtests
> @@ -692,21 +711,22 @@ def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> test = Test()
> test.log.extend(log)
> parent_test = False
> - main = parse_ktap_header(lines, test)
> - if main:
> - # If KTAP/TAP header is found, attempt to parse
> - # test plan
> + if not is_subtest:
> + # If parsing the main test, attempt to parse KTAP/TAP header
> + # and test plan
> test.name = "main"
> + parse_ktap_header(lines, test)
> parse_test_plan(lines, test)
> parent_test = True
> else:
> - # If KTAP/TAP header is not found, test must be subtest
> - # header or test result line so parse attempt to parser
> - # subtest header
> - parent_test = parse_test_header(lines, test)
> + # If test is a subtest, attempt to parse test suite header
> + # (either subtest line and/or KTAP/TAP version line)
> + subtest_line = parse_test_header(lines, test)
> + ktap_line = parse_ktap_header(lines, test)
> + parent_test = subtest_line or ktap_line
> if parent_test:
> - # If subtest header is found, attempt to parse
> - # test plan and print header
> + # If subtest header and/or KTAP/version line is found, attempt
> + # to parse test plan and print header
> parse_test_plan(lines, test)
> print_test_header(test)
> expected_count = test.expected_count
> @@ -721,7 +741,7 @@ def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> sub_log = parse_diagnostic(lines)
> sub_test = Test()
> if not lines or (peek_test_name_match(lines, test) and
> - not main):
> + is_subtest):
> if expected_count and test_num <= expected_count:
> # If parser reaches end of test before
> # parsing expected number of subtests, print
> @@ -735,20 +755,19 @@ def parse_test(lines: LineStream, expected_num: int, log: List[str]) -> Test:
> test.log.extend(sub_log)
> break
> else:
> - sub_test = parse_test(lines, test_num, sub_log)
> + sub_test = parse_test(lines, test_num, sub_log, True)
> subtests.append(sub_test)
> test_num += 1
> test.subtests = subtests
> - if not main:
> + if is_subtest:
> # If not main test, look for test result line
> test.log.extend(parse_diagnostic(lines))
> - if (parent_test and peek_test_name_match(lines, test)) or \
> - not parent_test:
> - parse_test_result(lines, test, expected_num)
> - else:
> + if subtest_line and not peek_test_name_match(lines, test):
> test.add_error('missing subtest result line!')
> + else:
> + parse_test_result(lines, test, expected_num)

This change isn't a straightforward change of the logic like
s/main/not is_subtest.
But looking at it, it seems fine.

One example input would be

KTAP version 1
1..2
# Subtest: suite1
KTAP version 1
1..1
ok 1 test1
# ok 1 suite1
ok 2 suite2

We get output like this

$ ./tools/testing/kunit/kunit.py parse < /tmp/out
[14:54:44] ============================================================
[14:54:44] ==================== suite1 (1 subtest) ====================
[14:54:44] [PASSED] test1
[14:54:44] [ERROR] Test: suite1: missing subtest result line!
[14:54:44] # Subtest: suite1
[14:54:44] KTAP version 1
[14:54:44] 1..1
[14:54:44] # ok 1 suite1
[14:54:44] ===================== [CRASHED] suite1 =====================
[14:54:44] [PASSED] suite2
[14:54:44] ============================================================

So it handles it about as well as we could expect.

Note: kunit.py is indeed saying the kernel crashed even though there's
"kernel output" after the missing line. But this is a pre-existing
condition. It already doesn't check to see that the output is
truncated before saying "CRASHED"