[PATCH 1/2] perf test shell trace_exit_race: Show what went wrong in verbose mode

Arnaldo Carvalho de Melo posted 2 patches 1 week, 3 days ago
[PATCH 1/2] perf test shell trace_exit_race: Show what went wrong in verbose mode
Posted by Arnaldo Carvalho de Melo 1 week, 3 days ago
From: Arnaldo Carvalho de Melo <acme@redhat.com>

If it fails we need to check what was the reason, what were the lines
that didn't match the expected format, so:

  root@number:~# perf test -v "trace exit race"
  --- start ---
  test child forked, pid 2028724
  Lines not matching the expected regexp: ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$':
       0.000 :2028750/2028750 syscalls:sys_enter_exit_group()
  ---- end(-1) ----
  110: perf trace exit race                                            : FAILED!
  root@number:~#

In this case we're not resolving the process COMM for some reason and
fallback to printing just the pid/tid, this will be fixed in a followup
patch.

Howard Chu spotted a problem with single code surrounding a regexp, that
made the test always fail, but since there were some failures when I
tested (COMM not being resolved in some of the results) the end inverse
grep would show some lines and thus didn't notice the single quote
problem.

He also provided a patch to test if less than the number of expected
matches took place but all of them with the expected output, in which
case the inverse grep wouldn't show anything, confusing the tester.

Reviewed-by: Howard Chu <howardchu95@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Benjamin Peterson <benjamin@engflow.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Kan Liang <kan.liang@linux.intel.com>
Cc: Mark Rutland <mark.rutland@arm.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: https://lore.kernel.org/lkml/ZzdknoHqrJbojb6P@x1
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/tests/shell/trace_exit_race.sh | 24 +++++++++++++++++++++--
 1 file changed, 22 insertions(+), 2 deletions(-)

diff --git a/tools/perf/tests/shell/trace_exit_race.sh b/tools/perf/tests/shell/trace_exit_race.sh
index 3cf2d71a5c3b9278..8ea24f4256bc8f5e 100755
--- a/tools/perf/tests/shell/trace_exit_race.sh
+++ b/tools/perf/tests/shell/trace_exit_race.sh
@@ -11,11 +11,19 @@
 
 skip_if_no_perf_trace || exit 2
 
+if [ "$1" = "-v" ]; then
+	verbose="1"
+fi
+
+iter=10
+regexp=" +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$"
+
 trace_shutdown_race() {
-	for _ in $(seq 10); do
+	for _ in $(seq $iter); do
 		perf trace -e syscalls:sys_enter_exit_group true 2>>$file
 	done
-	[ "$(grep -c -E ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$' $file)" = "10" ]
+	result="$(grep -c -E "$regexp" $file)"
+	[ $result = $iter ]
 }
 
 
@@ -27,5 +35,17 @@ export PERF_CONFIG=/dev/null
 
 trace_shutdown_race
 err=$?
+
+if [ $err != 0 ] && [ "${verbose}" = "1" ]; then
+	lines_not_matching=$(mktemp /tmp/temporary_file.XXXXX)
+	if grep -v -E "$regexp" $file > $lines_not_matching ; then
+		echo "Lines not matching the expected regexp: '$regexp':"
+		cat $lines_not_matching
+	else
+		echo "Missing output, expected $iter but only got $result"
+	fi
+	rm -f $lines_not_matching
+fi
+
 rm -f ${file}
 exit $err
-- 
2.47.0
Re: [PATCH 1/2] perf test shell trace_exit_race: Show what went wrong in verbose mode
Posted by Howard Chu 1 week, 3 days ago
Hello Arnaldo,

On Fri, Nov 15, 2024 at 7:36 AM Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
>
> From: Arnaldo Carvalho de Melo <acme@redhat.com>
>
> If it fails we need to check what was the reason, what were the lines
> that didn't match the expected format, so:
>
>   root@number:~# perf test -v "trace exit race"
>   --- start ---
>   test child forked, pid 2028724
>   Lines not matching the expected regexp: ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$':
>        0.000 :2028750/2028750 syscalls:sys_enter_exit_group()
>   ---- end(-1) ----
>   110: perf trace exit race                                            : FAILED!
>   root@number:~#
>
> In this case we're not resolving the process COMM for some reason and
> fallback to printing just the pid/tid, this will be fixed in a followup
> patch.
>
> Howard Chu spotted a problem with single code surrounding a regexp, that
> made the test always fail, but since there were some failures when I
> tested (COMM not being resolved in some of the results) the end inverse
> grep would show some lines and thus didn't notice the single quote
> problem.
>
> He also provided a patch to test if less than the number of expected
> matches took place but all of them with the expected output, in which
> case the inverse grep wouldn't show anything, confusing the tester.
>
> Reviewed-by: Howard Chu <howardchu95@gmail.com>
> Cc: Adrian Hunter <adrian.hunter@intel.com>
> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Cc: Benjamin Peterson <benjamin@engflow.com>
> Cc: Ian Rogers <irogers@google.com>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Jiri Olsa <jolsa@kernel.org>
> Cc: Kan Liang <kan.liang@linux.intel.com>
> Cc: Mark Rutland <mark.rutland@arm.com>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Link: https://lore.kernel.org/lkml/ZzdknoHqrJbojb6P@x1
> Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> ---
>  tools/perf/tests/shell/trace_exit_race.sh | 24 +++++++++++++++++++++--
>  1 file changed, 22 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/tests/shell/trace_exit_race.sh b/tools/perf/tests/shell/trace_exit_race.sh
> index 3cf2d71a5c3b9278..8ea24f4256bc8f5e 100755
> --- a/tools/perf/tests/shell/trace_exit_race.sh
> +++ b/tools/perf/tests/shell/trace_exit_race.sh
> @@ -11,11 +11,19 @@
>
>  skip_if_no_perf_trace || exit 2
>
> +if [ "$1" = "-v" ]; then
> +       verbose="1"
> +fi
> +
> +iter=10
> +regexp=" +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$"
> +
>  trace_shutdown_race() {
> -       for _ in $(seq 10); do
> +       for _ in $(seq $iter); do
>                 perf trace -e syscalls:sys_enter_exit_group true 2>>$file
>         done
> -       [ "$(grep -c -E ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$' $file)" = "10" ]
> +       result="$(grep -c -E "$regexp" $file)"
> +       [ $result = $iter ]
>  }
>
>
> @@ -27,5 +35,17 @@ export PERF_CONFIG=/dev/null
>
>  trace_shutdown_race
>  err=$?
> +
> +if [ $err != 0 ] && [ "${verbose}" = "1" ]; then
> +       lines_not_matching=$(mktemp /tmp/temporary_file.XXXXX)
> +       if grep -v -E "$regexp" $file > $lines_not_matching ; then
> +               echo "Lines not matching the expected regexp: '$regexp':"
> +               cat $lines_not_matching
> +       else
> +               echo "Missing output, expected $iter but only got $result"
> +       fi
> +       rm -f $lines_not_matching
> +fi
> +
>  rm -f ${file}
>  exit $err

LGTM.

Thanks,
Howard

> --
> 2.47.0
>