On Thu, Feb 9, 2023 at 12:06 AM David Gow <davidgow@xxxxxxxxxx> wrote:
>
> On Wed, 1 Feb 2023 at 06:04, Rae Moar <rmoar@xxxxxxxxxx> wrote:
> >
> > Fix bug in debugfs logs that causes an incorrect order of lines in the
> > debugfs log.
> >
> > Currently, any suite diagnostic lines, including the test counts lines
> > that show the number of tests passed, failed, and skipped,
> > appear prior to the individual results, which is a bug.
> >
> > Ensure the order of printing for the debugfs log is correct.
> >
> > Signed-off-by: Rae Moar <rmoar@xxxxxxxxxx>
> > ---
>
> I think this is overall an improvement, but there are a few remaining
> issues (some new, some old).
Hi David!
Thanks for your comments.
>
> First, as with the previous patches, could we have a before/after
> comparison in the commit description?
Yes, this sounds like a great idea. I originally thought the before
and after comparison in the cover letter would be sufficient but an
individual comparison for each patch is clearer. I will add this in
v2.
>
> Secondly, I think it'd be nice to either add an extra KTAP header to
> the start, so that each debugfs results file is a valid KTAP document
> by itself, or at least document that you'll need to prepend one for
> this to work.
> I'm personally leaning towards the latter, even if it loses us the
> ability to just concatenate result files together, because of the
> third issue below.
>
> Finally, with this patch, the final result line's suite number is
> recorded from its initial run, rather than always being '1'. This
> means that if multiple suites are run (e.g. list-test.ko), then the
> result file could contain a single suite, with "ok 2 ..." or similar
> as a result line. This might help a bit if we were concatenating
> result files, but otherwise leaves us with a parse error due to the
> mismatched number.
>
> Personally, I'd prefer we change those to always use suite number 1,
> and to add the KTAP header to the start. Adding the header should be
> easy, the suite number perhaps less so...
My intention was to match the logs with the exact KTAP output of the
test to be consistent. But I see the value in ensuring the logs are
easily parsable. In v2, I will add the KTAP header and change the test
number to be 1 to allow the logs to be parsed without error.
-Rae
>
> Cheers,
> -- David
>
> > lib/kunit/debugfs.c | 13 ++++++++-----
> > lib/kunit/test.c | 24 ++++++++++++------------
> > 2 files changed, 20 insertions(+), 17 deletions(-)
> >
> > diff --git a/lib/kunit/debugfs.c b/lib/kunit/debugfs.c
> > index de0ee2e03ed6..fbc645590701 100644
> > --- a/lib/kunit/debugfs.c
> > +++ b/lib/kunit/debugfs.c
> > @@ -52,19 +52,22 @@ static void debugfs_print_result(struct seq_file *seq,
> > static int debugfs_print_results(struct seq_file *seq, void *v)
> > {
> > struct kunit_suite *suite = (struct kunit_suite *)seq->private;
> > - enum kunit_status success = kunit_suite_has_succeeded(suite);
> > struct kunit_case *test_case;
> >
> > - if (!suite || !suite->log)
> > + if (!suite)
> > return 0;
> >
> > - seq_printf(seq, "%s", suite->log);
> > + /* Print suite header because it is not stored in the test logs. */
> > + seq_puts(seq, KUNIT_SUBTEST_INDENT "KTAP version 1\n");
>
> We probably want to print this twice, once without the indent, to
> start the whole document, once with it.
>
> > + seq_printf(seq, KUNIT_SUBTEST_INDENT "# Subtest: %s\n", suite->name);
> > + seq_printf(seq, KUNIT_SUBTEST_INDENT "1..%zd\n", kunit_suite_num_test_cases(suite));
> >
> > kunit_suite_for_each_test_case(suite, test_case)
> > debugfs_print_result(seq, suite, test_case);
> >
> > - seq_printf(seq, "%s %d %s\n",
> > - kunit_status_to_ok_not_ok(success), 1, suite->name);
>
> We probably still want to output the suite number as '1'...
>
> > + if (suite->log)
> > + seq_printf(seq, "%s", suite->log);
> > +
> > return 0;
> > }
> >
> > diff --git a/lib/kunit/test.c b/lib/kunit/test.c
> > index 66ba93b8222c..27763f0b420c 100644
> > --- a/lib/kunit/test.c
> > +++ b/lib/kunit/test.c
> > @@ -147,10 +147,18 @@ EXPORT_SYMBOL_GPL(kunit_suite_num_test_cases);
> >
> > static void kunit_print_suite_start(struct kunit_suite *suite)
> > {
> > - kunit_log(KERN_INFO, suite, KUNIT_SUBTEST_INDENT "KTAP version 1\n");
> > - kunit_log(KERN_INFO, suite, KUNIT_SUBTEST_INDENT "# Subtest: %s",
> > + /*
> > + * We do not log the test suite header as doing so would
> > + * mean debugfs display would consist of the test suite
> > + * header prior to individual test results.
> > + * Hence directly printk the suite status, and we will
> > + * separately seq_printf() the suite header for the debugfs
> > + * representation.
> > + */
> > + pr_info(KUNIT_SUBTEST_INDENT "KTAP version 1\n");
> > + pr_info(KUNIT_SUBTEST_INDENT "# Subtest: %s",
> > suite->name);
> > - kunit_log(KERN_INFO, suite, KUNIT_SUBTEST_INDENT "1..%zd",
> > + pr_info(KUNIT_SUBTEST_INDENT "1..%zd",
> > kunit_suite_num_test_cases(suite));
> > }
> >
> > @@ -165,16 +173,8 @@ static void kunit_print_ok_not_ok(void *test_or_suite,
> > struct kunit *test = is_test ? test_or_suite : NULL;
> > const char *directive_header = (status == KUNIT_SKIPPED) ? " # SKIP " : "";
> >
> > - /*
> > - * We do not log the test suite results as doing so would
> > - * mean debugfs display would consist of the test suite
> > - * description and status prior to individual test results.
> > - * Hence directly printk the suite status, and we will
> > - * separately seq_printf() the suite status for the debugfs
> > - * representation.
> > - */
> > if (suite)
> > - pr_info("%s %zd %s%s%s\n",
> > + kunit_log(KERN_INFO, suite, "%s %zd %s%s%s\n",
>
> Changing this breaks the code to ensure the suite number is always '1'...
>
>
> > kunit_status_to_ok_not_ok(status),
> > test_number, description, directive_header,
> > (status == KUNIT_SKIPPED) ? directive : "");
> > --
> > 2.39.1.456.gfc5497dd1b-goog
> >
