On Wed, 12 Feb 2020, Frank Rowand wrote:
> On 2/7/20 10:58 AM, Alan Maguire wrote:
> > add debugfs support for displaying kunit test suite results; this is
> > especially useful for module-loaded tests to allow disentangling of
> > test result display from other dmesg events.
> >
> > As well as printk()ing messages, we append them to a per-test log.
> >
> > Signed-off-by: Alan Maguire <alan.maguire@xxxxxxxxxx>
> > ---
> > include/kunit/test.h | 52 ++++++++++++++++---
> > lib/kunit/Makefile | 3 +-
> > lib/kunit/debugfs.c | 105 ++++++++++++++++++++++++++++++++++++++
> > lib/kunit/debugfs.h | 16 ++++++
> > lib/kunit/kunit-test.c | 4 +-
> > lib/kunit/test.c | 136 ++++++++++++++++++++++++++++++++++++++-----------
> > 6 files changed, 274 insertions(+), 42 deletions(-)
> > create mode 100644 lib/kunit/debugfs.c
> > create mode 100644 lib/kunit/debugfs.h
> >
> > diff --git a/include/kunit/test.h b/include/kunit/test.h
> > index 2dfb550..6a73c4e 100644
> > --- a/include/kunit/test.h
> > +++ b/include/kunit/test.h
> > @@ -81,6 +81,9 @@ struct kunit_resource {
> >
> > struct kunit;
> >
> > +/* Size of "lastrun" log associated with test. */
> > +#define KUNIT_LOG_SIZE 512
> > +
> > /**
> > * struct kunit_case - represents an individual test case.
> > *
> > @@ -123,8 +126,14 @@ struct kunit_case {
> >
> > /* private: internal use only. */
> > bool success;
> > + char *log;
> > };
> >
> > +static inline char *kunit_status_to_string(bool status)
> > +{
> > + return status ? "ok" : "not ok";
> > +}
> > +
> > /**
> > * KUNIT_CASE - A helper for creating a &struct kunit_case
> > *
> > @@ -157,6 +166,10 @@ struct kunit_suite {
> > int (*init)(struct kunit *test);
> > void (*exit)(struct kunit *test);
> > struct kunit_case *test_cases;
> > +
> > + /* private - internal use only */
> > + struct dentry *debugfs;
> > + char *log;
> > };
> >
> > /**
> > @@ -175,6 +188,7 @@ struct kunit {
> >
> > /* private: internal use only. */
> > const char *name; /* Read only after initialization! */
> > + char *log; /* Points at case log after initialization */
> > struct kunit_try_catch try_catch;
> > /*
> > * success starts as true, and may only be set to false during a
> > @@ -193,10 +207,19 @@ struct kunit {
> > struct list_head resources; /* Protected by lock. */
> > };
> >
> > -void kunit_init_test(struct kunit *test, const char *name);
> > +void kunit_init_test(struct kunit *test, const char *name, char *log);
> >
> > int kunit_run_tests(struct kunit_suite *suite);
> >
> > +size_t kunit_suite_num_test_cases(struct kunit_suite *suite);
> > +
> > +unsigned int kunit_test_case_num(struct kunit_suite *suite,
> > + struct kunit_case *test_case);
> > +
> > +int __kunit_test_suites_init(struct kunit_suite **suites);
> > +
> > +void __kunit_test_suites_exit(struct kunit_suite **suites);
> > +
> > /**
> > * kunit_test_suites() - used to register one or more &struct kunit_suite
> > * with KUnit.
> > @@ -226,20 +249,24 @@ struct kunit {
> > static struct kunit_suite *suites[] = { __VA_ARGS__, NULL}; \
> > static int kunit_test_suites_init(void) \
> > { \
> > - unsigned int i; \
> > - for (i = 0; suites[i] != NULL; i++) \
> > - kunit_run_tests(suites[i]); \
> > - return 0; \
> > + return __kunit_test_suites_init(suites); \
> > } \
> > late_initcall(kunit_test_suites_init); \
> > static void __exit kunit_test_suites_exit(void) \
> > { \
> > - return; \
> > + return __kunit_test_suites_exit(suites); \
> > } \
> > module_exit(kunit_test_suites_exit)
> >
> > #define kunit_test_suite(suite) kunit_test_suites(&suite)
> >
> > +#define kunit_suite_for_each_test_case(suite, test_case) \
> > + for (test_case = suite->test_cases; \
> > + test_case && test_case->run_case; \
>
> test_case does not become NULL for the final entry in suite->test_cases
> so do not test for such.
>
thanks for spotting this; I've fixed in v4.
>
> > + test_case++)
> > +
> > +bool kunit_suite_has_succeeded(struct kunit_suite *suite);
> > +
> > /*
> > * Like kunit_alloc_resource() below, but returns the struct kunit_resource
> > * object that contains the allocation. This is mostly for testing purposes.
> > @@ -356,8 +383,17 @@ static inline void *kunit_kzalloc(struct kunit *test, size_t size, gfp_t gfp)
> >
> > void kunit_cleanup(struct kunit *test);
> >
> > -#define kunit_printk(lvl, test, fmt, ...) \
> > - printk(lvl "\t# %s: " fmt, (test)->name, ##__VA_ARGS__)
> > +/* printk and log to per-test or per-suite log buffer */
> > +#define kunit_log(lvl, test, fmt, ...) \
>
> 'test' can be either a test or a suite, so this name is misleading. I suggest
> changing it to test_or_suite.
>
good point; fixed also.
>
> > + do { \
> > + printk(lvl fmt, ##__VA_ARGS__); \
> > + snprintf((test)->log, KUNIT_LOG_SIZE, \
> > + "%s" fmt "\n", \
> > + (test)->log, ##__VA_ARGS__); \
> > + } while (0)
> > +
>
> If kunit_log() is called multiple times in a test run for a single test case,
> does each call overwrite the previous value of (test)->log? For example,
> kunit_print_subtest_start() calls kunit_log() twice.
>
Yep, this works. However it's better to have a test that
confirms that, so I've added such a test in patch 2.
>
> > +#define kunit_printk(lvl, test, fmt, ...) \
> > + kunit_log(lvl, test, "\t# %s: " fmt, (test)->name, ##__VA_ARGS__)
> >
> > /**
> > * kunit_info() - Prints an INFO level message associated with @test.
> > diff --git a/lib/kunit/Makefile b/lib/kunit/Makefile
> > index fab5564..869aab0 100644
> > --- a/lib/kunit/Makefile
> > +++ b/lib/kunit/Makefile
> > @@ -3,7 +3,8 @@ obj-$(CONFIG_KUNIT) += kunit.o
> > kunit-objs += test.o \
> > string-stream.o \
> > assert.o \
> > - try-catch.o
> > + try-catch.o \
> > + debugfs.o
> >
> > obj-$(CONFIG_KUNIT_TEST) += kunit-test.o
> >
>
> Please make debugfs.o configurable distinctly from KUNIT. Or it
> might be possible to make KUNIT_LOG_SIZE zero (and make sure the
> code handles a NULL log) if that is easier to implement.
>
> The data size of the log buffers could otherwise be excessively
> large for a tiny resource constrained embedded platform. For
> example, with the proposed KUNIT_LOG_SIZE of 512, if there were
> 200 test cases enabled, the log space would be 100k bytes. If
> 2000 test cases were enabled, the log space would be 1000k bytes.
>
> I can easily imagine a user configuring an acceptance test with
> tens of thousands of test cases.
>
I've added a boolean CONFIG_KUNIT_DEBUGFS; when set to 'n'
no logs are allocated or used. There seemed to be precendents
with other CONFIG_*_DEBUGFS variables.
>
> > diff --git a/lib/kunit/debugfs.c b/lib/kunit/debugfs.c
> > new file mode 100644
> > index 0000000..b856d6b
> > --- /dev/null
> > +++ b/lib/kunit/debugfs.c
> > @@ -0,0 +1,105 @@
> > +// SPDX-License-Identifier: GPL-2.0
> > +/*
> > + * Copyright (c) 2020, Oracle and/or its affiliates.
> > + * Author: Alan Maguire <alan.maguire@xxxxxxxxxx>
> > + */
> > +
> > +#include <linux/debugfs.h>
> > +#include <linux/module.h>
> > +
> > +#include <kunit/test.h>
> > +
> > +#include "string-stream.h"
> > +
> > +#define KUNIT_DEBUGFS_ROOT "kunit"
> > +#define KUNIT_DEBUGFS_RESULTS "results"
> > +
> > +/*
> > + * Create a debugfs representation of test suites:
> > + *
> > + * Path Semantics
> > + * /sys/kernel/debug/kunit/<testsuite>/results Show results of last run for
> > + * testsuite
> > + *
> > + */
> > +
> > +static struct dentry *debugfs_rootdir;
> > +
> > +void kunit_debugfs_cleanup(void)
> > +{
> > + debugfs_remove_recursive(debugfs_rootdir);
> > +}
> > +
> > +void kunit_debugfs_init(void)
> > +{
> > + if (!debugfs_rootdir)
> > + debugfs_rootdir = debugfs_create_dir(KUNIT_DEBUGFS_ROOT, NULL);
> > +}
> > +
> > +static void debugfs_print_result(struct seq_file *seq,
> > + struct kunit_suite *suite,
> > + struct kunit_case *test_case)
> > +{
> > + if (!test_case)
> > + return;
> > +
> > + seq_printf(seq, "%s", test_case->log);
> > +}
> > +
> > +/*
> > + * /sys/kernel/debug/kunit/<testsuite>/results shows all results for testsuite.
> > + */
> > +static int debugfs_print_results(struct seq_file *seq, void *v)
> > +{
> > + struct kunit_suite *suite = (struct kunit_suite *)seq->private;
> > + bool success = kunit_suite_has_succeeded(suite);
> > + struct kunit_case *test_case;
> > +
> > + if (!suite)
> > + return 0;
> > +
> > + seq_printf(seq, "%s", suite->log);
> > +
> > + 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_string(success), 1, suite->name);
> > + return 0;
> > +}
> > +
> > +static int debugfs_release(struct inode *inode, struct file *file)
> > +{
> > + return single_release(inode, file);
> > +}
> > +
> > +static int debugfs_results_open(struct inode *inode, struct file *file)
> > +{
> > + struct kunit_suite *suite;
> > +
> > + suite = (struct kunit_suite *)inode->i_private;
> > +
> > + return single_open(file, debugfs_print_results, suite);
> > +}
> > +
> > +static const struct file_operations debugfs_results_fops = {
> > + .open = debugfs_results_open,
> > + .read = seq_read,
> > + .llseek = seq_lseek,
> > + .release = debugfs_release,
> > +};
> > +
> > +void kunit_debugfs_create_suite(struct kunit_suite *suite)
> > +{
> > + /* First add /sys/kernel/debug/kunit/<testsuite> */
> > + suite->debugfs = debugfs_create_dir(suite->name, debugfs_rootdir);
> > +
> > + debugfs_create_file(KUNIT_DEBUGFS_RESULTS, S_IFREG | 0444,
> > + suite->debugfs,
> > + suite, &debugfs_results_fops);
> > +}
> > +
> > +void kunit_debugfs_destroy_suite(struct kunit_suite *suite)
> > +{
> > + debugfs_remove_recursive(suite->debugfs);
> > +}
> > diff --git a/lib/kunit/debugfs.h b/lib/kunit/debugfs.h
> > new file mode 100644
> > index 0000000..9a92d5e
> > --- /dev/null
> > +++ b/lib/kunit/debugfs.h
> > @@ -0,0 +1,16 @@
> > +/* SPDX-License-Identifier: GPL-2.0 */
> > +/*
> > + * Copyright (C) 2020, Oracle and/or its affiliates.
> > + */
> > +
> > +#ifndef _KUNIT_DEBUGFS_H
> > +#define _KUNIT_DEBUGFS_H
> > +
> > +#include <kunit/test.h>
> > +
> > +void kunit_debugfs_create_suite(struct kunit_suite *suite);
> > +void kunit_debugfs_destroy_suite(struct kunit_suite *suite);
> > +void kunit_debugfs_init(void);
> > +void kunit_debugfs_cleanup(void);
> > +
> > +#endif /* _KUNIT_DEBUGFS_H */
> > diff --git a/lib/kunit/kunit-test.c b/lib/kunit/kunit-test.c
> > index ccb8d2e..aceb5bf 100644
> > --- a/lib/kunit/kunit-test.c
> > +++ b/lib/kunit/kunit-test.c
> > @@ -134,7 +134,7 @@ static void kunit_resource_test_init_resources(struct kunit *test)
> > {
> > struct kunit_test_resource_context *ctx = test->priv;
> >
> > - kunit_init_test(&ctx->test, "testing_test_init_test");
> > + kunit_init_test(&ctx->test, "testing_test_init_test", NULL);
> >
> > KUNIT_EXPECT_TRUE(test, list_empty(&ctx->test.resources));
> > }
> > @@ -301,7 +301,7 @@ static int kunit_resource_test_init(struct kunit *test)
> >
> > test->priv = ctx;
> >
> > - kunit_init_test(&ctx->test, "test_test_context");
> > + kunit_init_test(&ctx->test, "test_test_context", NULL);
> >
> > return 0;
> > }
> > diff --git a/lib/kunit/test.c b/lib/kunit/test.c
> > index 9242f93..aec607f 100644
> > --- a/lib/kunit/test.c
> > +++ b/lib/kunit/test.c
> > @@ -10,6 +10,7 @@
> > #include <linux/kernel.h>
> > #include <linux/sched/debug.h>
> >
> > +#include "debugfs.h"
> > #include "string-stream.h"
> > #include "try-catch-impl.h"
> >
> > @@ -28,73 +29,91 @@ static void kunit_print_tap_version(void)
> > }
> > }
> >
> > -static size_t kunit_test_cases_len(struct kunit_case *test_cases)
> > +size_t kunit_suite_num_test_cases(struct kunit_suite *suite)
> > {
> > struct kunit_case *test_case;
> > size_t len = 0;
> >
> > - for (test_case = test_cases; test_case->run_case; test_case++)
> > + kunit_suite_for_each_test_case(suite, test_case)
> > len++;
> >
> > return len;
> > }
> > +EXPORT_SYMBOL_GPL(kunit_suite_num_test_cases);
> >
> > static void kunit_print_subtest_start(struct kunit_suite *suite)
> > {
> > kunit_print_tap_version();
> > - pr_info("\t# Subtest: %s\n", suite->name);
> > - pr_info("\t1..%zd\n", kunit_test_cases_len(suite->test_cases));
> > + kunit_log(KERN_INFO, suite, "# Subtest: %s", suite->name);
> > + kunit_log(KERN_INFO, suite, "1..%zd",
> > + kunit_suite_num_test_cases(suite));
>
> The subtest 'is a TAP stream indented 4 spaces'. (So the old code was
> also incorrect since it indented with a tab.)
>
> kunit_print_ok_not_ok() has a similar indentation issue.
>
I'll defer to Brendan on the TAP format stuff if you don't
mind; the aim here is to preserve existing behaviour. I
think it might be better to tackle TAP format issues in
a separate patchset.
I also updated the documentation patch in v4 (patch 3)
to incorporate the suggested wording.
Thanks for the careful review!
Alan
>
> > }
> >
> > -static void kunit_print_ok_not_ok(bool should_indent,
> > +static void kunit_print_ok_not_ok(void *test_or_suite,
> > + bool is_test,
> > bool is_ok,
> > size_t test_number,
> > const char *description)
> > {
> > - const char *indent, *ok_not_ok;
> > + struct kunit_suite *suite = is_test ? NULL : test_or_suite;
> > + struct kunit *test = is_test ? test_or_suite : NULL;
> >
> > - if (should_indent)
> > - indent = "\t";
> > - else
> > - indent = "";
> > -
> > - if (is_ok)
> > - ok_not_ok = "ok";
> > + /*
> > + * 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",
> > + kunit_status_to_string(is_ok),
> > + test_number, description);
> > else
> > - ok_not_ok = "not ok";
> > -
> > - pr_info("%s%s %zd - %s\n", indent, ok_not_ok, test_number, description);
> > + kunit_log(KERN_INFO, test, "\t%s %zd - %s",
> > + kunit_status_to_string(is_ok),
> > + test_number, description);
> > }
> >
> > -static bool kunit_suite_has_succeeded(struct kunit_suite *suite)
> > +bool kunit_suite_has_succeeded(struct kunit_suite *suite)
> > {
> > const struct kunit_case *test_case;
> >
> > - for (test_case = suite->test_cases; test_case->run_case; test_case++)
> > + kunit_suite_for_each_test_case(suite, test_case) {
> > if (!test_case->success)
> > return false;
> > + }
> >
> > return true;
> > }
> > +EXPORT_SYMBOL_GPL(kunit_suite_has_succeeded);
> >
> > static void kunit_print_subtest_end(struct kunit_suite *suite)
> > {
> > static size_t kunit_suite_counter = 1;
> >
> > - kunit_print_ok_not_ok(false,
> > + kunit_print_ok_not_ok((void *)suite, false,
> > kunit_suite_has_succeeded(suite),
> > kunit_suite_counter++,
> > suite->name);
> > }
> >
> > -static void kunit_print_test_case_ok_not_ok(struct kunit_case *test_case,
> > - size_t test_number)
> > +unsigned int kunit_test_case_num(struct kunit_suite *suite,
> > + struct kunit_case *test_case)
> > {
> > - kunit_print_ok_not_ok(true,
> > - test_case->success,
> > - test_number,
> > - test_case->name);
> > + struct kunit_case *tc;
> > + unsigned int i = 1;
> > +
> > + kunit_suite_for_each_test_case(suite, tc) {
> > + if (tc == test_case)
> > + return i;
> > + i++;
> > + }
> > +
> > + return 0;
> > }
> > +EXPORT_SYMBOL_GPL(kunit_test_case_num);
> >
> > static void kunit_print_string_stream(struct kunit *test,
> > struct string_stream *stream)
> > @@ -102,6 +121,9 @@ static void kunit_print_string_stream(struct kunit *test,
> > struct string_stream_fragment *fragment;
> > char *buf;
> >
> > + if (string_stream_is_empty(stream))
> > + return;
> > +
> > buf = string_stream_get_string(stream);
> > if (!buf) {
> > kunit_err(test,
> > @@ -175,11 +197,14 @@ void kunit_do_assertion(struct kunit *test,
> > }
> > EXPORT_SYMBOL_GPL(kunit_do_assertion);
> >
> > -void kunit_init_test(struct kunit *test, const char *name)
> > +void kunit_init_test(struct kunit *test, const char *name, char *log)
> > {
> > spin_lock_init(&test->lock);
> > INIT_LIST_HEAD(&test->resources);
> > test->name = name;
> > + test->log = log;
> > + if (test->log)
> > + test->log[0] = '\0';
> > test->success = true;
> > }
> > EXPORT_SYMBOL_GPL(kunit_init_test);
> > @@ -290,7 +315,7 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite,
> > struct kunit_try_catch *try_catch;
> > struct kunit test;
> >
> > - kunit_init_test(&test, test_case->name);
> > + kunit_init_test(&test, test_case->name, test_case->log);
> > try_catch = &test.try_catch;
> >
> > kunit_try_catch_init(try_catch,
> > @@ -303,19 +328,20 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite,
> > kunit_try_catch_run(try_catch, &context);
> >
> > test_case->success = test.success;
> > +
> > + kunit_print_ok_not_ok(&test, true, test_case->success,
> > + kunit_test_case_num(suite, test_case),
> > + test_case->name);
> > }
> >
> > int kunit_run_tests(struct kunit_suite *suite)
> > {
> > struct kunit_case *test_case;
> > - size_t test_case_count = 1;
> >
> > kunit_print_subtest_start(suite);
> >
> > - for (test_case = suite->test_cases; test_case->run_case; test_case++) {
> > + kunit_suite_for_each_test_case(suite, test_case)
> > kunit_run_case_catch_errors(suite, test_case);
> > - kunit_print_test_case_ok_not_ok(test_case, test_case_count++);
> > - }
> >
> > kunit_print_subtest_end(suite);
> >
> > @@ -323,6 +349,51 @@ int kunit_run_tests(struct kunit_suite *suite)
> > }
> > EXPORT_SYMBOL_GPL(kunit_run_tests);
> >
> > +static void kunit_init_suite(struct kunit_suite *suite)
> > +{
> > + struct kunit_case *test_case;
> > +
> > + /* Allocate logs before creating debugfs representation. */
> > + suite->log = kzalloc(KUNIT_LOG_SIZE, GFP_KERNEL);
> > + kunit_suite_for_each_test_case(suite, test_case)
> > + test_case->log = kzalloc(KUNIT_LOG_SIZE, GFP_KERNEL);
> > +
> > + kunit_debugfs_create_suite(suite);
> > +}
> > +
> > +int __kunit_test_suites_init(struct kunit_suite **suites)
> > +{
> > + unsigned int i;
> > +
> > + for (i = 0; suites[i] != NULL; i++) {
> > + kunit_init_suite(suites[i]);
> > + kunit_run_tests(suites[i]);
> > + }
> > + return 0;
> > +}
> > +EXPORT_SYMBOL_GPL(__kunit_test_suites_init);
> > +
> > +static void kunit_exit_suite(struct kunit_suite *suite)
> > +{
> > + struct kunit_case *test_case;
> > +
> > + /* Destroy debugfs representation before freeing logs used by it. */
> > + kunit_debugfs_destroy_suite(suite);
> > +
> > + kfree(suite->log);
> > + kunit_suite_for_each_test_case(suite, test_case)
> > + kfree(test_case->log);
> > +}
> > +
> > +void __kunit_test_suites_exit(struct kunit_suite **suites)
> > +{
> > + unsigned int i;
> > +
> > + for (i = 0; suites[i] != NULL; i++)
> > + kunit_exit_suite(suites[i]);
> > +}
> > +EXPORT_SYMBOL_GPL(__kunit_test_suites_exit);
> > +
> > struct kunit_resource *kunit_alloc_and_get_resource(struct kunit *test,
> > kunit_resource_init_t init,
> > kunit_resource_free_t free,
> > @@ -489,12 +560,15 @@ void kunit_cleanup(struct kunit *test)
> >
> > static int __init kunit_init(void)
> > {
> > + kunit_debugfs_init();
> > +
> > return 0;
> > }
> > late_initcall(kunit_init);
> >
> > static void __exit kunit_exit(void)
> > {
> > + kunit_debugfs_cleanup();
> > }
> > module_exit(kunit_exit);
> >
> >
>
>
