Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
MIME-Version: 1.0
References: <20221129001234.606653-1-dlatypov@google.com> <CABVgOS=6nx2SGRVjN1Ek1htsXehcnU1fnp6FMc0ATdOJfRd0iQ@mail.gmail.com>
In-Reply-To: <CABVgOS=6nx2SGRVjN1Ek1htsXehcnU1fnp6FMc0ATdOJfRd0iQ@mail.gmail.com>
From:   Daniel Latypov <dlatypov@google.com>
Date:   Tue, 29 Nov 2022 09:09:29 -0800
Message-ID: <CAGS_qxqu+opwMusOGSS3s9fLo2GfpgsCQOgq6VZyBcVb+zS6Zg@mail.gmail.com>
Subject: Re: [PATCH] kunit: tool: don't include KTAP headers and the like in
 the test log
To:     David Gow <davidgow@google.com>
Cc:     brendanhiggins@google.com, rmoar@google.com,
        linux-kernel@vger.kernel.org, kunit-dev@googlegroups.com,
        linux-kselftest@vger.kernel.org, skhan@linuxfoundation.org
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

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.

>
> In any case, this looks good and works well here.
>
> Reviewed-by: David Gow <davidgow@google.com>
>
> Cheers,
> -- David