[PATCH] kunit: log numbers in decimal and hex

[PATCH] kunit: log numbers in decimal and hex

[Mark Rutland]

When KUNIT_EXPECT_EQ() or KUNIT_ASSERT_EQ() log a failure, they log the
two values being compared, with numerical values logged in decimal.

In some cases, decimal output is painful to consume, and hexadecimal
output would be more helpful. For example, this is the case for tests
I'm currently developing for the arm64 insn encoding/decoding code,
where comparing two 32-bit instruction opcodes results in output such
as:

|  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
|  Expected obj_insn == gen_insn, but
|      obj_insn == 2332164128
|      gen_insn == 1258422304

To make this easier to consume, this patch logs the values in both
decimal and hexadecimal:

|  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
|  Expected obj_insn == gen_insn, but
|      obj_insn == 2332164128 (0x8b020020)
|      gen_insn == 1258422304 (0x4b020020)

As can be seen from the example, having hexadecimal makes it
significantly easier for a human to spot which specific bits are
incorrect.

Signed-off-by: Mark Rutland <mark.rutland@arm.com>
Cc: Brendan Higgins <brendan.higgins@linux.dev>
Cc: David Gow <davidgow@google.com>
Cc: linux-kselftest@vger.kernel.org
Cc: kunit-dev@googlegroups.com
---
 lib/kunit/assert.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/lib/kunit/assert.c b/lib/kunit/assert.c
index d00d6d181ee8..24dec5b48722 100644
--- a/lib/kunit/assert.c
+++ b/lib/kunit/assert.c
@@ -127,13 +127,15 @@ void kunit_binary_assert_format(const struct kunit_assert *assert,
 			  binary_assert->text->right_text);
 	if (!is_literal(stream->test, binary_assert->text->left_text,
 			binary_assert->left_value, stream->gfp))
-		string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld\n",
+		string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld (0x%llx)\n",
 				  binary_assert->text->left_text,
+				  binary_assert->left_value,
 				  binary_assert->left_value);
 	if (!is_literal(stream->test, binary_assert->text->right_text,
 			binary_assert->right_value, stream->gfp))
-		string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld",
+		string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld (0x%llx)",
 				  binary_assert->text->right_text,
+				  binary_assert->right_value,
 				  binary_assert->right_value);
 	kunit_assert_print_msg(message, stream);
 }
-- 
2.30.2

Re: [PATCH] kunit: log numbers in decimal and hex

[Daniel Latypov]

On Wed, Oct 5, 2022 at 10:52 AM Mark Rutland <mark.rutland@arm.com> wrote:
>
> When KUNIT_EXPECT_EQ() or KUNIT_ASSERT_EQ() log a failure, they log the
> two values being compared, with numerical values logged in decimal.
>
> In some cases, decimal output is painful to consume, and hexadecimal
> output would be more helpful. For example, this is the case for tests
> I'm currently developing for the arm64 insn encoding/decoding code,
> where comparing two 32-bit instruction opcodes results in output such
> as:
>
> |  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
> |  Expected obj_insn == gen_insn, but
> |      obj_insn == 2332164128
> |      gen_insn == 1258422304
>
> To make this easier to consume, this patch logs the values in both
> decimal and hexadecimal:
>
> |  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
> |  Expected obj_insn == gen_insn, but
> |      obj_insn == 2332164128 (0x8b020020)
> |      gen_insn == 1258422304 (0x4b020020)
>
> As can be seen from the example, having hexadecimal makes it
> significantly easier for a human to spot which specific bits are
> incorrect.
>
> Signed-off-by: Mark Rutland <mark.rutland@arm.com>
> Cc: Brendan Higgins <brendan.higgins@linux.dev>
> Cc: David Gow <davidgow@google.com>
> Cc: linux-kselftest@vger.kernel.org
> Cc: kunit-dev@googlegroups.com

Acked-by: Daniel Latypov <dlatypov@google.com>

This is definitely something that has irked me as well.

I vaguely feel like this can clutter up the output for things that are
just ints, e.g.
    Expected len == 0, but
        len == 2 (0x2)

But I can't think of any suggestions that are actually worth doing [1].
And since this feels like a common enough case, I don't think the
existing workarounds [2] are sufficiently ergonomic.

So I think always showing the hex makes sense.

[1]
E.g. only emitting hex when the number in question is >16, but that
feels too magic (also needs more if's).
E.g. adding in a macro argument/separate set of macros that always format in hex

[2] can use these to coerce hex output
         KUNIT_EXPECT_EQ_MSG(test, obj_insn, gen_insn, "obj=0x%llx, gen=0x%llx",
                             obj_insn, gen_insn);
         KUNIT_EXPECT_PTR_EQ(test, obj_insn, gen_insn);

Re: [PATCH] kunit: log numbers in decimal and hex

[David Gow]

On Thu, Oct 6, 2022 at 1:52 AM Mark Rutland <mark.rutland@arm.com> wrote:
>
> When KUNIT_EXPECT_EQ() or KUNIT_ASSERT_EQ() log a failure, they log the
> two values being compared, with numerical values logged in decimal.
>
> In some cases, decimal output is painful to consume, and hexadecimal
> output would be more helpful. For example, this is the case for tests
> I'm currently developing for the arm64 insn encoding/decoding code,
> where comparing two 32-bit instruction opcodes results in output such
> as:
>
> |  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
> |  Expected obj_insn == gen_insn, but
> |      obj_insn == 2332164128
> |      gen_insn == 1258422304
>
> To make this easier to consume, this patch logs the values in both
> decimal and hexadecimal:
>
> |  # test_insn_add_shifted_reg: EXPECTATION FAILED at arch/arm64/lib/test_insn.c:2791
> |  Expected obj_insn == gen_insn, but
> |      obj_insn == 2332164128 (0x8b020020)
> |      gen_insn == 1258422304 (0x4b020020)
>
> As can be seen from the example, having hexadecimal makes it
> significantly easier for a human to spot which specific bits are
> incorrect.
>
> Signed-off-by: Mark Rutland <mark.rutland@arm.com>
> Cc: Brendan Higgins <brendan.higgins@linux.dev>
> Cc: David Gow <davidgow@google.com>
> Cc: linux-kselftest@vger.kernel.org
> Cc: kunit-dev@googlegroups.com
> ---

Thanks very much: this will definitely be useful. I tend to agree with
Daniel that this could clutter things up a bit, but I think the other
options (a separate ASSERT_EQ_HEX() macro, or a heuristic to remove it
for, e.g., values <= 9) add more complexity than benefit there.

So let's go with this as-is.

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

Cheers,
-- David

>  lib/kunit/assert.c | 6 ++++--
>  1 file changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/lib/kunit/assert.c b/lib/kunit/assert.c
> index d00d6d181ee8..24dec5b48722 100644
> --- a/lib/kunit/assert.c
> +++ b/lib/kunit/assert.c
> @@ -127,13 +127,15 @@ void kunit_binary_assert_format(const struct kunit_assert *assert,
>                           binary_assert->text->right_text);
>         if (!is_literal(stream->test, binary_assert->text->left_text,
>                         binary_assert->left_value, stream->gfp))
> -               string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld\n",
> +               string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld (0x%llx)\n",
>                                   binary_assert->text->left_text,
> +                                 binary_assert->left_value,
>                                   binary_assert->left_value);
>         if (!is_literal(stream->test, binary_assert->text->right_text,
>                         binary_assert->right_value, stream->gfp))
> -               string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld",
> +               string_stream_add(stream, KUNIT_SUBSUBTEST_INDENT "%s == %lld (0x%llx)",
>                                   binary_assert->text->right_text,
> +                                 binary_assert->right_value,
>                                   binary_assert->right_value);
>         kunit_assert_print_msg(message, stream);
>  }
> --
> 2.30.2
>