Message ID | 20201211072319.533803-1-davidgow@google.com |
---|---|
State | New |
Headers | show |
Series | kunit: Print test statistics on failure | expand |
Hi David, I love your patch! Yet something to improve: [auto build test ERROR on 5f6b99d0287de2c2d0b5e7abcb0092d553ad804a] url: https://github.com/0day-ci/linux/commits/David-Gow/kunit-Print-test-statistics-on-failure/20201211-153009 base: 5f6b99d0287de2c2d0b5e7abcb0092d553ad804a config: c6x-randconfig-r004-20201210 (attached as .config) compiler: c6x-elf-gcc (GCC) 9.3.0 reproduce (this is a W=1 build): wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross chmod +x ~/bin/make.cross # https://github.com/0day-ci/linux/commit/2bdf1b55a1b3673a1a02f71457fc52b497fc7223 git remote add linux-review https://github.com/0day-ci/linux git fetch --no-tags linux-review David-Gow/kunit-Print-test-statistics-on-failure/20201211-153009 git checkout 2bdf1b55a1b3673a1a02f71457fc52b497fc7223 # save the attached .config to linux build tree COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-9.3.0 make.cross ARCH=c6x If you fix the issue, kindly add following tag as appropriate Reported-by: kernel test robot <lkp@intel.com> All errors (new ones prefixed by >>): >> lib/kunit/test.c:27:53: error: expected ')' before 'int' 27 | core_param(kunit_stats_enabled, kunit_stats_enabled, int, 0644); | ^~~~ | ) In file included from lib/kunit/test.c:9: lib/kunit/test.c: In function 'kunit_print_test_stats': include/linux/kern_levels.h:5:18: warning: format '%lu' expects argument of type 'long unsigned int', but argument 3 has type 'size_t' {aka 'unsigned int'} [-Wformat=] 5 | #define KERN_SOH "\001" /* ASCII Start Of Header */ | ^~~~~~ include/kunit/test.h:621:10: note: in definition of macro 'kunit_log' 621 | printk(lvl fmt, ##__VA_ARGS__); \ | ^~~ include/linux/kern_levels.h:14:19: note: in expansion of macro 'KERN_SOH' 14 | #define KERN_INFO KERN_SOH "6" /* informational */ | ^~~~~~~~ lib/kunit/test.c:46:12: note: in expansion of macro 'KERN_INFO' 46 | kunit_log(KERN_INFO, test, | ^~~~~~~~~ lib/kunit/test.c:48:14: note: format string is defined here 48 | "# %s: %lu / %lu test parameters failed", | ~~^ | | | long unsigned int | %u In file included from lib/kunit/test.c:9: include/linux/kern_levels.h:5:18: warning: format '%lu' expects argument of type 'long unsigned int', but argument 4 has type 'size_t' {aka 'unsigned int'} [-Wformat=] 5 | #define KERN_SOH "\001" /* ASCII Start Of Header */ | ^~~~~~ include/kunit/test.h:621:10: note: in definition of macro 'kunit_log' 621 | printk(lvl fmt, ##__VA_ARGS__); \ | ^~~ include/linux/kern_levels.h:14:19: note: in expansion of macro 'KERN_SOH' 14 | #define KERN_INFO KERN_SOH "6" /* informational */ | ^~~~~~~~ lib/kunit/test.c:46:12: note: in expansion of macro 'KERN_INFO' 46 | kunit_log(KERN_INFO, test, | ^~~~~~~~~ lib/kunit/test.c:48:20: note: format string is defined here 48 | "# %s: %lu / %lu test parameters failed", | ~~^ | | | long unsigned int | %u lib/kunit/test.c: In function 'kunit_log_append': lib/kunit/test.c:72:2: warning: function 'kunit_log_append' might be a candidate for 'gnu_printf' format attribute [-Wsuggest-attribute=format] 72 | vsnprintf(line, sizeof(line), fmt, args); | ^~~~~~~~~ In file included from lib/kunit/test.c:9: lib/kunit/test.c: In function 'kunit_print_suite_stats': include/linux/kern_levels.h:5:18: warning: format '%lu' expects argument of type 'long unsigned int', but argument 3 has type 'size_t' {aka 'unsigned int'} [-Wformat=] 5 | #define KERN_SOH "\001" /* ASCII Start Of Header */ | ^~~~~~ include/kunit/test.h:621:10: note: in definition of macro 'kunit_log' 621 | printk(lvl fmt, ##__VA_ARGS__); \ | ^~~ include/linux/kern_levels.h:14:19: note: in expansion of macro 'KERN_SOH' 14 | #define KERN_INFO KERN_SOH "6" /* informational */ | ^~~~~~~~ lib/kunit/test.c:394:12: note: in expansion of macro 'KERN_INFO' 394 | kunit_log(KERN_INFO, suite, | ^~~~~~~~~ lib/kunit/test.c:395:15: note: format string is defined here 395 | "# %s: (%lu / %lu) tests failed (%lu / %lu test parameters)", | ~~^ | | | long unsigned int | %u In file included from lib/kunit/test.c:9: include/linux/kern_levels.h:5:18: warning: format '%lu' expects argument of type 'long unsigned int', but argument 4 has type 'size_t' {aka 'unsigned int'} [-Wformat=] 5 | #define KERN_SOH "\001" /* ASCII Start Of Header */ | ^~~~~~ include/kunit/test.h:621:10: note: in definition of macro 'kunit_log' 621 | printk(lvl fmt, ##__VA_ARGS__); \ | ^~~ include/linux/kern_levels.h:14:19: note: in expansion of macro 'KERN_SOH' 14 | #define KERN_INFO KERN_SOH "6" /* informational */ | ^~~~~~~~ lib/kunit/test.c:394:12: note: in expansion of macro 'KERN_INFO' 394 | kunit_log(KERN_INFO, suite, | ^~~~~~~~~ lib/kunit/test.c:395:21: note: format string is defined here 395 | "# %s: (%lu / %lu) tests failed (%lu / %lu test parameters)", | ~~^ | | | long unsigned int | %u In file included from lib/kunit/test.c:9: include/linux/kern_levels.h:5:18: warning: format '%lu' expects argument of type 'long unsigned int', but argument 5 has type 'size_t' {aka 'unsigned int'} [-Wformat=] 5 | #define KERN_SOH "\001" /* ASCII Start Of Header */ | ^~~~~~ include/kunit/test.h:621:10: note: in definition of macro 'kunit_log' 621 | printk(lvl fmt, ##__VA_ARGS__); \ | ^~~ include/linux/kern_levels.h:14:19: note: in expansion of macro 'KERN_SOH' 14 | #define KERN_INFO KERN_SOH "6" /* informational */ | ^~~~~~~~ lib/kunit/test.c:394:12: note: in expansion of macro 'KERN_INFO' 394 | kunit_log(KERN_INFO, suite, | ^~~~~~~~~ lib/kunit/test.c:395:40: note: format string is defined here 395 | "# %s: (%lu / %lu) tests failed (%lu / %lu test parameters)", vim +27 lib/kunit/test.c 19 20 /* 21 * KUnit statistic mode: 22 * 0 - disabled 23 * 1 - only when there is at least one failure, and more than one subtest 24 * 2 - enabled 25 */ 26 static int kunit_stats_enabled = 1; > 27 core_param(kunit_stats_enabled, kunit_stats_enabled, int, 0644); 28 --- 0-DAY CI Kernel Test Service, Intel Corporation https://lists.01.org/hyperkitty/list/kbuild-all@lists.01.org
On Thu, Dec 10, 2020 at 11:23 PM David Gow <davidgow@google.com> wrote: > > When a number of tests fail, it can be useful to get higher-level > statistics of how many tests are failing (or how many parameters are > failing in parameterised tests), and in what cases or suites. This is > already done by some non-KUnit tests, so add support for automatically > generating these for KUnit tests. > > This change adds a 'kunit_stats_enabled' switch which has three values: > - 0: No stats are printed (current behaviour) > - 1: Stats are printed only for tests/suites with more than one > subtests, and at least one failure (new default) > - 2: Always print test statistics > > For parameterised tests, the summary line looks as follows: > " # inode_test_xtimestamp_decoding: 0 / 16 test parameters failed" > For test suites, it looks like this: > "# ext4_inode_test: (0 / 1) tests failed (0 / 16 test parameters)" > > kunit_tool is also updated to correctly ignore diagnostic lines, so that > these statistics do not prevent the result from parsing. > > Signed-off-by: David Gow <davidgow@google.com> Sorry, forgot about this. A couple of comments below: > --- > > This is largely a follow-up to the discussion here: > https://lore.kernel.org/linux-kselftest/CABVgOSmy4n_LGwDS7yWfoLftcQzxv6S+iXx9Y=OPcgG2gu0z1w@mail.gmail.com/T/#t > > Does this seem like a sensible addition? I am fine with it as long as other people want it. > Cheers, > -- David > > lib/kunit/test.c | 71 +++++++++++++++++++++++++++++ > tools/testing/kunit/kunit_parser.py | 2 +- > 2 files changed, 72 insertions(+), 1 deletion(-) > > diff --git a/lib/kunit/test.c b/lib/kunit/test.c > index ec9494e914ef..711e269366a7 100644 > --- a/lib/kunit/test.c > +++ b/lib/kunit/test.c > @@ -9,6 +9,7 @@ > #include <kunit/test.h> > #include <linux/kernel.h> > #include <linux/kref.h> > +#include <linux/moduleparam.h> > #include <linux/sched/debug.h> > #include <linux/sched.h> > > @@ -16,6 +17,40 @@ > #include "string-stream.h" > #include "try-catch-impl.h" > > +/* > + * KUnit statistic mode: > + * 0 - disabled > + * 1 - only when there is at least one failure, and more than one subtest > + * 2 - enabled > + */ > +static int kunit_stats_enabled = 1; > +core_param(kunit_stats_enabled, kunit_stats_enabled, int, 0644); I think this should be a module param. Also, remember to document the param with: MODULE_PARM_DESC() > +static bool kunit_should_print_stats(int num_failures, int num_subtests) > +{ > + if (kunit_stats_enabled == 0) > + return false; > + > + if (kunit_stats_enabled == 2) > + return true; > + > + return (num_failures > 0 && num_subtests > 1); > +} > + > +static void kunit_print_test_stats(struct kunit *test, > + size_t num_failures, size_t num_subtests) > +{ > + if (!kunit_should_print_stats(num_failures, num_subtests)) > + return; > + > + kunit_log(KERN_INFO, test, > + KUNIT_SUBTEST_INDENT > + "# %s: %lu / %lu test parameters failed", > + test->name, > + num_failures, > + num_subtests); > +} > + > /* > * Append formatted message to log, size of which is limited to > * KUNIT_LOG_SIZE bytes (including null terminating byte). > @@ -346,15 +381,37 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite, > test_case->success = test->success; > } > > +static void kunit_print_suite_stats(struct kunit_suite *suite, > + size_t num_failures, > + size_t total_param_failures, > + size_t total_params) > +{ > + size_t num_cases = kunit_suite_num_test_cases(suite); > + > + if (!kunit_should_print_stats(num_failures, num_cases)) > + return; > + > + kunit_log(KERN_INFO, suite, > + "# %s: (%lu / %lu) tests failed (%lu / %lu test parameters)", > + suite->name, > + num_failures, > + num_cases, > + total_param_failures, > + total_params); > +} > + > int kunit_run_tests(struct kunit_suite *suite) > { > char param_desc[KUNIT_PARAM_DESC_SIZE]; > struct kunit_case *test_case; > + size_t num_suite_failures = 0; > + size_t total_param_failures = 0, total_params = 0; > > kunit_print_subtest_start(suite); > > kunit_suite_for_each_test_case(suite, test_case) { > struct kunit test = { .param_value = NULL, .param_index = 0 }; > + size_t num_params = 0, num_failures = 0; > bool test_success = true; > > if (test_case->generate_params) { > @@ -385,13 +442,27 @@ int kunit_run_tests(struct kunit_suite *suite) > test.param_value = test_case->generate_params(test.param_value, param_desc); > test.param_index++; > } > + > + if (!test.success) > + num_failures++; > + num_params++; > + > } while (test.param_value); > > + kunit_print_test_stats(&test, num_failures, num_params); > + > kunit_print_ok_not_ok(&test, true, test_success, > kunit_test_case_num(suite, test_case), > test_case->name); > + > + if (!test_success) > + num_suite_failures++; > + total_params += num_params; > + total_param_failures += num_failures; > } > > + kunit_print_suite_stats(suite, num_suite_failures, > + total_param_failures, total_params); > kunit_print_subtest_end(suite); > > return 0; > diff --git a/tools/testing/kunit/kunit_parser.py b/tools/testing/kunit/kunit_parser.py > index 6614ec4d0898..88ee2b2668ad 100644 > --- a/tools/testing/kunit/kunit_parser.py > +++ b/tools/testing/kunit/kunit_parser.py > @@ -95,7 +95,7 @@ def print_log(log): > for m in log: > print_with_timestamp(m) > > -TAP_ENTRIES = re.compile(r'^(TAP|[\s]*ok|[\s]*not ok|[\s]*[0-9]+\.\.[0-9]+|[\s]*#).*$') > +TAP_ENTRIES = re.compile(r'^(TAP|[\s]*ok|[\s]*not ok|[\s]*[0-9]+\.\.[0-9]+|[\s]*# Subtest:).*$') > > def consume_non_diagnositic(lines: List[str]) -> None: > while lines and not TAP_ENTRIES.match(lines[0]): > > base-commit: 5f6b99d0287de2c2d0b5e7abcb0092d553ad804a > -- > 2.29.2.576.ga3fc446d84-goog >
diff --git a/lib/kunit/test.c b/lib/kunit/test.c index ec9494e914ef..711e269366a7 100644 --- a/lib/kunit/test.c +++ b/lib/kunit/test.c @@ -9,6 +9,7 @@ #include <kunit/test.h> #include <linux/kernel.h> #include <linux/kref.h> +#include <linux/moduleparam.h> #include <linux/sched/debug.h> #include <linux/sched.h> @@ -16,6 +17,40 @@ #include "string-stream.h" #include "try-catch-impl.h" +/* + * KUnit statistic mode: + * 0 - disabled + * 1 - only when there is at least one failure, and more than one subtest + * 2 - enabled + */ +static int kunit_stats_enabled = 1; +core_param(kunit_stats_enabled, kunit_stats_enabled, int, 0644); + +static bool kunit_should_print_stats(int num_failures, int num_subtests) +{ + if (kunit_stats_enabled == 0) + return false; + + if (kunit_stats_enabled == 2) + return true; + + return (num_failures > 0 && num_subtests > 1); +} + +static void kunit_print_test_stats(struct kunit *test, + size_t num_failures, size_t num_subtests) +{ + if (!kunit_should_print_stats(num_failures, num_subtests)) + return; + + kunit_log(KERN_INFO, test, + KUNIT_SUBTEST_INDENT + "# %s: %lu / %lu test parameters failed", + test->name, + num_failures, + num_subtests); +} + /* * Append formatted message to log, size of which is limited to * KUNIT_LOG_SIZE bytes (including null terminating byte). @@ -346,15 +381,37 @@ static void kunit_run_case_catch_errors(struct kunit_suite *suite, test_case->success = test->success; } +static void kunit_print_suite_stats(struct kunit_suite *suite, + size_t num_failures, + size_t total_param_failures, + size_t total_params) +{ + size_t num_cases = kunit_suite_num_test_cases(suite); + + if (!kunit_should_print_stats(num_failures, num_cases)) + return; + + kunit_log(KERN_INFO, suite, + "# %s: (%lu / %lu) tests failed (%lu / %lu test parameters)", + suite->name, + num_failures, + num_cases, + total_param_failures, + total_params); +} + int kunit_run_tests(struct kunit_suite *suite) { char param_desc[KUNIT_PARAM_DESC_SIZE]; struct kunit_case *test_case; + size_t num_suite_failures = 0; + size_t total_param_failures = 0, total_params = 0; kunit_print_subtest_start(suite); kunit_suite_for_each_test_case(suite, test_case) { struct kunit test = { .param_value = NULL, .param_index = 0 }; + size_t num_params = 0, num_failures = 0; bool test_success = true; if (test_case->generate_params) { @@ -385,13 +442,27 @@ int kunit_run_tests(struct kunit_suite *suite) test.param_value = test_case->generate_params(test.param_value, param_desc); test.param_index++; } + + if (!test.success) + num_failures++; + num_params++; + } while (test.param_value); + kunit_print_test_stats(&test, num_failures, num_params); + kunit_print_ok_not_ok(&test, true, test_success, kunit_test_case_num(suite, test_case), test_case->name); + + if (!test_success) + num_suite_failures++; + total_params += num_params; + total_param_failures += num_failures; } + kunit_print_suite_stats(suite, num_suite_failures, + total_param_failures, total_params); kunit_print_subtest_end(suite); return 0; diff --git a/tools/testing/kunit/kunit_parser.py b/tools/testing/kunit/kunit_parser.py index 6614ec4d0898..88ee2b2668ad 100644 --- a/tools/testing/kunit/kunit_parser.py +++ b/tools/testing/kunit/kunit_parser.py @@ -95,7 +95,7 @@ def print_log(log): for m in log: print_with_timestamp(m) -TAP_ENTRIES = re.compile(r'^(TAP|[\s]*ok|[\s]*not ok|[\s]*[0-9]+\.\.[0-9]+|[\s]*#).*$') +TAP_ENTRIES = re.compile(r'^(TAP|[\s]*ok|[\s]*not ok|[\s]*[0-9]+\.\.[0-9]+|[\s]*# Subtest:).*$') def consume_non_diagnositic(lines: List[str]) -> None: while lines and not TAP_ENTRIES.match(lines[0]):
When a number of tests fail, it can be useful to get higher-level statistics of how many tests are failing (or how many parameters are failing in parameterised tests), and in what cases or suites. This is already done by some non-KUnit tests, so add support for automatically generating these for KUnit tests. This change adds a 'kunit_stats_enabled' switch which has three values: - 0: No stats are printed (current behaviour) - 1: Stats are printed only for tests/suites with more than one subtests, and at least one failure (new default) - 2: Always print test statistics For parameterised tests, the summary line looks as follows: " # inode_test_xtimestamp_decoding: 0 / 16 test parameters failed" For test suites, it looks like this: "# ext4_inode_test: (0 / 1) tests failed (0 / 16 test parameters)" kunit_tool is also updated to correctly ignore diagnostic lines, so that these statistics do not prevent the result from parsing. Signed-off-by: David Gow <davidgow@google.com> --- This is largely a follow-up to the discussion here: https://lore.kernel.org/linux-kselftest/CABVgOSmy4n_LGwDS7yWfoLftcQzxv6S+iXx9Y=OPcgG2gu0z1w@mail.gmail.com/T/#t Does this seem like a sensible addition? Cheers, -- David lib/kunit/test.c | 71 +++++++++++++++++++++++++++++ tools/testing/kunit/kunit_parser.py | 2 +- 2 files changed, 72 insertions(+), 1 deletion(-) base-commit: 5f6b99d0287de2c2d0b5e7abcb0092d553ad804a