[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <ZuCrCRfUi6QiRV_3@x1>
Date: Tue, 10 Sep 2024 17:24:41 -0300
From: Arnaldo Carvalho de Melo <acme@...nel.org>
To: Thomas Richter <tmricht@...ux.ibm.com>
Cc: Heiko Carstens <hca@...ux.ibm.com>, Vasily Gorbik <gor@...ux.ibm.com>,
Alexander Gordeev <agordeev@...ux.ibm.com>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
linux-perf-users@...r.kernel.org,
Adrian Hunter <adrian.hunter@...el.com>,
Ian Rogers <irogers@...gle.com>, Jiri Olsa <jolsa@...nel.org>,
Kan Liang <kan.liang@...ux.intel.com>,
Namhyung Kim <namhyung@...nel.org>
Subject: Re: Linux next breaks s390 test cases perf test vfs_getname
On Tue, Sep 10, 2024 at 02:05:42PM +0200, Thomas Richter wrote:
> Arnaldo,
>
> On linux-next
> commit a68080e1a21b ("perf test vfs_getname: Look for alternative line where to collect the pathname")
> breaks the following tests on s390:
>
> # perf test vfs_getname
> 85: Add vfs_getname probe to get syscall args filenames : FAILED!
> 87: Use vfs_getname probe to get syscall args filenames : FAILED!
> 120: Check open filename arg using perf trace + vfs_getname : FAILED!
>
> I used the linux next kernel from yesterdays build on s390 and the corresponding
> perf tools also built from that kernel repository:
> # uname -a
> Linux a35lp62.lnxne.boe 6.11.0-20240909.rc7.git205.100cc857359b.300.fc40.s390x+next #1 SMP Mon Sep 9 20:05:44 CEST 2024 s390x GNU/Linux
> # perf -v
> perf version 6.11.0-20240909.rc7.git205.100cc857359b.300.fc40.s390x+next
> #
>
> The root cause is a changed regular expression. Before the change the command
> extracts this line and strips everything after the line number:
> # perf probe -L getname_flags 2>&1 | grep -E 'result.*=.*filename;'
> 79 result->uptr = filename;
> # perf probe -L getname_flags 2>&1 | grep -E 'result.*=.*filename;' | \
> sed -r 's/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*/\1/'
> 79
> # perf probe -q "vfs_getname=getname_flags:79 pathname=result->name:string"
> # echo $?
> 0
> # perf probe -l
> probe:vfs_getname (on getname_flags:79@...namei.c with pathname)
> # perf probe -d '*'
> Removed event: probe:vfs_getname
> #
>
> With your changes the result is slightly different. The first part still matches the
> same line:
> #perf probe -L getname_flags| grep -E '[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*='
> 79 result->uptr = filename;
> but the sed command does not return the proper line number:
> # perf probe -L getname_flags| grep -E '[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*=' | \
> sed -r "s/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*=/\1/"
> 79 filename;
> #
> The filename; is not stripped and the perf probe command looks like
> # perf probe -q "vfs_getname=getname_flags:79 filename; pathname=result->name:string"
> # echo $?
> 254
> # perf probe -l
> # perf probe "vfs_getname=getname_flags:79 filename; pathname=result->name:string"
> Failed to find the location of the 'filename;' variable at this address.
> Perhaps it has been optimized out.
> Use -V with the --range option to show 'filename;' location range.
> Error: Failed to add events.
> #
>
>
> The issue is that trailing equal sign (=) in the regular expression:
> + result_filename_re="[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*"
> + line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_filename_re=" | \
> sed -r "s/$result_filename_re=/\1/")
> ^--------here-----
> which prevents word filename; from being stripped away.
> I wonder if this works on x86_64 platforms and if we need a archtecture specific
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~#
root@x1:~# uname -a
Linux x1 6.10.8-200.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Wed Sep 4 21:41:11 UTC 2024 x86_64 GNU/Linux
root@x1:~#
I forgot to mention the kernel version wher I did that a68080e1a21b
patch, but IIRC it was a recent, locally built kernel (not a distro
kernel, but with the fedora, probably 39, config):
kernel="/boot/vmlinuz-6.11.0-rc5+"
But even with the distro kernel I'm getting the same results:
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~#
With my changes, i.e. what is in perf-tools-next now:
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E 'result.*=.*filename;'
result->uptr = filename;
root@x1:~#
So no line number to be found:
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E 'result.*=.*filename;'
perf probe -L getname_flags 2>&1 | grep -E 'result.*=.*filename;' | sed -r 's/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*/\1/'
result->uptr = filename;
root@x1:~#
Then, with the change in place:
The first part continues not to find the info:
root@x1:~# perf probe -L getname_flags| grep -E '[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*='
root@x1:~#
Then it falls back to the new way of finding where to put the probe:
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re="
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re"
73 result->aname = NULL;
root@x1:~#
Yeah, that = shouldn't be there
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re" | sed -r "s/$result_aname_re/\1/"
73
root@x1:~# line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re" | sed -r "s/$result_aname_re/\1/")
root@x1:~# echo $line
73
root@x1:~#
Can you try with the patch below, that ending '=' is noise :-\
- Arnaldo
>From 9ccaf9a0ebcff9b4c45c34d92ca97be9926da636 Mon Sep 17 00:00:00 2001
From: Arnaldo Carvalho de Melo <acme@...hat.com>
Date: Tue, 10 Sep 2024 17:18:26 -0300
Subject: [PATCH 1/1] perf test shell probe_vfs_getname: Remove extraneous '='
from probe line number regex
Thomas reported the vfs_getname perf tests failing on s/390, it seems it
was just to some extraneous '=' somehow getting into the regexp, remove
it, now:
root@x1:~# perf test getname
91: Add vfs_getname probe to get syscall args filenames : Ok
93: Use vfs_getname probe to get syscall args filenames : FAILED!
126: Check open filename arg using perf trace + vfs_getname : Ok
root@x1:~#
Second one remains a mistery, have to take some time to nail it down.
Testing it:
root@x1:~# uname -a
Linux x1 6.10.8-200.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Wed Sep 4 21:41:11 UTC 2024 x86_64 GNU/Linux
root@x1:~# result_aname_re="[[:space:]]+([[:digit:]]+)[[:space:]]+result->aname = NULL;"
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re" | sed -r "s/$result_aname_re/\1/"
73
root@x1:~# perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re"
73 result->aname = NULL;
root@x1:~# line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re" | sed -r "s/$result_aname_re/\1/")
eroot@x1:~#
root@x1:~# echo $line
73
root@x1:~#
Reported-by: Thomas Richter <tmricht@...ux.ibm.com>
Cc: Adrian Hunter <adrian.hunter@...el.com>
Cc: Alexander Gordeev <agordeev@...ux.ibm.com>
Cc: Heiko Carstens <hca@...ux.ibm.com>
Cc: Ian Rogers <irogers@...gle.com>
Cc: Jiri Olsa <jolsa@...nel.org>
Cc: Kan Liang <kan.liang@...ux.intel.com>
Cc: Namhyung Kim <namhyung@...nel.org>
Cc: Vasily Gorbik <gor@...ux.ibm.com>,
Signed-off-by: Arnaldo Carvalho de Melo <acme@...hat.com>
---
tools/perf/tests/shell/lib/probe_vfs_getname.sh | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
index 0606e693eb59c5e9..5c33ec7a5a63bdb3 100644
--- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
+++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
@@ -14,10 +14,10 @@ add_probe_vfs_getname() {
add_probe_verbose=$1
if [ $had_vfs_getname -eq 1 ] ; then
result_filename_re="[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*"
- line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_filename_re=" | sed -r "s/$result_filename_re=/\1/")
+ line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_filename_re" | sed -r "s/$result_filename_re/\1/")
if [ -z "$line" ] ; then
result_aname_re="[[:space:]]+([[:digit:]]+)[[:space:]]+result->aname = NULL;"
- line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re=" | sed -r "s/$result_aname_re=/\1/")
+ line=$(perf probe -L getname_flags 2>&1 | grep -E "$result_aname_re" | sed -r "s/$result_aname_re/\1/")
fi
perf probe -q "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
perf probe $add_probe_verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring"
--
2.46.0
Powered by blists - more mailing lists