Re: [PATCH] kunit: tool: make parser preserve whitespace when printing test log

From: David Gow
Date: Tue Dec 06 2022 - 22:43:56 EST


On Thu, Dec 1, 2022 at 2:54 AM 'Daniel Latypov' via KUnit Development
<kunit-dev@xxxxxxxxxxxxxxxx> wrote:
>
> Currently, kunit_parser.py is stripping all leading whitespace to make
> parsing easier. But this means we can't accurately show kernel output
> for failing tests or when the kernel crashes.
>
> Embarassingly, this affects even KUnit's own output, e.g.
> [13:40:46] Expected 2 + 1 == 2, but
> [13:40:46] 2 + 1 == 3 (0x3)
> [13:40:46] not ok 1 example_simple_test
> [13:40:46] [FAILED] example_simple_test
>
> After this change, here's what the output in context would look like
> [13:40:46] =================== example (4 subtests) ===================
> [13:40:46] # example_simple_test: initializing
> [13:40:46] # example_simple_test: EXPECTATION FAILED at lib/kunit/kunit-example-test.c:29
> [13:40:46] Expected 2 + 1 == 2, but
> [13:40:46] 2 + 1 == 3 (0x3)
> [13:40:46] [FAILED] example_simple_test
> [13:40:46] [SKIPPED] example_skip_test
> [13:40:46] [SKIPPED] example_mark_skipped_test
> [13:40:46] [PASSED] example_all_expect_macros_test
> [13:40:46] # example: initializing suite
> [13:40:46] # example: pass:1 fail:1 skip:2 total:4
> [13:40:46] # Totals: pass:1 fail:1 skip:2 total:4
> [13:40:46] ===================== [FAILED] example =====================
>
> This example shows one minor cosmetic defect this approach has.
> The test counts lines prevent us from dedenting the suite-level output.
> But at the same time, any form of non-KUnit output would do the same
> unless it happened to be indented as well.
>
> Signed-off-by: Daniel Latypov <dlatypov@xxxxxxxxxx>
> ---

I agree that this is a good idea.

Personally, I think we could avoid some of the 'dedent' issues by
disabling the test statistics lines when run via kunit.py (if
raw_output is not enabled). That's probably better as a separate
patch, though, so this looks good to go.

Reviewed-by: David Gow <davidgow@xxxxxxxxxx>

Cheers,
-- David

> tools/testing/kunit/kunit.py | 2 +-
> tools/testing/kunit/kunit_parser.py | 27 +++++++++++++-------------
> tools/testing/kunit/kunit_tool_test.py | 2 ++
> 3 files changed, 16 insertions(+), 15 deletions(-)
>
> diff --git a/tools/testing/kunit/kunit.py b/tools/testing/kunit/kunit.py
> index e7b6549712d6..43fbe96318fe 100755
> --- a/tools/testing/kunit/kunit.py
> +++ b/tools/testing/kunit/kunit.py
> @@ -202,7 +202,7 @@ def parse_tests(request: KunitParseRequest, metadata: kunit_json.Metadata, input
> if request.raw_output == 'all':
> pass
> elif request.raw_output == 'kunit':
> - output = kunit_parser.extract_tap_lines(output, lstrip=False)
> + output = kunit_parser.extract_tap_lines(output)
> for line in output:
> print(line.rstrip())
> parse_time = time.time() - parse_start
> diff --git a/tools/testing/kunit/kunit_parser.py b/tools/testing/kunit/kunit_parser.py
> index 99b8f058db40..a225799f6b1b 100644
> --- a/tools/testing/kunit/kunit_parser.py
> +++ b/tools/testing/kunit/kunit_parser.py
> @@ -13,6 +13,7 @@ from __future__ import annotations
> from dataclasses import dataclass
> import re
> import sys
> +import textwrap
>
> from enum import Enum, auto
> from typing import Iterable, Iterator, List, Optional, Tuple
> @@ -208,12 +209,12 @@ class LineStream:
>
> # Parsing helper methods:
>
> -KTAP_START = re.compile(r'KTAP version ([0-9]+)$')
> -TAP_START = re.compile(r'TAP version ([0-9]+)$')
> -KTAP_END = re.compile('(List of all partitions:|'
> +KTAP_START = re.compile(r'\s*KTAP version ([0-9]+)$')
> +TAP_START = re.compile(r'\s*TAP version ([0-9]+)$')
> +KTAP_END = re.compile(r'\s*(List of all partitions:|'
> 'Kernel panic - not syncing: VFS:|reboot: System halted)')
>
> -def extract_tap_lines(kernel_output: Iterable[str], lstrip=True) -> LineStream:
> +def extract_tap_lines(kernel_output: Iterable[str]) -> LineStream:
> """Extracts KTAP lines from the kernel output."""
> def isolate_ktap_output(kernel_output: Iterable[str]) \
> -> Iterator[Tuple[int, str]]:
> @@ -239,11 +240,8 @@ def extract_tap_lines(kernel_output: Iterable[str], lstrip=True) -> LineStream:
> # stop extracting KTAP lines
> break
> elif started:
> - # remove the prefix and optionally any leading
> - # whitespace. Our parsing logic relies on this.
> + # remove the prefix, if any.
> line = line[prefix_len:]
> - if lstrip:
> - line = line.lstrip()
> yield line_num, line
> return LineStream(lines=isolate_ktap_output(kernel_output))
>
> @@ -298,7 +296,7 @@ def parse_ktap_header(lines: LineStream, test: Test) -> bool:
> lines.pop()
> return True
>
> -TEST_HEADER = re.compile(r'^# Subtest: (.*)$')
> +TEST_HEADER = re.compile(r'^\s*# Subtest: (.*)$')
>
> def parse_test_header(lines: LineStream, test: Test) -> bool:
> """
> @@ -322,7 +320,7 @@ def parse_test_header(lines: LineStream, test: Test) -> bool:
> lines.pop()
> return True
>
> -TEST_PLAN = re.compile(r'1\.\.([0-9]+)')
> +TEST_PLAN = re.compile(r'^\s*1\.\.([0-9]+)')
>
> def parse_test_plan(lines: LineStream, test: Test) -> bool:
> """
> @@ -350,9 +348,9 @@ def parse_test_plan(lines: LineStream, test: Test) -> bool:
> lines.pop()
> return True
>
> -TEST_RESULT = re.compile(r'^(ok|not ok) ([0-9]+) (- )?([^#]*)( # .*)?$')
> +TEST_RESULT = re.compile(r'^\s*(ok|not ok) ([0-9]+) (- )?([^#]*)( # .*)?$')
>
> -TEST_RESULT_SKIP = re.compile(r'^(ok|not ok) ([0-9]+) (- )?(.*) # SKIP(.*)$')
> +TEST_RESULT_SKIP = re.compile(r'^\s*(ok|not ok) ([0-9]+) (- )?(.*) # SKIP(.*)$')
>
> def peek_test_name_match(lines: LineStream, test: Test) -> bool:
> """
> @@ -511,8 +509,9 @@ def print_test_header(test: Test) -> None:
>
> def print_log(log: Iterable[str]) -> None:
> """Prints all strings in saved log for test in yellow."""
> - for m in log:
> - stdout.print_with_timestamp(stdout.yellow(m))
> + formatted = textwrap.dedent('\n'.join(log))
> + for line in formatted.splitlines():
> + stdout.print_with_timestamp(stdout.yellow(line))
>
> def format_test_result(test: Test) -> str:
> """
> diff --git a/tools/testing/kunit/kunit_tool_test.py b/tools/testing/kunit/kunit_tool_test.py
> index 1ef921ac4331..0c2190514103 100755
> --- a/tools/testing/kunit/kunit_tool_test.py
> +++ b/tools/testing/kunit/kunit_tool_test.py
> @@ -336,12 +336,14 @@ class KUnitParserTest(unittest.TestCase):
> KTAP version 1
> 1..1
> Test output.
> + Indented more.
> not ok 1 test1
> """
> result = kunit_parser.parse_run_tests(output.splitlines())
> self.assertEqual(kunit_parser.TestStatus.FAILURE, result.status)
>
> self.print_mock.assert_any_call(StrContains('Test output.'))
> + self.print_mock.assert_any_call(StrContains(' Indented more.'))
> self.noPrintCallContains('not ok 1 test1')
>
> def line_stream_from_strs(strs: Iterable[str]) -> kunit_parser.LineStream:
>
> base-commit: 0f08f3e2a0186dfb8e33cb46105228eb18448a0e
> --
> 2.38.1.584.g0f3c55d4c2-goog
>
> --
> You received this message because you are subscribed to the Google Groups "KUnit Development" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to kunit-dev+unsubscribe@xxxxxxxxxxxxxxxx.
> To view this discussion on the web visit https://groups.google.com/d/msgid/kunit-dev/20221130185419.2552673-1-dlatypov%40google.com.

Attachment: smime.p7s
Description: S/MIME Cryptographic Signature