linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL()
@ 2021-06-06  0:55 David Gow
  2021-06-06  9:56 ` Andrey Konovalov
  2021-06-07 20:02 ` Brendan Higgins
  0 siblings, 2 replies; 4+ messages in thread
From: David Gow @ 2021-06-06  0:55 UTC (permalink / raw)
  To: Andrey Ryabinin, Dmitry Vyukov, Daniel Axtens, Brendan Higgins
  Cc: David Gow, kasan-dev, kunit-dev, linux-kernel, Jonathan Corbet,
	linux-doc

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 set
report_expected to 'true'), and print a better failure message with
KUNIT_FAIL(). Because of this, report_expected is no longer used
anywhere, and can be removed.

Beforehand, a failure in:
KUNIT_EXPECT_KASAN_FAIL(test, ((volatile char *)area)[3100]);
would have 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

Also update the example failure in the documentation to reflect this.

Signed-off-by: David Gow <davidgow@google.com>
---

Changes since v2:
https://lkml.org/lkml/2021/6/4/1264
- Update the example error in the documentation

Changes since v1:
https://groups.google.com/g/kasan-dev/c/CbabdwoXGlE
- Remove fail_data.report_expected now that it's unused.
- Use '!' instead of '== false' in the comparison.
- Minor typo fixes in the commit message.

The test failure being used as an example is tracked in:
https://bugzilla.kernel.org/show_bug.cgi?id=213335



 Documentation/dev-tools/kasan.rst |  9 ++++-----
 include/linux/kasan.h             |  1 -
 lib/test_kasan.c                  | 11 +++++------
 3 files changed, 9 insertions(+), 12 deletions(-)

diff --git a/Documentation/dev-tools/kasan.rst b/Documentation/dev-tools/kasan.rst
index d3f335ffc751..83ec4a556c19 100644
--- a/Documentation/dev-tools/kasan.rst
+++ b/Documentation/dev-tools/kasan.rst
@@ -447,11 +447,10 @@ When a test fails due to a failed ``kmalloc``::
 
 When a test fails due to a missing KASAN report::
 
-        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:629
-        Expected kasan_data->report_expected == kasan_data->report_found, but
-        kasan_data->report_expected == 1
-        kasan_data->report_found == 0
-        not ok 28 - kmalloc_double_kzfree
+        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:974
+        KASAN failure expected in "kfree_sensitive(ptr)", but none occurred
+        not ok 44 - kmalloc_double_kzfree
+
 
 At the end the cumulative status of all KASAN tests is printed. On success::
 
diff --git a/include/linux/kasan.h b/include/linux/kasan.h
index b1678a61e6a7..18cd5ec2f469 100644
--- a/include/linux/kasan.h
+++ b/include/linux/kasan.h
@@ -17,7 +17,6 @@ struct task_struct;
 
 /* kasan_data struct is used in KUnit tests for KASAN expected failures */
 struct kunit_kasan_expectation {
-	bool report_expected;
 	bool report_found;
 };
 
diff --git a/lib/test_kasan.c b/lib/test_kasan.c
index cacbbbdef768..44e08f4d9c52 100644
--- a/lib/test_kasan.c
+++ b/lib/test_kasan.c
@@ -55,7 +55,6 @@ static int kasan_test_init(struct kunit *test)
 	multishot = kasan_save_enable_multi_shot();
 	kasan_set_tagging_report_once(false);
 	fail_data.report_found = false;
-	fail_data.report_expected = false;
 	kunit_add_named_resource(test, NULL, NULL, &resource,
 					"kasan_data", &fail_data);
 	return 0;
@@ -94,20 +93,20 @@ static void kasan_test_exit(struct kunit *test)
 	    !kasan_async_mode_enabled())				\
 		migrate_disable();					\
 	KUNIT_EXPECT_FALSE(test, READ_ONCE(fail_data.report_found));	\
-	WRITE_ONCE(fail_data.report_expected, true);			\
 	barrier();							\
 	expression;							\
 	barrier();							\
-	KUNIT_EXPECT_EQ(test,						\
-			READ_ONCE(fail_data.report_expected),		\
-			READ_ONCE(fail_data.report_found));		\
+	if (!READ_ONCE(fail_data.report_found)) {			\
+		KUNIT_FAIL(test, KUNIT_SUBTEST_INDENT "KASAN failure "	\
+				"expected in \"" #expression		\
+				 "\", but none occurred");		\
+	}								\
 	if (IS_ENABLED(CONFIG_KASAN_HW_TAGS)) {				\
 		if (READ_ONCE(fail_data.report_found))			\
 			kasan_enable_tagging_sync();			\
 		migrate_enable();					\
 	}								\
 	WRITE_ONCE(fail_data.report_found, false);			\
-	WRITE_ONCE(fail_data.report_expected, false);			\
 } while (0)
 
 #define KASAN_TEST_NEEDS_CONFIG_ON(test, config) do {			\
-- 
2.32.0.rc1.229.g3e70b5a671-goog


^ permalink raw reply related	[flat|nested] 4+ messages in thread

* Re: [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL()
  2021-06-06  0:55 [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL() David Gow
@ 2021-06-06  9:56 ` Andrey Konovalov
  2021-06-07  9:15   ` Marco Elver
  2021-06-07 20:02 ` Brendan Higgins
  1 sibling, 1 reply; 4+ messages in thread
From: Andrey Konovalov @ 2021-06-06  9:56 UTC (permalink / raw)
  To: David Gow
  Cc: Andrey Ryabinin, Dmitry Vyukov, Daniel Axtens, Brendan Higgins,
	kasan-dev, kunit-dev, LKML, Jonathan Corbet,
	open list:DOCUMENTATION

On Sun, Jun 6, 2021 at 3:55 AM '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 set
> report_expected to 'true'), and print a better failure message with
> KUNIT_FAIL(). Because of this, report_expected is no longer used
> anywhere, and can be removed.
>
> Beforehand, a failure in:
> KUNIT_EXPECT_KASAN_FAIL(test, ((volatile char *)area)[3100]);
> would have 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
>
> Also update the example failure in the documentation to reflect this.
>
> Signed-off-by: David Gow <davidgow@google.com>
> ---
>
> Changes since v2:
> https://lkml.org/lkml/2021/6/4/1264
> - Update the example error in the documentation
>
> Changes since v1:
> https://groups.google.com/g/kasan-dev/c/CbabdwoXGlE
> - Remove fail_data.report_expected now that it's unused.
> - Use '!' instead of '== false' in the comparison.
> - Minor typo fixes in the commit message.
>
> The test failure being used as an example is tracked in:
> https://bugzilla.kernel.org/show_bug.cgi?id=213335
>
>
>
>  Documentation/dev-tools/kasan.rst |  9 ++++-----
>  include/linux/kasan.h             |  1 -
>  lib/test_kasan.c                  | 11 +++++------
>  3 files changed, 9 insertions(+), 12 deletions(-)
>
> diff --git a/Documentation/dev-tools/kasan.rst b/Documentation/dev-tools/kasan.rst
> index d3f335ffc751..83ec4a556c19 100644
> --- a/Documentation/dev-tools/kasan.rst
> +++ b/Documentation/dev-tools/kasan.rst
> @@ -447,11 +447,10 @@ When a test fails due to a failed ``kmalloc``::
>
>  When a test fails due to a missing KASAN report::
>
> -        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:629
> -        Expected kasan_data->report_expected == kasan_data->report_found, but
> -        kasan_data->report_expected == 1
> -        kasan_data->report_found == 0
> -        not ok 28 - kmalloc_double_kzfree
> +        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:974
> +        KASAN failure expected in "kfree_sensitive(ptr)", but none occurred
> +        not ok 44 - kmalloc_double_kzfree
> +
>
>  At the end the cumulative status of all KASAN tests is printed. On success::
>
> diff --git a/include/linux/kasan.h b/include/linux/kasan.h
> index b1678a61e6a7..18cd5ec2f469 100644
> --- a/include/linux/kasan.h
> +++ b/include/linux/kasan.h
> @@ -17,7 +17,6 @@ struct task_struct;
>
>  /* kasan_data struct is used in KUnit tests for KASAN expected failures */
>  struct kunit_kasan_expectation {
> -       bool report_expected;
>         bool report_found;
>  };
>
> diff --git a/lib/test_kasan.c b/lib/test_kasan.c
> index cacbbbdef768..44e08f4d9c52 100644
> --- a/lib/test_kasan.c
> +++ b/lib/test_kasan.c
> @@ -55,7 +55,6 @@ static int kasan_test_init(struct kunit *test)
>         multishot = kasan_save_enable_multi_shot();
>         kasan_set_tagging_report_once(false);
>         fail_data.report_found = false;
> -       fail_data.report_expected = false;
>         kunit_add_named_resource(test, NULL, NULL, &resource,
>                                         "kasan_data", &fail_data);
>         return 0;
> @@ -94,20 +93,20 @@ static void kasan_test_exit(struct kunit *test)
>             !kasan_async_mode_enabled())                                \
>                 migrate_disable();                                      \
>         KUNIT_EXPECT_FALSE(test, READ_ONCE(fail_data.report_found));    \
> -       WRITE_ONCE(fail_data.report_expected, true);                    \
>         barrier();                                                      \
>         expression;                                                     \
>         barrier();                                                      \
> -       KUNIT_EXPECT_EQ(test,                                           \
> -                       READ_ONCE(fail_data.report_expected),           \
> -                       READ_ONCE(fail_data.report_found));             \
> +       if (!READ_ONCE(fail_data.report_found)) {                       \
> +               KUNIT_FAIL(test, KUNIT_SUBTEST_INDENT "KASAN failure "  \
> +                               "expected in \"" #expression            \
> +                                "\", but none occurred");              \
> +       }                                                               \
>         if (IS_ENABLED(CONFIG_KASAN_HW_TAGS)) {                         \
>                 if (READ_ONCE(fail_data.report_found))                  \
>                         kasan_enable_tagging_sync();                    \
>                 migrate_enable();                                       \
>         }                                                               \
>         WRITE_ONCE(fail_data.report_found, false);                      \
> -       WRITE_ONCE(fail_data.report_expected, false);                   \
>  } while (0)
>
>  #define KASAN_TEST_NEEDS_CONFIG_ON(test, config) do {                  \
> --
> 2.32.0.rc1.229.g3e70b5a671-goog

Reviewed-by: Andrey Konovalov <andreyknvl@gmail.com>

Thanks!

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL()
  2021-06-06  9:56 ` Andrey Konovalov
@ 2021-06-07  9:15   ` Marco Elver
  0 siblings, 0 replies; 4+ messages in thread
From: Marco Elver @ 2021-06-07  9:15 UTC (permalink / raw)
  To: Andrey Konovalov
  Cc: David Gow, Andrey Ryabinin, Dmitry Vyukov, Daniel Axtens,
	Brendan Higgins, kasan-dev, KUnit Development, LKML,
	Jonathan Corbet, open list:DOCUMENTATION, Andrew Morton

On Sun, 6 Jun 2021 at 11:57, Andrey Konovalov <andreyknvl@gmail.com> wrote:
>
> On Sun, Jun 6, 2021 at 3:55 AM '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 set
> > report_expected to 'true'), and print a better failure message with
> > KUNIT_FAIL(). Because of this, report_expected is no longer used
> > anywhere, and can be removed.
> >
> > Beforehand, a failure in:
> > KUNIT_EXPECT_KASAN_FAIL(test, ((volatile char *)area)[3100]);
> > would have 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
> >
> > Also update the example failure in the documentation to reflect this.
> >
> > Signed-off-by: David Gow <davidgow@google.com>
> > ---
> >
> > Changes since v2:
> > https://lkml.org/lkml/2021/6/4/1264
> > - Update the example error in the documentation
> >
> > Changes since v1:
> > https://groups.google.com/g/kasan-dev/c/CbabdwoXGlE
> > - Remove fail_data.report_expected now that it's unused.
> > - Use '!' instead of '== false' in the comparison.
> > - Minor typo fixes in the commit message.
> >
> > The test failure being used as an example is tracked in:
> > https://bugzilla.kernel.org/show_bug.cgi?id=213335
> >
> >
> >
> >  Documentation/dev-tools/kasan.rst |  9 ++++-----
> >  include/linux/kasan.h             |  1 -
> >  lib/test_kasan.c                  | 11 +++++------
> >  3 files changed, 9 insertions(+), 12 deletions(-)
> >
> > diff --git a/Documentation/dev-tools/kasan.rst b/Documentation/dev-tools/kasan.rst
> > index d3f335ffc751..83ec4a556c19 100644
> > --- a/Documentation/dev-tools/kasan.rst
> > +++ b/Documentation/dev-tools/kasan.rst
> > @@ -447,11 +447,10 @@ When a test fails due to a failed ``kmalloc``::
> >
> >  When a test fails due to a missing KASAN report::
> >
> > -        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:629
> > -        Expected kasan_data->report_expected == kasan_data->report_found, but
> > -        kasan_data->report_expected == 1
> > -        kasan_data->report_found == 0
> > -        not ok 28 - kmalloc_double_kzfree
> > +        # kmalloc_double_kzfree: EXPECTATION FAILED at lib/test_kasan.c:974
> > +        KASAN failure expected in "kfree_sensitive(ptr)", but none occurred
> > +        not ok 44 - kmalloc_double_kzfree
> > +
> >
> >  At the end the cumulative status of all KASAN tests is printed. On success::
> >
> > diff --git a/include/linux/kasan.h b/include/linux/kasan.h
> > index b1678a61e6a7..18cd5ec2f469 100644
> > --- a/include/linux/kasan.h
> > +++ b/include/linux/kasan.h
> > @@ -17,7 +17,6 @@ struct task_struct;
> >
> >  /* kasan_data struct is used in KUnit tests for KASAN expected failures */
> >  struct kunit_kasan_expectation {
> > -       bool report_expected;
> >         bool report_found;
> >  };
> >
> > diff --git a/lib/test_kasan.c b/lib/test_kasan.c
> > index cacbbbdef768..44e08f4d9c52 100644
> > --- a/lib/test_kasan.c
> > +++ b/lib/test_kasan.c
> > @@ -55,7 +55,6 @@ static int kasan_test_init(struct kunit *test)
> >         multishot = kasan_save_enable_multi_shot();
> >         kasan_set_tagging_report_once(false);
> >         fail_data.report_found = false;
> > -       fail_data.report_expected = false;
> >         kunit_add_named_resource(test, NULL, NULL, &resource,
> >                                         "kasan_data", &fail_data);
> >         return 0;
> > @@ -94,20 +93,20 @@ static void kasan_test_exit(struct kunit *test)
> >             !kasan_async_mode_enabled())                                \
> >                 migrate_disable();                                      \
> >         KUNIT_EXPECT_FALSE(test, READ_ONCE(fail_data.report_found));    \
> > -       WRITE_ONCE(fail_data.report_expected, true);                    \
> >         barrier();                                                      \
> >         expression;                                                     \
> >         barrier();                                                      \
> > -       KUNIT_EXPECT_EQ(test,                                           \
> > -                       READ_ONCE(fail_data.report_expected),           \
> > -                       READ_ONCE(fail_data.report_found));             \
> > +       if (!READ_ONCE(fail_data.report_found)) {                       \
> > +               KUNIT_FAIL(test, KUNIT_SUBTEST_INDENT "KASAN failure "  \
> > +                               "expected in \"" #expression            \
> > +                                "\", but none occurred");              \
> > +       }                                                               \
> >         if (IS_ENABLED(CONFIG_KASAN_HW_TAGS)) {                         \
> >                 if (READ_ONCE(fail_data.report_found))                  \
> >                         kasan_enable_tagging_sync();                    \
> >                 migrate_enable();                                       \
> >         }                                                               \
> >         WRITE_ONCE(fail_data.report_found, false);                      \
> > -       WRITE_ONCE(fail_data.report_expected, false);                   \
> >  } while (0)
> >
> >  #define KASAN_TEST_NEEDS_CONFIG_ON(test, config) do {                  \
> > --
> > 2.32.0.rc1.229.g3e70b5a671-goog
>
> Reviewed-by: Andrey Konovalov <andreyknvl@gmail.com>

Reviewed-by: Marco Elver <elver@google.com>

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL()
  2021-06-06  0:55 [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL() David Gow
  2021-06-06  9:56 ` Andrey Konovalov
@ 2021-06-07 20:02 ` Brendan Higgins
  1 sibling, 0 replies; 4+ messages in thread
From: Brendan Higgins @ 2021-06-07 20:02 UTC (permalink / raw)
  To: David Gow
  Cc: Andrey Ryabinin, Dmitry Vyukov, Daniel Axtens, kasan-dev,
	KUnit Development, Linux Kernel Mailing List, Jonathan Corbet,
	open list:DOCUMENTATION

On Sat, Jun 5, 2021 at 5:55 PM David Gow <davidgow@google.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 set
> report_expected to 'true'), and print a better failure message with
> KUNIT_FAIL(). Because of this, report_expected is no longer used
> anywhere, and can be removed.
>
> Beforehand, a failure in:
> KUNIT_EXPECT_KASAN_FAIL(test, ((volatile char *)area)[3100]);
> would have 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
>
> Also update the example failure in the documentation to reflect this.
>
> Signed-off-by: David Gow <davidgow@google.com>

Nice work!

Acked-by: Brendan Higgins <brendanhiggins@google.com>

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, other threads:[~2021-06-07 20:02 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-06-06  0:55 [PATCH v3] kasan: test: Improve failure message in KUNIT_EXPECT_KASAN_FAIL() David Gow
2021-06-06  9:56 ` Andrey Konovalov
2021-06-07  9:15   ` Marco Elver
2021-06-07 20:02 ` Brendan Higgins

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).