| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <ZzZihs9AvoaJeerD@x1>
Date: Thu, 14 Nov 2024 17:50:14 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Benjamin Peterson <benjamin@...flow.com>
Cc: Peter Zijlstra <peterz@...radead.org>, Ingo Molnar <mingo@...hat.com>,
Namhyung Kim <namhyung@...nel.org>,
Mark Rutland <mark.rutland@....com>,
Alexander Shishkin <alexander.shishkin@...ux.intel.com>,
Jiri Olsa <jolsa@...nel.org>, Ian Rogers <irogers@...gle.com>,
Adrian Hunter <adrian.hunter@...el.com>,
"Liang, Kan" <kan.liang@...ux.intel.com>,
open list <linux-kernel@...r.kernel.org>,
"open list:PERFORMANCE EVENTS SUBSYSTEM" <linux-perf-users@...r.kernel.org>
Subject: Re: [PATCH 2/2] perf tests: add test for trace output loss
On Thu, Nov 14, 2024 at 05:09:17PM -0300, Arnaldo Carvalho de Melo wrote:
> On Thu, Nov 14, 2024 at 09:44:56AM -0800, Benjamin Peterson wrote:
> > > On Thu, Nov 14, 2024 at 02:37:52PM -0300, Arnaldo Carvalho de Melo wrote:
> > > diff --git a/tools/perf/tests/shell/trace_exit_race.sh b/tools/perf/tests/shell/trace_exit_race.sh
> > > index 8b70324bc5b4fb4c..c37ed6bb9f7e8fab 100755
> > > --- a/tools/perf/tests/shell/trace_exit_race.sh
> > > +++ b/tools/perf/tests/shell/trace_exit_race.sh
> > > @@ -12,10 +12,10 @@
> > > skip_if_no_perf_trace || exit 2
>
> > > trace_shutdown_race() {
> > > - for i in $(seq 100); do
> > > + for _ in $(seq 100); 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) = "100" ]
> > > + [ "$(grep -c -E ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$' $file)" = "100" ]
> > > }
>
> > This all looks okay.
>
> The test is failing for me as there is garbage in the output of perf
> trace even with Namhyung having already applied your previous patch:
>
> ⬢ [acme@...lbox perf-tools-next]$ git log --oneline --author benjamin@...flow.com
> 12bd434f68ea45c7 (HEAD -> perf-tools-next) perf tests: Add test for 'perf trace' output loss
> efbcd2cd7eac10a9 perf trace: Do not lose last events in a race
> 5fb8e56542a3cf46 (perf-tools-next/tmp.perf-tools-next) perf trace: avoid garbage when not printing a trace event's arguments
> ⬢ [acme@...lbox perf-tools-next]$
>
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982428 syscalls:sys_enter_exit_group( k?m)
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982430 syscalls:sys_enter_exit_group()
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982432 syscalls:sys_enter_exit_group()
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982434 syscalls:sys_enter_exit_group()
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982437 syscalls:sys_enter_exit_group( k�)
> root@...ber:~# perf trace -e syscalls:sys_enter_exit_group true
> 0.000 true/1982439 syscalls:sys_enter_exit_group(, loads 8��1)
> root@...ber:~#
>
> So we don't _miss_ the events, which I was noticing and brought me to
> test your latest 2 patches, which I applied and added a Tested-by, now
> tryint to figure out this garbage...
So, I fixed it with this simple patch:
And then, after adding this patch to the 'perf test' for the exit race
that you contributed:
⬢ [acme@...lbox perf-tools-next]$ git diff tools/perf/tests/
diff --git a/tools/perf/tests/shell/trace_exit_race.sh b/tools/perf/tests/shell/trace_exit_race.sh
index c37ed6bb9f7e8fab..2eb39abaadffc344 100755
--- a/tools/perf/tests/shell/trace_exit_race.sh
+++ b/tools/perf/tests/shell/trace_exit_race.sh
@@ -11,11 +11,17 @@
skip_if_no_perf_trace || exit 2
+if [ "$1" = "-v" ]; then
+ verbose="1"
+fi
+
+regexp=" +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$"
+
trace_shutdown_race() {
for _ in $(seq 100); 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)" = "100" ]
+ [ "$(grep -c -E '$regexp' $file)" = "100" ]
}
@@ -27,5 +33,11 @@ export PERF_CONFIG=/dev/null
trace_shutdown_race
err=$?
+
+if [ $err != 0 ] && [ "${verbose}" = "1" ]; then
+ echo "Lines not matching the expected regexp: '$regexp':"
+ grep -v -E "$regexp" $file
+fi
+
rm -f ${file}
exit $err
⬢ [acme@...lbox perf-tools-next]
⬢ [acme@...lbox perf-tools-next]$ git diff tools/perf/builtin-trace.c
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index ca5c3f5d6c389427..0834a11940c18f05 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2405,6 +2405,9 @@ static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
}
}
+ if (printed == 0)
+ bf[0] = '\0';
+
return printed;
}
⬢ [acme@...lbox perf-tools-next]$
The test still fails but for another reason:
root@...ber:~# perf test -v "trace exit race"
--- start ---
test child forked, pid 2002298
Lines not matching the expected regexp: ' +[0-9]+\.[0-9]+ +true/[0-9]+ syscalls:sys_enter_exit_group\(\)$':
0.000 :2002317/2002317 syscalls:sys_enter_exit_group()
0.000 :2002319/2002319 syscalls:sys_enter_exit_group()
0.000 :2002353/2002353 syscalls:sys_enter_exit_group()
0.000 :2002357/2002357 syscalls:sys_enter_exit_group()
0.000 :2002376/2002376 syscalls:sys_enter_exit_group()
0.000 :2002378/2002378 syscalls:sys_enter_exit_group()
0.000 :2002393/2002393 syscalls:sys_enter_exit_group()
0.000 :2002444/2002444 syscalls:sys_enter_exit_group()
0.000 :2002491/2002491 syscalls:sys_enter_exit_group()
0.000 :2002503/2002503 syscalls:sys_enter_exit_group()
---- end(-1) ----
110: perf trace exit race : FAILED!
root@...ber:~#
Somehow we're missing the PERF_RECORD_COMM or racing to get it from
/proc for those processes and thus we end up printing just the pid/ppid
Since what we are testing here is garbage when printing the argument
list, we can just disable comm printing and get consistent results:
root@...ber:~# perf trace --no-comm -e syscalls:sys_enter_exit_group true
0.000 2003312 syscalls:sys_enter_exit_group()
root@...ber:~#
I'll take this route and sent a patch series.
- Arnaldo
Powered by blists - more mailing lists