diff mbox series

[v2,4/5] lib/cpumask_kunit: log mask contents

Message ID 98cb4e5323c2059506e93cb39c32ba471031e487.1661007339.git.sander@svanheule.net (mailing list archive)
State Superseded
Headers show
Series cpumask: KUnit test suite fixes and improvements | expand

Commit Message

Sander Vanheule Aug. 20, 2022, 3:03 p.m. UTC 
For extra context, log the contents of the masks under test.  This
should help with finding out why a certain test fails.

Link: https://lore.kernel.org/lkml/CABVgOSkPXBc-PWk1zBZRQ_Tt+Sz1ruFHBj3ixojymZF=Vi4tpQ@mail.gmail.com/
Suggested-by: David Gow <davidgow@google.com>
Signed-off-by: Sander Vanheule <sander@svanheule.net>
Reviewed-by: David Gow <davidgow@google.com>
---
 lib/cpumask_kunit.c | 10 ++++++++++
 1 file changed, 10 insertions(+)

Comments

Yury Norov Aug. 20, 2022, 9:46 p.m. UTC | #1 
On Sat, Aug 20, 2022 at 05:03:12PM +0200, Sander Vanheule wrote:
> For extra context, log the contents of the masks under test.  This
> should help with finding out why a certain test fails.
> 
> Link: https://lore.kernel.org/lkml/CABVgOSkPXBc-PWk1zBZRQ_Tt+Sz1ruFHBj3ixojymZF=Vi4tpQ@mail.gmail.com/
> Suggested-by: David Gow <davidgow@google.com>
> Signed-off-by: Sander Vanheule <sander@svanheule.net>
> Reviewed-by: David Gow <davidgow@google.com>
> ---
>  lib/cpumask_kunit.c | 10 ++++++++++
>  1 file changed, 10 insertions(+)
> 
> diff --git a/lib/cpumask_kunit.c b/lib/cpumask_kunit.c
> index 4d353614d853..0f8059a5e93b 100644
> --- a/lib/cpumask_kunit.c
> +++ b/lib/cpumask_kunit.c
> @@ -51,6 +51,10 @@
>  static cpumask_t mask_empty;
>  static cpumask_t mask_all;
>  
> +#define STR_MASK(m)			#m
> +#define TEST_CPUMASK_PRINT(test, mask)	\
> +	kunit_info(test, "%s = '%*pbl'\n", STR_MASK(mask), nr_cpumask_bits, cpumask_bits(mask))
> +
>  static void test_cpumask_weight(struct kunit *test)
>  {
>  	KUNIT_EXPECT_TRUE(test, cpumask_empty(&mask_empty));
> @@ -103,6 +107,9 @@ static void test_cpumask_iterators_builtin(struct kunit *test)
>  	/* Ensure the dynamic masks are stable while running the tests */
>  	cpu_hotplug_disable();
>  
> +	TEST_CPUMASK_PRINT(test, cpu_online_mask);
> +	TEST_CPUMASK_PRINT(test, cpu_present_mask);
> +
>  	EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, online);
>  	EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, present);
>  
> @@ -114,6 +121,9 @@ static int test_cpumask_init(struct kunit *test)
>  	cpumask_clear(&mask_empty);
>  	cpumask_setall(&mask_all);
>  
> +	TEST_CPUMASK_PRINT(test, &mask_all);
> +	TEST_CPUMASK_PRINT(test, cpu_possible_mask);
> +

It sort of breaks the rule of silence. Can you make this print conditional
on a test failure? If everything is OK, who wants to look into details? 

>  	return 0;
>  }
>  
> -- 
> 2.37.2
Sander Vanheule Aug. 21, 2022, 1:13 p.m. UTC | #2 
On Sat, 2022-08-20 at 14:46 -0700, Yury Norov wrote:
> On Sat, Aug 20, 2022 at 05:03:12PM +0200, Sander Vanheule wrote:
> > For extra context, log the contents of the masks under test.  This
> > should help with finding out why a certain test fails.
> > 
> > Link:
> > https://lore.kernel.org/lkml/CABVgOSkPXBc-PWk1zBZRQ_Tt+Sz1ruFHBj3ixojymZF=Vi4tpQ@mail.gmail.com/
> > Suggested-by: David Gow <davidgow@google.com>
> > Signed-off-by: Sander Vanheule <sander@svanheule.net>
> > Reviewed-by: David Gow <davidgow@google.com>
> > ---
> >  lib/cpumask_kunit.c | 10 ++++++++++
> >  1 file changed, 10 insertions(+)
> > 
> > diff --git a/lib/cpumask_kunit.c b/lib/cpumask_kunit.c
> > index 4d353614d853..0f8059a5e93b 100644
> > --- a/lib/cpumask_kunit.c
> > +++ b/lib/cpumask_kunit.c
> > @@ -51,6 +51,10 @@
> >  static cpumask_t mask_empty;
> >  static cpumask_t mask_all;
> >  
> > +#define STR_MASK(m)                    #m
> > +#define TEST_CPUMASK_PRINT(test, mask) \
> > +       kunit_info(test, "%s = '%*pbl'\n", STR_MASK(mask), nr_cpumask_bits,
> > cpumask_bits(mask))
> > +
> >  static void test_cpumask_weight(struct kunit *test)
> >  {
> >         KUNIT_EXPECT_TRUE(test, cpumask_empty(&mask_empty));
> > @@ -103,6 +107,9 @@ static void test_cpumask_iterators_builtin(struct kunit
> > *test)
> >         /* Ensure the dynamic masks are stable while running the tests */
> >         cpu_hotplug_disable();
> >  
> > +       TEST_CPUMASK_PRINT(test, cpu_online_mask);
> > +       TEST_CPUMASK_PRINT(test, cpu_present_mask);
> > +
> >         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, online);
> >         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, present);
> >  
> > @@ -114,6 +121,9 @@ static int test_cpumask_init(struct kunit *test)
> >         cpumask_clear(&mask_empty);
> >         cpumask_setall(&mask_all);
> >  
> > +       TEST_CPUMASK_PRINT(test, &mask_all);
> > +       TEST_CPUMASK_PRINT(test, cpu_possible_mask);
> > +
> 
> It sort of breaks the rule of silence. Can you make this print conditional
> on a test failure? If everything is OK, who wants to look into details? 

I will change the macros to the _MSG versions, and log the mask there.

I implemented this with kunit_info() as David proposed. AFAICT I can't call 
kunit_info() only when the test fails, because the EXPECT_ macros don't return
any result.

Best,
Sander

> 
> >         return 0;
> >  }
> >  
> > -- 
> > 2.37.2
Maíra Canal Aug. 21, 2022, 2:02 p.m. UTC | #3 
On 8/21/22 10:13, Sander Vanheule wrote:
> On Sat, 2022-08-20 at 14:46 -0700, Yury Norov wrote:
>> On Sat, Aug 20, 2022 at 05:03:12PM +0200, Sander Vanheule wrote:
>>> For extra context, log the contents of the masks under test.  This
>>> should help with finding out why a certain test fails.
>>>
>>> Link:
>>> https://lore.kernel.org/lkml/CABVgOSkPXBc-PWk1zBZRQ_Tt+Sz1ruFHBj3ixojymZF=Vi4tpQ@mail.gmail.com/
>>> Suggested-by: David Gow <davidgow@google.com>
>>> Signed-off-by: Sander Vanheule <sander@svanheule.net>
>>> Reviewed-by: David Gow <davidgow@google.com>
>>> ---
>>>  lib/cpumask_kunit.c | 10 ++++++++++
>>>  1 file changed, 10 insertions(+)
>>>
>>> diff --git a/lib/cpumask_kunit.c b/lib/cpumask_kunit.c
>>> index 4d353614d853..0f8059a5e93b 100644
>>> --- a/lib/cpumask_kunit.c
>>> +++ b/lib/cpumask_kunit.c
>>> @@ -51,6 +51,10 @@
>>>  static cpumask_t mask_empty;
>>>  static cpumask_t mask_all;
>>>  
>>> +#define STR_MASK(m)                    #m
>>> +#define TEST_CPUMASK_PRINT(test, mask) \
>>> +       kunit_info(test, "%s = '%*pbl'\n", STR_MASK(mask), nr_cpumask_bits,
>>> cpumask_bits(mask))
>>> +
>>>  static void test_cpumask_weight(struct kunit *test)
>>>  {
>>>         KUNIT_EXPECT_TRUE(test, cpumask_empty(&mask_empty));
>>> @@ -103,6 +107,9 @@ static void test_cpumask_iterators_builtin(struct kunit
>>> *test)
>>>         /* Ensure the dynamic masks are stable while running the tests */
>>>         cpu_hotplug_disable();
>>>  
>>> +       TEST_CPUMASK_PRINT(test, cpu_online_mask);
>>> +       TEST_CPUMASK_PRINT(test, cpu_present_mask);
>>> +
>>>         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, online);
>>>         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, present);
>>>  
>>> @@ -114,6 +121,9 @@ static int test_cpumask_init(struct kunit *test)
>>>         cpumask_clear(&mask_empty);
>>>         cpumask_setall(&mask_all);
>>>  
>>> +       TEST_CPUMASK_PRINT(test, &mask_all);
>>> +       TEST_CPUMASK_PRINT(test, cpu_possible_mask);
>>> +
>>
>> It sort of breaks the rule of silence. Can you make this print conditional
>> on a test failure? If everything is OK, who wants to look into details? 
> 
> I will change the macros to the _MSG versions, and log the mask there.
> 
> I implemented this with kunit_info() as David proposed. AFAICT I can't call 
> kunit_info() only when the test fails, because the EXPECT_ macros don't return
> any result.

Maybe you can use KUNIT_EXPECT_EQ_MSG to print a more detailed error and
avoid printing the info when the test doesn't fail.

Best Regards,
- Maíra Canal

> 
> Best,
> Sander
> 
>>
>>>         return 0;
>>>  }
>>>  
>>> -- 
>>> 2.37.2
>
Sander Vanheule Aug. 21, 2022, 4:39 p.m. UTC | #4 
Hi Maíra,

On Sun, 2022-08-21 at 11:02 -0300, Maíra Canal wrote:
> 
> 
> On 8/21/22 10:13, Sander Vanheule wrote:
> > On Sat, 2022-08-20 at 14:46 -0700, Yury Norov wrote:
> > > On Sat, Aug 20, 2022 at 05:03:12PM +0200, Sander Vanheule wrote:
> > > > For extra context, log the contents of the masks under test.  This
> > > > should help with finding out why a certain test fails.
> > > > 
> > > > Link:
> > > > https://lore.kernel.org/lkml/CABVgOSkPXBc-PWk1zBZRQ_Tt+Sz1ruFHBj3ixojymZF=Vi4tpQ@mail.gmail.com/
> > > > Suggested-by: David Gow <davidgow@google.com>
> > > > Signed-off-by: Sander Vanheule <sander@svanheule.net>
> > > > Reviewed-by: David Gow <davidgow@google.com>
> > > > ---
> > > >  lib/cpumask_kunit.c | 10 ++++++++++
> > > >  1 file changed, 10 insertions(+)
> > > > 
> > > > diff --git a/lib/cpumask_kunit.c b/lib/cpumask_kunit.c
> > > > index 4d353614d853..0f8059a5e93b 100644
> > > > --- a/lib/cpumask_kunit.c
> > > > +++ b/lib/cpumask_kunit.c
> > > > @@ -51,6 +51,10 @@
> > > >  static cpumask_t mask_empty;
> > > >  static cpumask_t mask_all;
> > > >  
> > > > +#define STR_MASK(m)                    #m
> > > > +#define TEST_CPUMASK_PRINT(test, mask) \
> > > > +       kunit_info(test, "%s = '%*pbl'\n", STR_MASK(mask),
> > > > nr_cpumask_bits,
> > > > cpumask_bits(mask))
> > > > +
> > > >  static void test_cpumask_weight(struct kunit *test)
> > > >  {
> > > >         KUNIT_EXPECT_TRUE(test, cpumask_empty(&mask_empty));
> > > > @@ -103,6 +107,9 @@ static void test_cpumask_iterators_builtin(struct
> > > > kunit
> > > > *test)
> > > >         /* Ensure the dynamic masks are stable while running the tests
> > > > */
> > > >         cpu_hotplug_disable();
> > > >  
> > > > +       TEST_CPUMASK_PRINT(test, cpu_online_mask);
> > > > +       TEST_CPUMASK_PRINT(test, cpu_present_mask);
> > > > +
> > > >         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, online);
> > > >         EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, present);
> > > >  
> > > > @@ -114,6 +121,9 @@ static int test_cpumask_init(struct kunit *test)
> > > >         cpumask_clear(&mask_empty);
> > > >         cpumask_setall(&mask_all);
> > > >  
> > > > +       TEST_CPUMASK_PRINT(test, &mask_all);
> > > > +       TEST_CPUMASK_PRINT(test, cpu_possible_mask);
> > > > +
> > > 
> > > It sort of breaks the rule of silence. Can you make this print conditional
> > > on a test failure? If everything is OK, who wants to look into details? 
> > 
> > I will change the macros to the _MSG versions, and log the mask there.
> > 
> > I implemented this with kunit_info() as David proposed. AFAICT I can't call 
> > kunit_info() only when the test fails, because the EXPECT_ macros don't
> > return
> > any result.
> 
> Maybe you can use KUNIT_EXPECT_EQ_MSG to print a more detailed error and
> avoid printing the info when the test doesn't fail.

Yes, this is what I currently have for use with the _MSG() variants of the
macros:

+#define MASK_MSG(m)                    \
+       "%s contains %sCPUs %*pbl", #m, (cpumask_weight(m) ? "" : "no "), nr_cpumask_bits, cpumask_bits(m)
+

For example, with (bogus) KUNIT_EXPECT_TRUE_MSG(test, ..., MASK_MSG(mask)) this
becomes (trimmed):

$ ./tools/testing/kunit/kunit.py run  --build_dir=build-um cpumask
[...]
[18:15:33] # test_cpumask_weight: EXPECTATION FAILED at lib/cpumask_kunit.c:60
[18:15:33] Expected cpumask_empty(((struct cpumask *)(1 ? (cpu_all_bits) : (void *)sizeof(__check_is_bitmap(cpu_all_bits))))) to be true, but is false
[18:15:33] 
[18:15:33] cpu_all_mask contains CPUs 0
[18:15:33] # test_cpumask_weight: EXPECTATION FAILED at lib/cpumask_kunit.c:61
[18:15:33] Expected cpumask_full(&mask_empty) to be true, but is false
[18:15:33] 
[18:15:33] &mask_empty contains no CPUs
[18:15:33] not ok 1 - test_cpumask_weight
[18:15:33] [FAILED] test_cpumask_weight
[...]

Or on a real system:
[    1.246805]     # test_cpumask_weight: EXPECTATION FAILED at lib/cpumask_kunit.c:59
[    1.246805]     Expected cpumask_empty(((struct cpumask *)(1 ? (cpu_all_bits) : (void *)sizeof(__check_is_bitmap(cpu_all_bits))))) to be true, but is false
[    1.246805] 
[    1.246805] cpu_all_mask contains CPUs 0-1
[    1.249756]     not ok 1 - test_cpumask_weight

I will send an updated series tomorrow, in case David or others have more more comments.

Best,
Sander
diff mbox series

Patch

diff --git a/lib/cpumask_kunit.c b/lib/cpumask_kunit.c
index 4d353614d853..0f8059a5e93b 100644
--- a/lib/cpumask_kunit.c
+++ b/lib/cpumask_kunit.c
@@ -51,6 +51,10 @@ 
 static cpumask_t mask_empty;
 static cpumask_t mask_all;
 
+#define STR_MASK(m)			#m
+#define TEST_CPUMASK_PRINT(test, mask)	\
+	kunit_info(test, "%s = '%*pbl'\n", STR_MASK(mask), nr_cpumask_bits, cpumask_bits(mask))
+
 static void test_cpumask_weight(struct kunit *test)
 {
 	KUNIT_EXPECT_TRUE(test, cpumask_empty(&mask_empty));
@@ -103,6 +107,9 @@  static void test_cpumask_iterators_builtin(struct kunit *test)
 	/* Ensure the dynamic masks are stable while running the tests */
 	cpu_hotplug_disable();
 
+	TEST_CPUMASK_PRINT(test, cpu_online_mask);
+	TEST_CPUMASK_PRINT(test, cpu_present_mask);
+
 	EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, online);
 	EXPECT_FOR_EACH_CPU_BUILTIN_EQ(test, present);
 
@@ -114,6 +121,9 @@  static int test_cpumask_init(struct kunit *test)
 	cpumask_clear(&mask_empty);
 	cpumask_setall(&mask_all);
 
+	TEST_CPUMASK_PRINT(test, &mask_all);
+	TEST_CPUMASK_PRINT(test, cpu_possible_mask);
+
 	return 0;
 }