Re: [PATCH] lib: Convert test_printf.c to KUnit

[Brendan Higgins]

On Fri, Aug 21, 2020 at 5:19 AM Rasmus Villemoes
<linux@xxxxxxxxxxxxxxxxxx> wrote:

Sorry about the late reply. I saw activity on this before and thought
it was under control. I only saw the unresolved state now looking
through patchwork.

> On 21/08/2020 13.37, Petr Mladek wrote:
> > On Mon 2020-08-17 09:06:32, Rasmus Villemoes wrote:
> >> On 17/08/2020 06.30, Arpitha Raghunandan wrote:
> >>> Converts test lib/test_printf.c to KUnit.
> >>> More information about KUnit can be found at
> >>> https://www.kernel.org/doc/html/latest/dev-tools/kunit/index.html.
> >>> KUnit provides a common framework for unit tests in the kernel.
> >>
> >> So I can continue to build a kernel with some appropriate CONFIG set to
> >> y, boot it under virt-me, run dmesg and see if I broke printf? That's
> >> what I do now, and I don't want to have to start using some enterprisy
> >> framework.
> >
> > I had the same concern. I have tried it.
>
> Thanks for doing that and reporting the results.
>
> >     #> modprobe printf_kunit
> >
> > produced the following in dmesg:
> >
> > [   60.931175] printf_kunit: module verification failed: signature and/or required key missing - tainting kernel
> > [   60.942209] TAP version 14
> > [   60.945197]     # Subtest: printf-kunit-test
> > [   60.945200]     1..1
> > [   60.951092]     ok 1 - selftest
> > [   60.953414] ok 1 - printf-kunit-test
> >
> > I could live with the above. Then I tried to break a test by the following change:
> >
> >
> > diff --git a/lib/printf_kunit.c b/lib/printf_kunit.c
> > index 68ac5f9b8d28..1689dadd70a3 100644
> > --- a/lib/printf_kunit.c
> > +++ b/lib/printf_kunit.c
> > @@ -395,7 +395,7 @@ ip4(struct kunit *kunittest)
> >         sa.sin_port = cpu_to_be16(12345);
> >         sa.sin_addr.s_addr = cpu_to_be32(0x7f000001);
> >
> > -       test(kunittest, "127.000.000.001|127.0.0.1", "%pi4|%pI4", &sa.sin_addr, &sa.sin_addr);
> > +       test(kunittest, "127-000.000.001|127.0.0.1", "%pi4|%pI4", &sa.sin_addr, &sa.sin_addr);
> >         test(kunittest, "127.000.000.001|127.0.0.1", "%piS|%pIS", &sa, &sa);
> >         sa.sin_addr.s_addr = cpu_to_be32(0x01020304);
> >         test(kunittest, "001.002.003.004:12345|1.2.3.4:12345", "%piSp|%pISp", &sa, &sa);
> >
> >
> > It produced::
> >
> > [   56.786858] TAP version 14
> > [   56.787493]     # Subtest: printf-kunit-test
> > [   56.787494]     1..1
> > [   56.788612]     # selftest: EXPECTATION FAILED at lib/printf_kunit.c:76
> >                    Expected memcmp(test_buffer, expect, written) == 0, but
> >                        memcmp(test_buffer, expect, written) == 1
> >                        0 == 0
> >                vsnprintf(buf, 256, "%pi4|%pI4", ...) wrote '127.000.000.001|127.0.0.1', expected '127-000.000.001|127.0.0.1'
> > [   56.795433]     # selftest: EXPECTATION FAILED at lib/printf_kunit.c:76
> >                    Expected memcmp(test_buffer, expect, written) == 0, but
> >                        memcmp(test_buffer, expect, written) == 1
> >                        0 == 0
> >                vsnprintf(buf, 20, "%pi4|%pI4", ...) wrote '127.000.000.001|127', expected '127-000.000.001|127'
> > [   56.800909]     # selftest: EXPECTATION FAILED at lib/printf_kunit.c:108
> >                    Expected memcmp(p, expect, elen+1) == 0, but
> >                        memcmp(p, expect, elen+1) == 1
> >                        0 == 0
> >                kvasprintf(..., "%pi4|%pI4", ...) returned '127.000.000.001|127.0.0.1', expected '127-000.000.001|127.0.0.1'
> > [   56.806497]     not ok 1 - selftest
> > [   56.806497] not ok 1 - printf-kunit-test
> >
> > while the original code would have written the following error messages:
> >
> > [   95.859225] test_printf: loaded.
> > [   95.860031] test_printf: vsnprintf(buf, 256, "%pi4|%pI4", ...) wrote '127.000.000.001|127.0.0.1', expected '127-000.000.001|127.0.0.1'
> > [   95.862630] test_printf: vsnprintf(buf, 6, "%pi4|%pI4", ...) wrote '127.0', expected '127-0'
> > [   95.864118] test_printf: kvasprintf(..., "%pi4|%pI4", ...) returned '127.000.000.001|127.0.0.1', expected '127-000.000.001|127.0.0.1'
> > [   95.866589] test_printf: failed 3 out of 388 tests
> >
> >
> > Even the error output is acceptable for me.
>
> Urgh. Yeah, perhaps, but the original is much more readable; it really
> doesn't matter that a memcmp() fails to compare equal to 0, that's
> merely how we figured out that the output was wrong.

We can go back to the original error reporting format, just as long as
you don't mind the "ok" lines interspersed throughout (this is part of
an attempt to standardize around the KTAP reporting format[1].

> I am just curious why
> > the 2nd failure is different:
> >
> >    + original code: vsnprintf(buf, 6, "%pi4|%pI4", ...) wrote '127.0', expected '127-0'
> >    + kunit code: vsnprintf(buf, 20, "%pi4|%pI4", ...) wrote '127.000.000.001|127', expected '127-000.000.001|127'
>
> That's by design. If you read the code, there's a comment that says we
> do every test case four times: With a buffer that is large enough to do
> the whole output, with a 0 size buffer (that's essential to allowing
> kasprintf to know how much to allocate),  with kvasprintf - but also
> with a buffer size that's guaranteed to ensure the output gets truncated
> somewhere. And that size is chosen randomly - I guess one could test
> every single buffer size between 0 and elen+1, but that's overkill.
>
> Now I should probably have made the tests deterministic in the sense of
> getting a random seed for a PRNG, printing that seed and allowing a
> module parameter to set the seed in order to repeat the exact same
> tests. But so far I haven't really seen any bugs caught by test_printf
> which would have been easier to fix with that.
>
> The reason I added that "chop it off somewhere randomly" was, IIRC, due
> to some %p extensions that behaved rather weirdly depending on whether
> there was enough room left or not, but I fixed those bugs before
> creating test_printf (and they were in turn the reason for creating
> test_printf). See for example 41416f2330, where %pE at the beginning of
> the format string would work ok, but if anything preceded it and the
> buffer was too small we'd crash.
>
> >
> > I am also a bit scared by the following note at
> > https://www.kernel.org/doc/html/latest/dev-tools/kunit/start.html#running-tests-without-the-kunit-wrapper
> >
> >    "KUnit is not designed for use in a production system, and it’s
> >    possible that tests may reduce the stability or security of the
> >    system."
> >
> > What does it mean thay it might reduce stability or security?
> > Is it because the tests might cause problems?
> > Or because the kunit framework modifies functionality of the running
> > system all the time?

Oh yeah, that's just because we are afraid that tests might cause
problems. KUnit by itself does nothing to affect the stability or
security of the system.