On Tue, Nov 29, 2022 at 12:09 PM Daniel Latypov dlatypov@google.com wrote:
On Tue, Nov 29, 2022 at 12:31 AM David Gow davidgow@google.com wrote:
On Tue, Nov 29, 2022 at 8:12 AM Daniel Latypov dlatypov@google.com wrote:
We print the "test log" on failure. This is meant to be all the kernel output that happened during the test.
But we also include the special KTAP lines in it, which are often redundant.
E.g. we include the "not ok" line in the log, right before we print that the test case failed... [13:51:48] Expected 2 + 1 == 2, but [13:51:48] 2 + 1 == 3 (0x3) [13:51:48] not ok 1 example_simple_test [13:51:48] [FAILED] example_simple_test
More full example after this patch: [13:51:48] =================== example (4 subtests) =================== [13:51:48] # example_simple_test: initializing [13:51:48] # example_simple_test: EXPECTATION FAILED at lib/kunit/kunit-example-test.c:29 [13:51:48] Expected 2 + 1 == 2, but [13:51:48] 2 + 1 == 3 (0x3) [13:51:48] [FAILED] example_simple_test
Signed-off-by: Daniel Latypov dlatypov@google.com
I totally agree we should skip these from the log. (Unless --raw_output is enabled, but that obviously doesn't apply.)
Going forward, I think we should also probably disable kunit.stats_enabled when running via kunit.py, too (again, unless --raw_output is used.)
I considered including that as a patch 2/2 here. But changing the behavior like that felt a bit iffy.
We've basically been telling people that looking at .kunit/test.log is logically equivalent to running with kunit.py run --raw_output. That would no longer be true after such a change. So I'm torn between that and automatically filtering them out in the parser side.
Cons of tweaking args based on --raw_output
- now more magic, harder to explain (see above)
- people might find test counts useful when looking at test.log
Cons of filtering out test counts in the parser
- risks false positives: filtering out other lines besides test counts
- when there's missing output, this is less debuggable
- 99% of users are *not* going to dig into the python code
- but IMO users are fairly likely to notice the extra
kunit.stats_enabled=0 cmdline arg
And overall, the benefit of hiding these is very small and cosmetic in nature. So that means making a tradeoff to do so feels more iffy.
The hiding done in this patch seemed fine since there was no tradeoff, we just needed to stop including lines we've already recognized as KTAP directives.
I tested and reviewed the changes and this all looks good to me. Nice to no longer print the KTAP version line or test result lines in the test logs.
To comment on the above discussion: of the options discussed, I would prefer to either tweak the stats_enabled arg based on the raw_output flag or simply leave the output as is. I personally think that filtering out the test counts using the parser would be messy and does not match the precedent set by this patch to not include only recognized KTAP directives in the test log (with the exception of the "# Subtest" line, which I am planning to propose for KTAP v2).
I agree with the cons to tweaking the arg based on the raw_output flag Daniel mentioned above. Additionally, I think including the test counts line in the log could actually be quite useful in the instance of combining module results. Since the parser does not include a test summary line with counts for failed subtests, this would save the time counting up the number of failed/skipped/passed subtests for a specific module. This would, in general, also apply to failing tests with a large number of subtests within them.
That being said I would be ok with tweaking the stats_enabled arg based on the raw_output flag as well. It does look cleaner without the counts printed in the log, especially when there are only a few number of tests or the test summary line of the parser repeats the same information as the test counts line.
Reviewed-by: Rae Moar rmoar@google.com
Thanks! Rae
In any case, this looks good and works well here.
Reviewed-by: David Gow davidgow@google.com
Cheers, -- David