Re: [PATCH v2] kunit: fix failure to build without printk

From: Brendan Higgins
Date: Fri Aug 30 2019 - 14:38:30 EST


On Thu, Aug 29, 2019 at 09:44:58PM -0700, Joe Perches wrote:
> On Thu, 2019-08-29 at 11:01 -0600, shuah wrote:
> > On 8/28/19 3:49 AM, Sergey Senozhatsky wrote:
> > > On (08/28/19 02:31), Brendan Higgins wrote:
> > > [..]
> > > > Previously KUnit assumed that printk would always be present, which is
> > > > not a valid assumption to make. Fix that by removing call to
> > > > vprintk_emit, and calling printk directly.
> > > >
> > > > Reported-by: Randy Dunlap <rdunlap@xxxxxxxxxxxxx>
> > > > Link: https://lore.kernel.org/linux-kselftest/0352fae9-564f-4a97-715a-fabe016259df@xxxxxxxxxx/T/#t
> > > > Cc: Stephen Rothwell <sfr@xxxxxxxxxxxxxxxx>
> > > > Cc: Sergey Senozhatsky <sergey.senozhatsky.work@xxxxxxxxx>
> > > > Signed-off-by: Brendan Higgins <brendanhiggins@xxxxxxxxxx>
> > >
> > > [..]
> > >
> > > > -static void kunit_vprintk(const struct kunit *test,
> > > > - const char *level,
> > > > - struct va_format *vaf)
> > > > -{
> > > > - kunit_printk_emit(level[1] - '0', "\t# %s: %pV", test->name, vaf);
> > > > -}
> > >
> > > This patch looks good to me. I like the removal of recursive
> > > vsprintf() (%pV).
> > >
> > > -ss
> > >
> >
> > Hi Sergey,
> >
> > What are the guidelines for using printk(). I recall some discussion
> > about not using printk(). I am seeing the following from checkpatch
> > script:
> >
> >
> > WARNING: Prefer [subsystem eg: netdev]_level([subsystem]dev, ... then
> > dev_level(dev, ... then pr_level(... to printk(KERN_LEVEL ...
> > #105: FILE: include/kunit/test.h:343:
> > + printk(KERN_LEVEL "\t# %s: " fmt, (test)->name, ##__VA_ARGS__)
> >
> >
> > Is there supposed to be pr_level() - I can find dev_level()
> >
> > cc'ing Joe Perches for his feedback on this message recommending
> > pr_level() which isn't in 5.3.
>
> I don't care for pr_level or KERN_LEVEL in a printk.

I don't think I follow, how does your version fix this?

> I think this is somewhat overly complicated.
>
> I think I'd write it like:
> ---
> include/kunit/test.h | 11 ++++-----
> kunit/test.c | 69 ++++++++++++++++------------------------------------
> 2 files changed, 26 insertions(+), 54 deletions(-)
>
> diff --git a/include/kunit/test.h b/include/kunit/test.h
> index 8b7eb03d4971..aa4abf0a22a5 100644
> --- a/include/kunit/test.h
> +++ b/include/kunit/test.h
> @@ -339,9 +339,8 @@ static inline void *kunit_kzalloc(struct kunit *test, size_t size, gfp_t gfp)
>
> void kunit_cleanup(struct kunit *test);
>
> -void __printf(3, 4) kunit_printk(const char *level,
> - const struct kunit *test,
> - const char *fmt, ...);
> +__printf(2, 3)
> +void kunit_printk(const struct kunit *test, const char *fmt, ...);
>
> /**
> * kunit_info() - Prints an INFO level message associated with @test.
> @@ -353,7 +352,7 @@ void __printf(3, 4) kunit_printk(const char *level,
> * Takes a variable number of format parameters just like printk().
> */
> #define kunit_info(test, fmt, ...) \
> - kunit_printk(KERN_INFO, test, fmt, ##__VA_ARGS__)
> + kunit_printk(test, KERN_INFO fmt, ##__VA_ARGS__)
>
> /**
> * kunit_warn() - Prints a WARN level message associated with @test.
> @@ -364,7 +363,7 @@ void __printf(3, 4) kunit_printk(const char *level,
> * Prints a warning level message.
> */
> #define kunit_warn(test, fmt, ...) \
> - kunit_printk(KERN_WARNING, test, fmt, ##__VA_ARGS__)
> + kunit_printk(test, KERN_WARNING fmt, ##__VA_ARGS__)
>
> /**
> * kunit_err() - Prints an ERROR level message associated with @test.
> @@ -375,7 +374,7 @@ void __printf(3, 4) kunit_printk(const char *level,
> * Prints an error level message.
> */
> #define kunit_err(test, fmt, ...) \
> - kunit_printk(KERN_ERR, test, fmt, ##__VA_ARGS__)
> + kunit_printk(test, KERN_ERR fmt, ##__VA_ARGS__)
>
> /**
> * KUNIT_SUCCEED() - A no-op expectation. Only exists for code clarity.
> diff --git a/kunit/test.c b/kunit/test.c
> index b2ca9b94c353..ddb9bffb5a5d 100644
> --- a/kunit/test.c
> +++ b/kunit/test.c
> @@ -16,40 +16,6 @@ static void kunit_set_failure(struct kunit *test)
> WRITE_ONCE(test->success, false);
> }
>
> -static int kunit_vprintk_emit(int level, const char *fmt, va_list args)
> -{
> - return vprintk_emit(0, level, NULL, 0, fmt, args);
> -}
> -
> -static int kunit_printk_emit(int level, const char *fmt, ...)
> -{
> - va_list args;
> - int ret;
> -
> - va_start(args, fmt);
> - ret = kunit_vprintk_emit(level, fmt, args);
> - va_end(args);
> -
> - return ret;
> -}
> -
> -static void kunit_vprintk(const struct kunit *test,
> - const char *level,
> - struct va_format *vaf)
> -{
> - kunit_printk_emit(level[1] - '0', "\t# %s: %pV", test->name, vaf);
> -}
> -
> -static void kunit_print_tap_version(void)
> -{
> - static bool kunit_has_printed_tap_version;
> -
> - if (!kunit_has_printed_tap_version) {
> - kunit_printk_emit(LOGLEVEL_INFO, "TAP version 14\n");
> - kunit_has_printed_tap_version = true;
> - }
> -}
> -
> static size_t kunit_test_cases_len(struct kunit_case *test_cases)
> {
> struct kunit_case *test_case;
> @@ -63,11 +29,9 @@ static size_t kunit_test_cases_len(struct kunit_case *test_cases)
>
> static void kunit_print_subtest_start(struct kunit_suite *suite)
> {
> - kunit_print_tap_version();
> - kunit_printk_emit(LOGLEVEL_INFO, "\t# Subtest: %s\n", suite->name);
> - kunit_printk_emit(LOGLEVEL_INFO,
> - "\t1..%zd\n",
> - kunit_test_cases_len(suite->test_cases));
> + pr_info_once("TAP version 14\n");
> + pr_info("\t# Subtest: %s\n", suite->name);
> + pr_info("\t1..%zd\n", kunit_test_cases_len(suite->test_cases));
> }
>
> static void kunit_print_ok_not_ok(bool should_indent,
> @@ -87,9 +51,8 @@ static void kunit_print_ok_not_ok(bool should_indent,
> else
> ok_not_ok = "not ok";
>
> - kunit_printk_emit(LOGLEVEL_INFO,
> - "%s%s %zd - %s\n",
> - indent, ok_not_ok, test_number, description);
> + pr_info("%s%s %zd - %s\n",
> + indent, ok_not_ok, test_number, description);
> }
>
> static bool kunit_suite_has_succeeded(struct kunit_suite *suite)
> @@ -133,11 +96,11 @@ static void kunit_print_string_stream(struct kunit *test,
> kunit_err(test,
> "Could not allocate buffer, dumping stream:\n");
> list_for_each_entry(fragment, &stream->fragments, node) {
> - kunit_err(test, fragment->fragment);
> + kunit_err(test, "%s", fragment->fragment);
> }
> kunit_err(test, "\n");
> } else {
> - kunit_err(test, buf);
> + kunit_err(test, "%s", buf);
> kunit_kfree(test, buf);
> }
> }
> @@ -505,19 +468,29 @@ void kunit_cleanup(struct kunit *test)
> }
> }
>
> -void kunit_printk(const char *level,
> - const struct kunit *test,
> - const char *fmt, ...)
> +void kunit_printk(const struct kunit *test, const char *fmt, ...)
> {
> + char lvl[PRINTK_MAX_SINGLE_HEADER_LEN + 1] = "\0";
> struct va_format vaf;
> va_list args;
> + int kern_level;
>
> va_start(args, fmt);
>
> + while ((kern_level = printk_get_level(fmt)) != 0) {
> + size_t size = printk_skip_level(fmt) - fmt;
> +
> + if (kern_level >= '0' && kern_level <= '7') {
> + memcpy(lvl, fmt, size);
> + lvl[size] = '\0';
> + }
> + fmt += size;
> + }
> +
> vaf.fmt = fmt;
> vaf.va = &args;
>
> - kunit_vprintk(test, level, &vaf);
> + printk("%s\t# %s %pV\n", lvl, test->name, &vaf);
>
> va_end(args);
> }

How is this simpler?

If we are okay with dynamically adding the KERN_<LEVEL> and %pV (and I
don't think that Sergey is), then wouldn't it be easier to pass in the
kernel level as a separate parameter and then strip off all printk
headers like this:

void kunit_printk(const char *level,
const struct kunit *test,
const char *fmt, ...)
{
struct va_format vaf;
va_list args;

va_start(args, fmt);

+ fmt = printk_skip_headers(fmt);
+
vaf.fmt = fmt;
vaf.va = &args;

- kunit_vprintk(test, level, &vaf);
+ printk("%s\t# %s %pV\n", level, test->name, &vaf);

va_end(args);
}

Then the kunit_printk function is much simpler, and I don't think my
header file has to change at all.

I don't know. I am clearly not an expert on this topic, but I don't see
the merit of the while loop you added above or dropping the level param.