Re: [PATCH] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL()

[David Gow <davidgow@google.com>]

On Fri, Jun 4, 2021 at 3:55 PM Marco Elver <elver@google.com> wrote:
>
> On Fri, 4 Jun 2021 at 07:26, 'David Gow' via kasan-dev
> <kasan-dev@googlegroups.com> wrote:
> > The KUNIT_EXPECT_KASAN_FAIL() macro currently uses KUNIT_EXPECT_EQ() to
> > compare fail_data.report_expected and fail_data.report_found. This
> > always gave a somewhat useless error message on failure, but the
> > addition of extra compile-time checking with READ_ONCE() has caused it
> > to get much longer, and be truncated before anything useful is displayed.
> >
> > Instead, just check fail_data.report_found by hand (we've just test
> > report_expected to 'true'), and print a better failure message with
> > KUNIT_FAIL()
> >
> > Beforehand, a failure in:
> > KUNIT_EXPECT_KASAN_FAIL(test, ((volatile char *)area)[3100]);
> > would looked like:
> > [22:00:34] [FAILED] vmalloc_oob
> > [22:00:34]     # vmalloc_oob: EXPECTATION FAILED at lib/test_kasan.c:991
> > [22:00:34]     Expected ({ do { extern void __compiletime_assert_705(void) __attribute__((__error__("Unsupported access size for {READ,WRITE}_ONCE()."))); if (!((sizeof(fail_data.report_expected) == sizeof(char) || sizeof(fail_data.repp
> > [22:00:34]     not ok 45 - vmalloc_oob
> >
> > With this change, it instead looks like:
> > [22:04:04] [FAILED] vmalloc_oob
> > [22:04:04]     # vmalloc_oob: EXPECTATION FAILED at lib/test_kasan.c:993
> > [22:04:04]     KASAN failure expected in "((volatile char *)area)[3100]", but none occurred
> > [22:04:04]     not ok 45 - vmalloc_oob
> >
> > Signed-off-by: David Gow <davidgow@google.com>
> > ---
> >
> > Stumbled across this because the vmalloc_oob test is failing (i.e.,
> > KASAN isn't picking up an error) under qemu on my system, and the
> > message above was horrifying. (I'll file a Bugzilla bug for the test
> > failure today.)
> >
> > Cheers,
> > -- David
> >
> >  lib/test_kasan.c | 8 +++++---
> >  1 file changed, 5 insertions(+), 3 deletions(-)
> >
> > diff --git a/lib/test_kasan.c b/lib/test_kasan.c
> > index cacbbbdef768..deda13c9d9ff 100644
> > --- a/lib/test_kasan.c
> > +++ b/lib/test_kasan.c
> > @@ -98,9 +98,11 @@ static void kasan_test_exit(struct kunit *test)
> >         barrier();                                                      \
> >         expression;                                                     \
> >         barrier();                                                      \
> > -       KUNIT_EXPECT_EQ(test,                                           \
> > -                       READ_ONCE(fail_data.report_expected),           \
>
> What do we have fail_data.report_expected for? Could we remove it now?
> I think it's unused now.
>

I thought this was being used in kasan_update_kunit_status() (in
mm/kasan/report.c), but it looks like I was mistaken. We should be
able to get rid of it, then/

> > -                       READ_ONCE(fail_data.report_found));             \
> > +       if (READ_ONCE(fail_data.report_found) == false) {               \
>
> if (!READ_ONCE(fail_data.report_found)) {
> ?
>

I'll change this for v2.

> > +               KUNIT_FAIL(test, KUNIT_SUBTEST_INDENT "KASAN failure "  \
> > +                               "expected in \"" #expression            \
> > +                                "\", but none occurred");              \
> > +       }                                                               \
>
> Thanks,
> -- Marco