[PATCH net-next v2] selftests: net: ksft: print more of the stack for checks

[PATCH net-next v2] selftests: net: ksft: print more of the stack for checks

[Jakub Kicinski]

Print more stack frames and the failing line when check fails.
This helps when tests use helpers to do the checks.

Before:

  # At ./ksft/drivers/net/hw/rss_ctx.py line 92:
  # Check failed 1037698 >= 396893.0 traffic on other queues:[344612, 462380, 233020, 449174, 342298]
  not ok 8 rss_ctx.test_rss_context_queue_reconfigure

After:

  # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 387, in test_rss_context_queue_reconfigure:
  # Check|     test_rss_queue_reconfigure(cfg, main_ctx=False)
  # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 230, in test_rss_queue_reconfigure:
  # Check|     _send_traffic_check(cfg, port, ctx_ref, { 'target': (0, 3),
  # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 92, in _send_traffic_check:
  # Check|     ksft_lt(sum(cnts[i] for i in params['noise']), directed / 2,
  # Check failed 1045235 >= 405823.5 traffic on other queues (context 1)':[460068, 351995, 565970, 351579, 127270]
  not ok 8 rss_ctx.test_rss_context_queue_reconfigure

Signed-off-by: Jakub Kicinski <kuba@kernel.org>
---
v2:
 - use Stan's iteration suggestion
v1: https://lore.kernel.org/all/20240729204536.3637577-1-kuba@kernel.org/

CC: shuah@kernel.org
CC: petrm@nvidia.com
---
 tools/testing/selftests/net/lib/py/ksft.py | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

diff --git a/tools/testing/selftests/net/lib/py/ksft.py b/tools/testing/selftests/net/lib/py/ksft.py
index f26c20df9db4..707e0dfc7b9d 100644
--- a/tools/testing/selftests/net/lib/py/ksft.py
+++ b/tools/testing/selftests/net/lib/py/ksft.py
@@ -32,8 +32,15 @@ KSFT_RESULT_ALL = True
     global KSFT_RESULT
     KSFT_RESULT = False
 
-    frame = inspect.stack()[2]
-    ksft_pr("At " + frame.filename + " line " + str(frame.lineno) + ":")
+    stack = inspect.stack()
+    started = False
+    for frame in reversed(stack[2:]):
+        if not started:
+            started |= frame.function == 'ksft_run'
+            continue
+        ksft_pr("Check| At " + frame.filename + ", line " + str(frame.lineno) +
+                ", in " + frame.function + ":")
+        ksft_pr("Check|     " + frame.code_context[0].strip())
     ksft_pr(*args)
 
 
-- 
2.45.2

Re: [PATCH net-next v2] selftests: net: ksft: print more of the stack for checks

[Petr Machata]

Jakub Kicinski <kuba@kernel.org> writes:

> Print more stack frames and the failing line when check fails.
> This helps when tests use helpers to do the checks.
>
> Before:
>
>   # At ./ksft/drivers/net/hw/rss_ctx.py line 92:
>   # Check failed 1037698 >= 396893.0 traffic on other queues:[344612, 462380, 233020, 449174, 342298]
>   not ok 8 rss_ctx.test_rss_context_queue_reconfigure
>
> After:
>
>   # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 387, in test_rss_context_queue_reconfigure:
>   # Check|     test_rss_queue_reconfigure(cfg, main_ctx=False)
>   # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 230, in test_rss_queue_reconfigure:
>   # Check|     _send_traffic_check(cfg, port, ctx_ref, { 'target': (0, 3),
>   # Check| At ./ksft/drivers/net/hw/rss_ctx.py, line 92, in _send_traffic_check:
>   # Check|     ksft_lt(sum(cnts[i] for i in params['noise']), directed / 2,
>   # Check failed 1045235 >= 405823.5 traffic on other queues (context 1)':[460068, 351995, 565970, 351579, 127270]
>   not ok 8 rss_ctx.test_rss_context_queue_reconfigure
>
> Signed-off-by: Jakub Kicinski <kuba@kernel.org>

Reviewed-by: Petr Machata <petrm@nvidia.com>

> diff --git a/tools/testing/selftests/net/lib/py/ksft.py b/tools/testing/selftests/net/lib/py/ksft.py
> index f26c20df9db4..707e0dfc7b9d 100644
> --- a/tools/testing/selftests/net/lib/py/ksft.py
> +++ b/tools/testing/selftests/net/lib/py/ksft.py
> @@ -32,8 +32,15 @@ KSFT_RESULT_ALL = True
>      global KSFT_RESULT
>      KSFT_RESULT = False
>  
> -    frame = inspect.stack()[2]
> -    ksft_pr("At " + frame.filename + " line " + str(frame.lineno) + ":")
> +    stack = inspect.stack()
> +    started = False
> +    for frame in reversed(stack[2:]):
> +        if not started:
> +            started |= frame.function == 'ksft_run'

Hmm, using bitwise operations on booleans is somewhat unusual in Python
I think, especially if here the short-circuiting of "or" wouldn't be a
problem. But it doesn't degrade to integers so I guess it's well-defined.

> +            continue
> +        ksft_pr("Check| At " + frame.filename + ", line " + str(frame.lineno) +
> +                ", in " + frame.function + ":")
> +        ksft_pr("Check|     " + frame.code_context[0].strip())
>      ksft_pr(*args)

Re: [PATCH net-next v2] selftests: net: ksft: print more of the stack for checks

[Jakub Kicinski]

On Wed, 31 Jul 2024 13:07:26 +0200 Petr Machata wrote:
> > +            started |= frame.function == 'ksft_run'  
> 
> Hmm, using bitwise operations on booleans is somewhat unusual in Python
> I think, especially if here the short-circuiting of "or" wouldn't be a
> problem. But it doesn't degrade to integers so I guess it's well-defined.

Right, I thought the automatic conversions to booleans are sometimes
considered in poor taste in Python, but wasn't aware that bitwise ops
may be frowned upon. IIUC the alternative would be:

	if frame.function == 'ksft_run':
		started = True

or

	started = started or frame.function == 'ksft_run'

or another way?

Re: [PATCH net-next v2] selftests: net: ksft: print more of the stack for checks

[Petr Machata]

Jakub Kicinski <kuba@kernel.org> writes:

> On Wed, 31 Jul 2024 13:07:26 +0200 Petr Machata wrote:
>> > +            started |= frame.function == 'ksft_run'  
>> 
>> Hmm, using bitwise operations on booleans is somewhat unusual in Python
>> I think, especially if here the short-circuiting of "or" wouldn't be a
>> problem. But it doesn't degrade to integers so I guess it's well-defined.
>
> Right, I thought the automatic conversions to booleans are sometimes
> considered in poor taste in Python, but wasn't aware that bitwise ops
> may be frowned upon. IIUC the alternative would be:

FWIW I checked with a proper Pythonist in the meantime, and it's not
just me :)

Also, it's not bitwise ops per se. When doing bit twiddling on integrals
it would be totally legit. It's the part where we are dealing with
booleans that makes it unfashionable.

>
> 	if frame.function == 'ksft_run':
> 		started = True
>
> or
>
> 	started = started or frame.function == 'ksft_run'

I'd prefer the former.