Re: [PATCH v2] perf test shell: Fix check open filename arg using 'perf trace

[Michael Petlan <mpetlan@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 3314 bytes --]

On Mon, 11 Dec 2017, Arnaldo Carvalho de Melo wrote:
> It is not working here:

Hmm, I think I got it.

The following construction:

evts=`perf list syscalls:sys_enter_open* |& egrep 'open(at)? ' | sed -r 's/.*sys_enter_(.*) +\[.*/-e \1/'`

... expands to:

"-e open -e openat"

... which is a format that perf-trace does not seem to accept.
It simply overrides the first event with the second, thus it
only traces "openat". It worked for me, since I tested it on
aarch64 where $evts expanded to only one "-e" parameter.

Attaching a patch for perf-trace that should address it. It
seems to work, so perf-trace accepts "-e open -e openat".
However, one weak point is there:

"-e open,openat -e stat" works, while
"-e open -e openat,stat" does not.

In case you don't like the patch for perf-trace, the test's
patch would need to expand events to something else (which is
of course possible).

Also, on my system (x86_64, 4.15.0-rc1), I needed another
patch for the test (perf_test_shell_fix_filename_arg.patch),
because the variable name changed...

> [root@jouet mnt]# perf test -v 62
> 62: Check open filename arg using perf trace + vfs_getname:
> --- start ---
> test child forked, pid 4919
> Added new event:
>   probe:vfs_getname    (on getname_flags:72 with pathname=result->name:string)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:vfs_getname -aR sleep 1
> 
> test child finished with -1
> ---- end ----
> Check open filename arg using perf trace + vfs_getname: FAILED!
> [root@jouet mnt]#
> 
> and when I run this with strace -e open to see if it is picking the
> right script, it is:
> 
> open("/home/acme/libexec/perf-core/tests/shell/record+script_probe_vfs_getname.sh", O_RDONLY) = 4
> open("/home/acme/libexec/perf-core/tests/shell/trace+probe_libc_inet_pton.sh", O_RDONLY) = 4
> open("/home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh", O_RDONLY) = 4
> 62: Check open filename arg using perf trace + vfs_getname:
> --- start ---
> test child forked, pid 4947
> Added new event:
>   probe:vfs_getname    (on getname_flags:72 with pathname=result->name:string)
> 
> You can now use it in all perf tools, such as:
> 
> 	perf record -e probe:vfs_getname -aR sleep 1
> 
> --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=4947, si_uid=0, si_status=255, si_utime=0, si_stime=0} ---
> test child finished with -1
> ---- end ----
> Check open filename arg using perf trace + vfs_getname: FAILED!
> open("/home/acme/libexec/perf-core/tests/shell/probe_vfs_getname.sh", O_RDONLY) = 4
> +++ exited with 0 +++
> [root@jouet mnt]# 
> 
> [acme@jouet linux]$ diff -u /home/acme/libexec/perf-core/tests/shell/probe_vfs_getname.sh tools/perf/tests/shell/probe_vfs_getname.sh 
> [acme@jouet linux]$ git log --oneline -1
> 0553ba305e4e (HEAD -> perf/core) perf test shell: Fix check open filename arg using 'perf trace
> [acme@jouet linux]$ 
> 
> So can you please check if the file you're using is the one in this
> patch submission?

So attaching all three patches to be sure. I have tested them on
two environments:

  * x86_64 with 4.15.0-rc1
  * aarch64 with 4.14.0

Both work with all three patches applied, applying on perf/core's
head (commit 26ea2ece7802f8fdaaacf321dbfb22de3271ab82).

> 
> - Arnaldo
> 

Thanks for your patience :)

Cheers,
Michael

[-- Attachment #2: Type: text/plain, Size: 1899 bytes --]

commit b8abd0f49d680c9f943ac460a5eba291424bb6d0
Author: Michael Petlan <mpetlan@redhat.com>
Date:   Tue Dec 12 03:43:11 2017 +0100

    perf trace: support multiple -e arguments
    
    Other perf subcommands, such as perf-stat allow multiple event specification
    arguments, like "perf stat -e evt1 -e evt2 ...".
    
    This patch enables perf-trace to allow that too.
    
    Before:
         0.030 ( 0.004 ms): true/19173 close(fd: 3) = 0
         0.089 ( 0.007 ms): true/19173 close(fd: 3) = 0
    
    After:
         0.018 ( 0.013 ms): true/19175 open(filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
         0.040 ( 0.004 ms): true/19175 close(fd: 3</etc/ld.so.cache>) = 0
         0.053 ( 0.014 ms): true/19175 open(filename: /lib64/libc.so.6, flags: CLOEXEC) = 3
         0.107 ( 0.006 ms): true/19175 close(fd: 3</lib64/libc.so.6>) = 0
    
    Signed-off-by: Michael Petlan <mpetlan@redhat.com>

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 7c57898..abcfdcc 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -2935,10 +2935,18 @@ static int trace__parse_events_option(const struct option *opt, const char *str,
 			.dirname = strace_groups_dir,
 		};
 
-		trace->ev_qualifier = strlist__new(lists[1], &slist_config);
 		if (trace->ev_qualifier == NULL) {
-			fputs("Not enough memory to parse event qualifier", trace->output);
-			goto out;
+			trace->ev_qualifier = strlist__new(lists[1], &slist_config);
+			if (trace->ev_qualifier == NULL) {
+				fputs("Not enough memory to parse event qualifier", trace->output);
+				goto out;
+			}
+		} else {
+			int rv = strlist__add(trace->ev_qualifier, lists[1]);
+			if (rv != 0) {
+				fputs("A problem occurred when parsing event qualifier", trace->output);
+				goto out;
+			}
 		}
 
 		if (trace__validate_ev_qualifier(trace))

[-- Attachment #3: Type: text/plain, Size: 691 bytes --]

diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
index 30a950c..3759582 100644
--- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
+++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
@@ -13,7 +13,7 @@ add_probe_vfs_getname() {
 	local verbose=$1
 	if [ $had_vfs_getname -eq 1 ] ; then
 		line=$(perf probe -L getname_flags 2>&1 | egrep 'result.*=.*filename;' | sed -r 's/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*/\1/')
-		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=result->name:string"
+		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
 	fi
 }
 

[-- Attachment #4: Type: text/plain, Size: 1785 bytes --]

commit 92281a9ff73f98d8aca7595504340a25c92b9f1a
Author: Michael Petlan <mpetlan@redhat.com>
Date:   Fri Dec 8 18:43:18 2017 +0100

    perf test shell: Fix check open filename arg using 'perf trace'
    
    The following commit added an exception for s390x to use openat()
    instead of open() in the test:
    
      commit f231af789b11a2f1a3795acc3228a3e178a80c21
      Author: Thomas Richter <tmricht@linux.vnet.ibm.com>
      Date:   Tue Nov 14 08:18:46 2017 +0100
    
    Since the problem is not s390x-specific, this patch makes it more
    generic, so the test handles both open() and openat() no matter
    which architecture it is running on.
    
    Signed-off-by: Michael Petlan <mpetlan@redhat.com>

diff --git a/tools/perf/tests/shell/trace+probe_vfs_getname.sh b/tools/perf/tests/shell/trace+probe_vfs_getname.sh
index 2a9ef08..edd1073 100755
--- a/tools/perf/tests/shell/trace+probe_vfs_getname.sh
+++ b/tools/perf/tests/shell/trace+probe_vfs_getname.sh
@@ -17,10 +17,9 @@ skip_if_no_perf_probe || exit 2
 file=$(mktemp /tmp/temporary_file.XXXXX)
 
 trace_open_vfs_getname() {
-	test "$(uname -m)" = s390x && { svc="openat"; txt="dfd: +CWD, +"; }
-
-	perf trace -e ${svc:-open} touch $file 2>&1 | \
-	egrep " +[0-9]+\.[0-9]+ +\( +[0-9]+\.[0-9]+ ms\): +touch\/[0-9]+ ${svc:-open}\(${txt}filename: +${file}, +flags: CREAT\|NOCTTY\|NONBLOCK\|WRONLY, +mode: +IRUGO\|IWUGO\) += +[0-9]+$"
+	evts=`perf list syscalls:sys_enter_open* |& egrep 'open(at)? ' | sed -r 's/.*sys_enter_(.*) +\[.*/-e \1/'`
+	perf trace $evts touch $file 2>&1 | \
+	egrep " +[0-9]+\.[0-9]+ +\( +[0-9]+\.[0-9]+ ms\): +touch\/[0-9]+ open(at)?\((dfd: +CWD, +)?filename: +${file}, +flags: CREAT\|NOCTTY\|NONBLOCK\|WRONLY, +mode: +IRUGO\|IWUGO\) += +[0-9]+$"
 }