linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
@ 2020-02-13 12:20 Thomas Richter
  2020-02-13 14:30 ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 10+ messages in thread
From: Thomas Richter @ 2020-02-13 12:20 UTC (permalink / raw)
  To: linux-kernel, linux-perf-users, acme
  Cc: gor, sumanthk, heiko.carstens, Thomas Richter

This test places a kprobe to function getname_flags() in the kernel
which has the following prototype:

  struct filename *
  getname_flags(const char __user *filename, int flags, int *empty)

Variable filename points to a filename located in user space memory.
Looking at
commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
the kprobe should indicate that user space memory is accessed.

The following patch specifies user space memory access first and if this
fails use type 'string' in case 'ustring' is not supported.

Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
---
 tools/perf/tests/shell/lib/probe_vfs_getname.sh | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
index 7cb99b433888..30c1eadbc5be 100644
--- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
+++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
@@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
+		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
+		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
+		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
 	fi
 }
-- 
2.21.0


^ permalink raw reply related	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-13 12:20 [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh Thomas Richter
@ 2020-02-13 14:30 ` Arnaldo Carvalho de Melo
  2020-02-13 17:01   ` Masami Hiramatsu
  0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2020-02-13 14:30 UTC (permalink / raw)
  To: Thomas Richter
  Cc: linux-kernel, linux-perf-users, gor, sumanthk, heiko.carstens,
	Masami Hiramatsu

Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> This test places a kprobe to function getname_flags() in the kernel
> which has the following prototype:
> 
>   struct filename *
>   getname_flags(const char __user *filename, int flags, int *empty)
> 
> Variable filename points to a filename located in user space memory.
> Looking at
> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> the kprobe should indicate that user space memory is accessed.
> 
> The following patch specifies user space memory access first and if this
> fails use type 'string' in case 'ustring' is not supported.

What are you fixing?

I haven't seen any example of this test failing, and right now testing
it with:

[root@quaco ~]# uname -a
Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
[root@quaco ~]#

Shows it is working:

[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: Ok
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: Ok
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: Ok
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: Ok
[root@quaco ~]#

Making sure this is what is upstream _using_ that vfs_getname thing:

[root@quaco ~]# grep 'vfs_getname=g' ~acme/libexec/perf-core/tests/shell/lib/probe_vfs_getname.sh
		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
[root@quaco ~]#

Lets try the first line:

  # perf probe -l
  # perf probe 'vfs_getname=getname_flags:72 pathname=result->name:string'
  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
  
  # perf probe -l
    probe:vfs_getname    (on getname_flags:72@acme/git/linux/fs/namei.c with pathname)
  #

Lets run it again using 'perf trace', that will see that
probe:vfs_getname in place and will use it:

[root@quaco ~]# perf trace -e open* perf test "trace + vfs" |& egrep '(trace\+probe_vf|touch|Ok)'
    30.496 ( 0.055 ms): perf/23673 openat(dfd: CWD, filename: /home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh) = 4
    31.621 ( 0.061 ms): perf/23673 openat(dfd: CWD, filename: /home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh) = 4
    38.807 ( 0.064 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
    39.013 ( 0.063 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /lib64/libtinfo.so.6, flags: RDONLY|CLOEXEC) = 3
    39.253 ( 0.073 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /lib64/libdl.so.2, flags: RDONLY|CLOEXEC)  = 3
    39.477 ( 0.068 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDONLY|CLOEXEC)   = 3
    40.177 ( 0.079 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /dev/tty, flags: RDWR|NONBLOCK)            = 3
    40.431 ( 0.067 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: RDONLY|CLOEXEC) = 3
    40.661 ( 0.065 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /usr/lib64/gconv/gconv-modules.cache)      = 3
    42.236 ( 0.076 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh) = 3
    46.023 ( 0.027 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /home/acme/libexec/perf-core/tests/shell/lib/probe.sh) = 3
   110.521 ( 0.023 ms): trace+probe_vf/23675 openat(dfd: CWD, filename: /home/acme/libexec/perf-core/tests/shell/lib/probe_vfs_getname.sh) = 3
  2040.036 ( 0.012 ms): trace+probe_vf/23898 openat(dfd: CWD, filename: ., flags: RDONLY|CLOEXEC|DIRECTORY|NONBLOCK) = 3
  2731.204 ( 0.017 ms): touch/23948 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
  2731.254 ( 0.017 ms): touch/23948 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDONLY|CLOEXEC)   = 3
  2731.668 ( 0.019 ms): touch/23948 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: RDONLY|CLOEXEC) = 3
  2731.765 ( 0.017 ms): touch/23948 openat(dfd: CWD, filename: /tmp/temporary_file.ipQ2W, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3
  2732.089 ( 0.010 ms): perf/23917 openat(dfd: CWD, filename: /usr/bin/touch, flags: RDONLY|CLOEXEC)     = 6
 Ok
[root@quaco ~]# echo $?
0
[root@quaco ~]#

Then, I apply this patch and it starts consistently failing:

First clean up everything:

[root@quaco ~]# perf probe -d probe:*
Removed event: probe:vfs_getname
[root@quaco ~]# perf probe -l
[root@quaco ~]#

Then try again with this patch:

[acme@quaco perf]$ git cherry-pick d87c35073ec84736c08ef9a62bfed9cff1e5d9d5
[perf/urgent 8d9f3054a71c] perf test: Fix test trace+probe_vfs_getname.sh
 Author: Thomas Richter <tmricht@linux.ibm.com>
 Date: Thu Feb 13 13:20:09 2020 +0100
 1 file changed, 3 insertions(+), 1 deletion(-)
[acme@quaco perf]$

install it and check:

[root@quaco ~]# grep 'vfs_getname=g' ~acme/libexec/perf-core/tests/shell/lib/probe_vfs_getname.sh
		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
[root@quaco ~]#

Then run the test:

[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@quaco ~]# perf test "trace + vfs"
72: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@quaco ~]#
[root@quaco ~]#
[root@quaco ~]# for a in $(seq 5) ; do perf test "trace + vfs" ; done
72: Check open filename arg using perf trace + vfs_getname: FAILED!
72: Check open filename arg using perf trace + vfs_getname: FAILED!
72: Check open filename arg using perf trace + vfs_getname: FAILED!
72: Check open filename arg using perf trace + vfs_getname: FAILED!
72: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@quaco ~]#

Now lets try putting in place the probes as you did, using "ustring":

[root@quaco ~]# perf probe -l
[root@quaco ~]# perf probe "vfs_getname=getname_flags:72 pathname=result->uptr:ustring"
Added new event:
  probe:vfs_getname    (on getname_flags:72 with pathname=result->uptr:ustring)

You can now use it in all perf tools, such as:

	perf record -e probe:vfs_getname -aR sleep 1

[root@quaco ~]#

[root@quaco ~]# perf trace -e open* perf test "trace + vfs" |& egrep '(trace\+probe_vf|touch|Ok|FAIL)'
     7.658 ( 0.003 ms): perf/19334 openat(dfd: CWD, filename: ts/shell/trace+probe_vfs_getname.sh)       = 4
     7.787 ( 0.004 ms): perf/19334 openat(dfd: CWD, filename: ts/shell/trace+probe_vfs_getname.sh)       = 72: Check open filename arg using perf trace + vfs_getname:4
    10.242 ( 0.004 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /etc/ld.so.preload, flags: RDONLY|CLOEXEC) = 3
    10.259 ( 0.005 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
    10.295 ( 0.006 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /lib64/libtinfo.so.6, flags: RDONLY|CLOEXEC) = 3
    10.334 ( 0.006 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /lib64/libdl.so.2, flags: RDONLY|CLOEXEC)  = 3
    10.546 ( 0.008 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDWR|NONBLOCK)    = 3
    10.596 ( 0.005 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /dev/tty, flags: RDONLY|CLOEXEC)           = 3
    10.627 ( 0.005 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive)            = 3
    11.070 ( 0.007 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: OLDPWD)                                    = 3
    12.076 ( 0.008 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: )                                          = 3
    30.957 ( 0.012 ms): trace+probe_vf/19336 openat(dfd: CWD, filename: )                                          = 3
   471.042 ( 0.010 ms): trace+probe_vf/19541 openat(dfd: CWD, filename: 	, flags: RDONLY|CLOEXEC|DIRECTORY|NONBLOCK) = 3
   789.676 ( 0.007 ms): touch/19627 openat(dfd: CWD, filename: /etc/ld.so.preload, flags: RDONLY|CLOEXEC) = 3
   789.700 ( 0.008 ms): touch/19627 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
   789.820 ( 0.004 ms): perf/19610 openat(dfd: CWD, filename: /usr/bin/touch, flags: RDONLY|CLOEXEC)     = 6
   789.936 ( 0.011 ms): touch/19627 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDONLY|CLOEXEC)   = 3
   790.002 ( 0.125 ms): touch/19627 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3
 FAILED!
[root@quaco ~]#
[root@quaco ~]# perf trace -e open* perf test "trace + vfs" |& egrep '(trace\+probe_vf|touch|Ok|FAIL)'
    27.182 ( 0.047 ms): perf/23632 openat(dfd: CWD, filename: ts/shell/trace+probe_vfs_getname.sh)       = 4
    28.189 ( 0.049 ms): perf/23632 openat(dfd: CWD, filename: ts/shell/trace+probe_vfs_getname.sh)       = 4
    35.281 ( 0.062 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /etc/ld.so.preload, flags: RDONLY|CLOEXEC) = 3
    35.488 ( 0.060 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
    35.707 ( 0.070 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /lib64/libtinfo.so.6, flags: RDONLY|CLOEXEC) = 3
    35.921 ( 0.069 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /lib64/libdl.so.2, flags: RDONLY|CLOEXEC)  = 3
    36.634 ( 0.082 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDWR|NONBLOCK)    = 3
    36.895 ( 0.063 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /dev/tty, flags: RDONLY|CLOEXEC)           = 3
    37.113 ( 0.058 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive)            = 3
    38.738 ( 0.071 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: OLDPWD)                                    = 3
    42.446 ( 0.025 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: 	)                                         = 3
   105.135 ( 0.024 ms): trace+probe_vf/23634 openat(dfd: CWD, filename: 	)                                         = 3
  2027.596 ( 0.012 ms): trace+probe_vf/23815 openat(dfd: CWD, filename: 	, flags: RDONLY|CLOEXEC|DIRECTORY|NONBLOCK) = 3
  2302.961 ( 0.138 ms): perf/23824 openat(dfd: CWD, filename: /lib/modules/5.6.0-rc1+/kernel/drivers/usb/storage/ums-onetouch.ko, flags: RDONLY|CLOEXEC|DIRECTORY|NONBLOCK) = 8
  2661.047 ( 0.008 ms): perf/23824 openat(dfd: CWD, filename: /usr/bin/touch, flags: RDONLY|CLOEXEC)     = 6
  2661.940 (         ): touch/23885 openat(dfd: CWD, filename: , flags: RDONLY|CLOEXEC)                ...
  2661.940 ( 0.326 ms): touch/23885  ... [continued]: openat())                                           = 3
  2662.386 ( 0.075 ms): touch/23885 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: RDONLY|CLOEXEC)   = 3
  2662.940 ( 0.099 ms): touch/23885 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: RDONLY|CLOEXEC)   = 3
  2663.185 ( 0.076 ms): touch/23885 openat(dfd: CWD, filename: /usr/lib/locale/locale-archive, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3
 FAILED!
[root@quaco ~]#

If we use it directly:

[root@quaco ~]# perf trace -e probe:vfs_getname sleep 1
     0.000 sleep/30276 probe:vfs_getname(__probe_ip: -1942877253, pathname: "")
     1.107 sleep/30276 probe:vfs_getname(__probe_ip: -1942877253, pathname: "")
     1.186 sleep/30276 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/etc/ld.so.cache")
     1.589 sleep/30276 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/lib64/libc.so.6")
[root@quaco ~]# perf trace -e probe:vfs_getname sleep 1
     0.000 sleep/30782 probe:vfs_getname(__probe_ip: -1942877253, pathname: "")
     0.016 sleep/30782 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/etc/ld.so.preload")
     0.048 sleep/30782 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/etc/ld.so.cache")
     0.405 sleep/30782 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/lib64/libc.so.6")
[root@quaco ~]# perf trace -e probe:vfs_getname sleep 1
     0.000 sleep/31237 probe:vfs_getname(__probe_ip: -1942877253, pathname: "")
     0.016 sleep/31237 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/etc/ld.so.preload")
     0.049 sleep/31237 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/etc/ld.so.cache")
     0.376 sleep/31237 probe:vfs_getname(__probe_ip: -1942877253, pathname: "/lib64/libc.so.6")
[root@quaco ~]#

While:

[root@quaco ~]# strace -e open,openat,access sleep 1
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
+++ exited with 0 +++
[root@quaco ~]# strace -e open,openat,access sleep 1
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
+++ exited with 0 +++
[root@quaco ~]# strace -e open,openat,access sleep 1
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
+++ exited with 0 +++
[root@quaco ~]#

Also for completeness:

[root@quaco ~]# strace -f -e open,openat perf test "trace + vfs" |& egrep '(vfs_getname\.sh|trace\+probe_vf|touch|Ok|FAILED)'
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/record+script_probe_vfs_getname.sh", O_RDONLY) = 4
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/probe_vfs_getname.sh", O_RDONLY) = 4
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh", O_RDONLY) = 4
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/record+script_probe_vfs_getname.sh", O_RDONLY) = 4
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/probe_vfs_getname.sh", O_RDONLY) = 4
openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh", O_RDONLY) = 4
[pid  7538] openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/trace+probe_vfs_getname.sh", O_RDONLY) = 3
[pid  7538] openat(AT_FDCWD, "/home/acme/libexec/perf-core/tests/shell/lib/probe_vfs_getname.sh", O_RDONLY) = 3
[pid  7768] openat(AT_FDCWD, "/usr/bin/touch", O_RDONLY|O_CLOEXEC) = 6
 FAILED!
[root@quaco ~]# grep 'vfs_getname=g' /home/acme/libexec/perf-core/tests/shell/lib/probe_vfs_getname.sh
		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
[root@quaco ~]#

[root@quaco ~]# cat /sys/kernel/debug/tracing/README  | grep -B6 -A5 ustring
   place (uprobe): <path>:<offset>[(ref_ctr_offset)]
	     args: <name>=fetcharg[:type]
	 fetcharg: %<register>, @<address>, @<symbol>[+|-<offset>],
	           $stack<index>, $stack, $retval, $comm, $arg<N>,
	           +|-[u]<offset>(<fetcharg>), \imm-value, \"imm-string"
	     type: s8/16/32/64, u8/16/32/64, x8/16/32/64, string, symbol,
	           b<bit-width>@<bit-offset>/<container-size>, ustring,
	           <type>\[<array-size>\]
	    field: <stype> <name>;
	    stype: u8/u16/u32/u64, s8/s16/s32/s64, pid_t,
	           [unsigned] char/int/long
  events/		- Directory containing all trace event subsystems:
[root@quaco ~]#

So this needs some more investigation :-\

I'm not applying this patch till we get to the bottom of this, ok?

- Arnaldo
 
> Signed-off-by: Thomas Richter <tmricht@linux.ibm.com>
> ---
>  tools/perf/tests/shell/lib/probe_vfs_getname.sh | 4 +++-
>  1 file changed, 3 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> index 7cb99b433888..30c1eadbc5be 100644
> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>  	fi
>  }
> -- 
> 2.21.0
> 

-- 

- Arnaldo

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-13 14:30 ` Arnaldo Carvalho de Melo
@ 2020-02-13 17:01   ` Masami Hiramatsu
  2020-02-13 18:11     ` Arnaldo Carvalho de Melo
  0 siblings, 1 reply; 10+ messages in thread
From: Masami Hiramatsu @ 2020-02-13 17:01 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Thomas Richter, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens, Masami Hiramatsu

Hi Thomas and Arnaldo,

On Thu, 13 Feb 2020 11:30:48 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> > This test places a kprobe to function getname_flags() in the kernel
> > which has the following prototype:
> > 
> >   struct filename *
> >   getname_flags(const char __user *filename, int flags, int *empty)
> > 
> > Variable filename points to a filename located in user space memory.
> > Looking at
> > commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> > the kprobe should indicate that user space memory is accessed.
> > 
> > The following patch specifies user space memory access first and if this
> > fails use type 'string' in case 'ustring' is not supported.
> 
> What are you fixing?
> 
> I haven't seen any example of this test failing, and right now testing
> it with:
> 
> [root@quaco ~]# uname -a
> Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
> [root@quaco ~]#

This bug doesn't happen on x86 or other archs on which user-address space and
kernel address space is same. On some arch (ppc64 in this case?) user-address
space is partially or completely same as kernel address space. (Yes, they switch
the world when running into the kernel) In this case, we need to use different
data access functions for each spaces. That is why I introduced "ustring" type
for kprobe event.
As far as I can see, Thomas's patch is sane. Thomas, could you show us your
result on your test environment?

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-13 17:01   ` Masami Hiramatsu
@ 2020-02-13 18:11     ` Arnaldo Carvalho de Melo
  2020-02-14  0:45       ` Masami Hiramatsu
  0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2020-02-13 18:11 UTC (permalink / raw)
  To: Masami Hiramatsu
  Cc: Thomas Richter, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens

Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
> On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
 
> > Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> > > This test places a kprobe to function getname_flags() in the kernel
> > > which has the following prototype:
 
> > >   struct filename *
> > >   getname_flags(const char __user *filename, int flags, int *empty)
 
> > > Variable filename points to a filename located in user space memory.
> > > Looking at
> > > commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> > > the kprobe should indicate that user space memory is accessed.
 
> > > The following patch specifies user space memory access first and if this
> > > fails use type 'string' in case 'ustring' is not supported.
 
> > What are you fixing?
 
> > I haven't seen any example of this test failing, and right now testing
> > it with:
 
> > [root@quaco ~]# uname -a
> > Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
> > [root@quaco ~]#
 
> This bug doesn't happen on x86 or other archs on which user-address space and
> kernel address space is same. On some arch (ppc64 in this case?) user-address
> space is partially or completely same as kernel address space. (Yes, they switch
> the world when running into the kernel) In this case, we need to use different
> data access functions for each spaces. That is why I introduced "ustring" type
> for kprobe event.
> As far as I can see, Thomas's patch is sane.

Well, without his patch, on x86, the test he is claiming to be fixing
works well, with his patch it stops working, see the rest of my reply.

- Arnaldo

> Thomas, could you show us your result on your test environment?

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-13 18:11     ` Arnaldo Carvalho de Melo
@ 2020-02-14  0:45       ` Masami Hiramatsu
  2020-02-14  9:44         ` Thomas Richter
                           ` (2 more replies)
  0 siblings, 3 replies; 10+ messages in thread
From: Masami Hiramatsu @ 2020-02-14  0:45 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Thomas Richter, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens

On Thu, 13 Feb 2020 15:11:40 -0300
Arnaldo Carvalho de Melo <acme@kernel.org> wrote:

> Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
> > On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>  
> > > Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> > > > This test places a kprobe to function getname_flags() in the kernel
> > > > which has the following prototype:
>  
> > > >   struct filename *
> > > >   getname_flags(const char __user *filename, int flags, int *empty)
>  
> > > > Variable filename points to a filename located in user space memory.
> > > > Looking at
> > > > commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> > > > the kprobe should indicate that user space memory is accessed.
>  
> > > > The following patch specifies user space memory access first and if this
> > > > fails use type 'string' in case 'ustring' is not supported.
>  
> > > What are you fixing?
>  
> > > I haven't seen any example of this test failing, and right now testing
> > > it with:
>  
> > > [root@quaco ~]# uname -a
> > > Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
> > > [root@quaco ~]#
>  
> > This bug doesn't happen on x86 or other archs on which user-address space and
> > kernel address space is same. On some arch (ppc64 in this case?) user-address
> > space is partially or completely same as kernel address space. (Yes, they switch
> > the world when running into the kernel) In this case, we need to use different
> > data access functions for each spaces. That is why I introduced "ustring" type
> > for kprobe event.
> > As far as I can see, Thomas's patch is sane.
> 
> Well, without his patch, on x86, the test he is claiming to be fixing
> works well, with his patch it stops working, see the rest of my reply.

OK, let me see.


> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> index 7cb99b433888..30c1eadbc5be 100644
> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>  	fi
>  }

This looks no good (depends on architecture or debuginfo). In fs/namei.c,

struct filename *
getname_flags(const char __user *filename, int flags, int *empty)
...
        kname = (char *)result->iname;
        result->name = kname;
...
        result->uptr = filename;
        result->aname = NULL;
        audit_getname(result);
        return result;
}

And the line number script, egreps below line.

        result->uptr = filename;

However, the probe on this line will hit *before* execute this line.
Note that kprobes is a breakpoint, which breaks into this line execution,
not after executed.

So, I thik at this point, result->uptr should be NULL, but filename and
result->name already have assigned value.

Thus, the fix should be something like below.

> 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \

Thomas, is this OK for you too, or would you have any reason to trace
result->uptr?

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-14  0:45       ` Masami Hiramatsu
@ 2020-02-14  9:44         ` Thomas Richter
  2020-02-14 13:00           ` Arnaldo Carvalho de Melo
  2020-02-14 10:02         ` Thomas Richter
  2020-02-14 13:04         ` Arnaldo Carvalho de Melo
  2 siblings, 1 reply; 10+ messages in thread
From: Thomas Richter @ 2020-02-14  9:44 UTC (permalink / raw)
  To: Masami Hiramatsu, Arnaldo Carvalho de Melo
  Cc: linux-kernel, linux-perf-users, gor, sumanthk, heiko.carstens

On 2/14/20 1:45 AM, Masami Hiramatsu wrote:
> On Thu, 13 Feb 2020 15:11:40 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
>> Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
>>> On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>  
>>>> Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
>>>>> This test places a kprobe to function getname_flags() in the kernel
>>>>> which has the following prototype:
>>  
>>>>>   struct filename *
>>>>>   getname_flags(const char __user *filename, int flags, int *empty)
>>  
>>>>> Variable filename points to a filename located in user space memory.
>>>>> Looking at
>>>>> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
>>>>> the kprobe should indicate that user space memory is accessed.
>>  
>>>>> The following patch specifies user space memory access first and if this
>>>>> fails use type 'string' in case 'ustring' is not supported.
>>  
>>>> What are you fixing?
>>  
>>>> I haven't seen any example of this test failing, and right now testing
>>>> it with:
>>  
>>>> [root@quaco ~]# uname -a
>>>> Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
>>>> [root@quaco ~]#
>>  
>>> This bug doesn't happen on x86 or other archs on which user-address space and
>>> kernel address space is same. On some arch (ppc64 in this case?) user-address
>>> space is partially or completely same as kernel address space. (Yes, they switch
>>> the world when running into the kernel) In this case, we need to use different
>>> data access functions for each spaces. That is why I introduced "ustring" type
>>> for kprobe event.
>>> As far as I can see, Thomas's patch is sane.
>>
>> Well, without his patch, on x86, the test he is claiming to be fixing
>> works well, with his patch it stops working, see the rest of my reply.
> 
> OK, let me see.
> 
> 
>> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> index 7cb99b433888..30c1eadbc5be 100644
>> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
>>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>>  	fi
>>  }
> 
> This looks no good (depends on architecture or debuginfo). In fs/namei.c,
> 
> struct filename *
> getname_flags(const char __user *filename, int flags, int *empty)
> ...
>         kname = (char *)result->iname;
>         result->name = kname;
> ...
>         result->uptr = filename;
>         result->aname = NULL;
>         audit_getname(result);
>         return result;
> }
> 
> And the line number script, egreps below line.
> 
>         result->uptr = filename;
> 
> However, the probe on this line will hit *before* execute this line.
> Note that kprobes is a breakpoint, which breaks into this line execution,
> not after executed.
> 
> So, I thik at this point, result->uptr should be NULL, but filename and
> result->name already have assigned value.
> 
> Thus, the fix should be something like below.
> 
>> 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>> - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> 
> Thomas, is this OK for you too, or would you have any reason to trace
> result->uptr?
> 
> Thank you,
> 

Thank you very much for your help!!!

I started from scratch and just installed linux 5.6.0rc1 without
any changes and got this failure:

[root@m35lp76 perf]# ./perf test  66 67
66: Use vfs_getname probe to get syscall args filenames   : FAILED!
67: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@m35lp76 perf]#

Now I applied Masami's patch and this is the result

[root@m35lp76 perf]# ./perf test  66 67
66: Use vfs_getname probe to get syscall args filenames   : Ok
67: Check open filename arg using perf trace + vfs_getname: Ok
[root@m35lp76 perf        

Can we commit this patch?
Thanks a lot
-- 
Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzender des Aufsichtsrats: Matthias Hartmann
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-14  0:45       ` Masami Hiramatsu
  2020-02-14  9:44         ` Thomas Richter
@ 2020-02-14 10:02         ` Thomas Richter
  2020-02-14 13:04         ` Arnaldo Carvalho de Melo
  2 siblings, 0 replies; 10+ messages in thread
From: Thomas Richter @ 2020-02-14 10:02 UTC (permalink / raw)
  To: Masami Hiramatsu, Arnaldo Carvalho de Melo
  Cc: linux-kernel, linux-perf-users, gor, sumanthk, heiko.carstens

On 2/14/20 1:45 AM, Masami Hiramatsu wrote:
> On Thu, 13 Feb 2020 15:11:40 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
>> Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
>>> On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>  
>>>> Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
>>>>> This test places a kprobe to function getname_flags() in the kernel
>>>>> which has the following prototype:
>>  
>>>>>   struct filename *
>>>>>   getname_flags(const char __user *filename, int flags, int *empty)
>>  
>>>>> Variable filename points to a filename located in user space memory.
>>>>> Looking at
>>>>> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
>>>>> the kprobe should indicate that user space memory is accessed.
>>  
>>>>> The following patch specifies user space memory access first and if this
>>>>> fails use type 'string' in case 'ustring' is not supported.
>>  
>>>> What are you fixing?
>>  
>>>> I haven't seen any example of this test failing, and right now testing
>>>> it with:
>>  
>>>> [root@quaco ~]# uname -a
>>>> Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
>>>> [root@quaco ~]#
>>  
>>> This bug doesn't happen on x86 or other archs on which user-address space and
>>> kernel address space is same. On some arch (ppc64 in this case?) user-address
>>> space is partially or completely same as kernel address space. (Yes, they switch
>>> the world when running into the kernel) In this case, we need to use different
>>> data access functions for each spaces. That is why I introduced "ustring" type
>>> for kprobe event.
>>> As far as I can see, Thomas's patch is sane.
>>
>> Well, without his patch, on x86, the test he is claiming to be fixing
>> works well, with his patch it stops working, see the rest of my reply.
> 
> OK, let me see.
> 
> 
>> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> index 7cb99b433888..30c1eadbc5be 100644
>> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
>>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>>  	fi
>>  }
> 
> This looks no good (depends on architecture or debuginfo). In fs/namei.c,
> 
> struct filename *
> getname_flags(const char __user *filename, int flags, int *empty)
> ...
>         kname = (char *)result->iname;
>         result->name = kname;
> ...
>         result->uptr = filename;
>         result->aname = NULL;
>         audit_getname(result);
>         return result;
> }
> 
> And the line number script, egreps below line.
> 
>         result->uptr = filename;
> 
> However, the probe on this line will hit *before* execute this line.
> Note that kprobes is a breakpoint, which breaks into this line execution,
> not after executed.
> 
> So, I thik at this point, result->uptr should be NULL, but filename and
> result->name already have assigned value.
> 
> Thus, the fix should be something like below.
> 
>> 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>> - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> 
> Thomas, is this OK for you too, or would you have any reason to trace
> result->uptr?
> 
> Thank you,
> 


Masami, thanks very much for your help!

I started from scratch and just installed linux 5.6.0rc1 without
any changes and got this failure:

[root@m35lp76 perf]# ./perf test  66 67
66: Use vfs_getname probe to get syscall args filenames   : FAILED!
67: Check open filename arg using perf trace + vfs_getname: FAILED!
[root@m35lp76 perf]#

Now I applied Masami's patch and this is the result

[root@m35lp76 perf]# ./perf test  66 67
66: Use vfs_getname probe to get syscall args filenames   : Ok
67: Check open filename arg using perf trace + vfs_getname: Ok
[root@m35lp76 perf  

This is what I wanted to achieve.
And I think I know what went wrong. I supplied an initial patch and when
I rewrote it for V3 I kprobed the wrong line.

Again thanks a lot and sorry for the noise...
-- 
Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzender des Aufsichtsrats: Matthias Hartmann
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-14  9:44         ` Thomas Richter
@ 2020-02-14 13:00           ` Arnaldo Carvalho de Melo
  2020-02-14 13:54             ` Thomas Richter
  0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2020-02-14 13:00 UTC (permalink / raw)
  To: Thomas Richter
  Cc: Masami Hiramatsu, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens

Em Fri, Feb 14, 2020 at 10:44:06AM +0100, Thomas Richter escreveu:
> On 2/14/20 1:45 AM, Masami Hiramatsu wrote:
> > On Thu, 13 Feb 2020 15:11:40 -0300
> > Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> > 
> >> Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
> >>> On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> >>  
> >>>> Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> >>>>> This test places a kprobe to function getname_flags() in the kernel
> >>>>> which has the following prototype:
> >>  
> >>>>>   struct filename *
> >>>>>   getname_flags(const char __user *filename, int flags, int *empty)
> >>  
> >>>>> Variable filename points to a filename located in user space memory.
> >>>>> Looking at
> >>>>> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> >>>>> the kprobe should indicate that user space memory is accessed.
> >>  
> >>>>> The following patch specifies user space memory access first and if this
> >>>>> fails use type 'string' in case 'ustring' is not supported.
> >>  
> >>>> What are you fixing?
> >>  
> >>>> I haven't seen any example of this test failing, and right now testing
> >>>> it with:
> >>  
> >>>> [root@quaco ~]# uname -a
> >>>> Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
> >>>> [root@quaco ~]#
> >>  
> >>> This bug doesn't happen on x86 or other archs on which user-address space and
> >>> kernel address space is same. On some arch (ppc64 in this case?) user-address
> >>> space is partially or completely same as kernel address space. (Yes, they switch
> >>> the world when running into the kernel) In this case, we need to use different
> >>> data access functions for each spaces. That is why I introduced "ustring" type
> >>> for kprobe event.
> >>> As far as I can see, Thomas's patch is sane.
> >>
> >> Well, without his patch, on x86, the test he is claiming to be fixing
> >> works well, with his patch it stops working, see the rest of my reply.
> > 
> > OK, let me see.
> > 
> > 
> >> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> >> index 7cb99b433888..30c1eadbc5be 100644
> >> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> >> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> >> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> >> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
> >> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> >> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
> >>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> >>  	fi
> >>  }
> > 
> > This looks no good (depends on architecture or debuginfo). In fs/namei.c,
> > 
> > struct filename *
> > getname_flags(const char __user *filename, int flags, int *empty)
> > ...
> >         kname = (char *)result->iname;
> >         result->name = kname;
> > ...
> >         result->uptr = filename;
> >         result->aname = NULL;
> >         audit_getname(result);
> >         return result;
> > }
> > 
> > And the line number script, egreps below line.
> > 
> >         result->uptr = filename;
> > 
> > However, the probe on this line will hit *before* execute this line.
> > Note that kprobes is a breakpoint, which breaks into this line execution,
> > not after executed.
> > 
> > So, I thik at this point, result->uptr should be NULL, but filename and
> > result->name already have assigned value.
> > 
> > Thus, the fix should be something like below.
> > 
> >> 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> >> - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> >> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> > 
> > Thomas, is this OK for you too, or would you have any reason to trace
> > result->uptr?
> > 
> > Thank you,
> > 
> 
> Thank you very much for your help!!!
> 
> I started from scratch and just installed linux 5.6.0rc1 without
> any changes and got this failure:
> 
> [root@m35lp76 perf]# ./perf test  66 67
> 66: Use vfs_getname probe to get syscall args filenames   : FAILED!
> 67: Check open filename arg using perf trace + vfs_getname: FAILED!
> [root@m35lp76 perf]#
> 
> Now I applied Masami's patch and this is the result
> 
> [root@m35lp76 perf]# ./perf test  66 67
> 66: Use vfs_getname probe to get syscall args filenames   : Ok
> 67: Check open filename arg using perf trace + vfs_getname: Ok
> [root@m35lp76 perf        
> 
> Can we commit this patch?
> Thanks a lot

So, I'll keep authorship to Thomas but will add a committer note stating
Masami's correction, is that ok?

- Arnaldo

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-14  0:45       ` Masami Hiramatsu
  2020-02-14  9:44         ` Thomas Richter
  2020-02-14 10:02         ` Thomas Richter
@ 2020-02-14 13:04         ` Arnaldo Carvalho de Melo
  2 siblings, 0 replies; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2020-02-14 13:04 UTC (permalink / raw)
  To: Masami Hiramatsu
  Cc: Thomas Richter, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens

Em Fri, Feb 14, 2020 at 09:45:50AM +0900, Masami Hiramatsu escreveu:
> On Thu, 13 Feb 2020 15:11:40 -0300
> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> 
> > Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
> > > On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
> >  
> > > > Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
> > > > > This test places a kprobe to function getname_flags() in the kernel
> > > > > which has the following prototype:
> >  
> > > > >   struct filename *
> > > > >   getname_flags(const char __user *filename, int flags, int *empty)
> >  
> > > > > Variable filename points to a filename located in user space memory.
> > > > > Looking at
> > > > > commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> > > > > the kprobe should indicate that user space memory is accessed.
> >  
> > > > > The following patch specifies user space memory access first and if this
> > > > > fails use type 'string' in case 'ustring' is not supported.
> >  
> > > > What are you fixing?
> >  
> > > > I haven't seen any example of this test failing, and right now testing
> > > > it with:
> >  
> > > > [root@quaco ~]# uname -a
> > > > Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
> > > > [root@quaco ~]#
> >  
> > > This bug doesn't happen on x86 or other archs on which user-address space and
> > > kernel address space is same. On some arch (ppc64 in this case?) user-address
> > > space is partially or completely same as kernel address space. (Yes, they switch
> > > the world when running into the kernel) In this case, we need to use different
> > > data access functions for each spaces. That is why I introduced "ustring" type
> > > for kprobe event.
> > > As far as I can see, Thomas's patch is sane.
> > 
> > Well, without his patch, on x86, the test he is claiming to be fixing
> > works well, with his patch it stops working, see the rest of my reply.
> 
> OK, let me see.
> 
> 
> > diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> > index 7cb99b433888..30c1eadbc5be 100644
> > --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> > +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> > @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> > +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
> > +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> > +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
> >  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> >  	fi
> >  }
> 
> This looks no good (depends on architecture or debuginfo). In fs/namei.c,
> 
> struct filename *
> getname_flags(const char __user *filename, int flags, int *empty)
> ...
>         kname = (char *)result->iname;
>         result->name = kname;
> ...
>         result->uptr = filename;
>         result->aname = NULL;
>         audit_getname(result);
>         return result;
> }
> 
> And the line number script, egreps below line.
> 
>         result->uptr = filename;
> 
> However, the probe on this line will hit *before* execute this line.
> Note that kprobes is a breakpoint, which breaks into this line execution,
> not after executed.
> 
> So, I thik at this point, result->uptr should be NULL, but filename and
> result->name already have assigned value.
> 
> Thus, the fix should be something like below.
> 
> > 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> > - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> > +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
> 
> Thomas, is this OK for you too, or would you have any reason to trace
> result->uptr?

Ok, I retract my last e-mail, can you provide a final patch with the fix?

- Arnaldo

^ permalink raw reply	[flat|nested] 10+ messages in thread
* Re: [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh
  2020-02-14 13:00           ` Arnaldo Carvalho de Melo
@ 2020-02-14 13:54             ` Thomas Richter
  0 siblings, 0 replies; 10+ messages in thread
From: Thomas Richter @ 2020-02-14 13:54 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo
  Cc: Masami Hiramatsu, linux-kernel, linux-perf-users, gor, sumanthk,
	heiko.carstens

On 2/14/20 2:00 PM, Arnaldo Carvalho de Melo wrote:
> Em Fri, Feb 14, 2020 at 10:44:06AM +0100, Thomas Richter escreveu:
>> On 2/14/20 1:45 AM, Masami Hiramatsu wrote:
>>> On Thu, 13 Feb 2020 15:11:40 -0300
>>> Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>>
>>>> Em Fri, Feb 14, 2020 at 02:01:51AM +0900, Masami Hiramatsu escreveu:
>>>>> On Thu, 13 Feb 2020 11:30:48 -0300 Arnaldo Carvalho de Melo <acme@kernel.org> wrote:
>>>>  
>>>>>> Em Thu, Feb 13, 2020 at 01:20:09PM +0100, Thomas Richter escreveu:
>>>>>>> This test places a kprobe to function getname_flags() in the kernel
>>>>>>> which has the following prototype:
>>>>  
>>>>>>>   struct filename *
>>>>>>>   getname_flags(const char __user *filename, int flags, int *empty)
>>>>  
>>>>>>> Variable filename points to a filename located in user space memory.
>>>>>>> Looking at
>>>>>>> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
>>>>>>> the kprobe should indicate that user space memory is accessed.
>>>>  
>>>>>>> The following patch specifies user space memory access first and if this
>>>>>>> fails use type 'string' in case 'ustring' is not supported.
>>>>  
>>>>>> What are you fixing?
>>>>  
>>>>>> I haven't seen any example of this test failing, and right now testing
>>>>>> it with:
>>>>  
>>>>>> [root@quaco ~]# uname -a
>>>>>> Linux quaco 5.6.0-rc1+ #1 SMP Wed Feb 12 15:42:16 -03 2020 x86_64 x86_64 x86_64 GNU/Linux
>>>>>> [root@quaco ~]#
>>>>  
>>>>> This bug doesn't happen on x86 or other archs on which user-address space and
>>>>> kernel address space is same. On some arch (ppc64 in this case?) user-address
>>>>> space is partially or completely same as kernel address space. (Yes, they switch
>>>>> the world when running into the kernel) In this case, we need to use different
>>>>> data access functions for each spaces. That is why I introduced "ustring" type
>>>>> for kprobe event.
>>>>> As far as I can see, Thomas's patch is sane.
>>>>
>>>> Well, without his patch, on x86, the test he is claiming to be fixing
>>>> works well, with his patch it stops working, see the rest of my reply.
>>>
>>> OK, let me see.
>>>
>>>
>>>> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>>>> index 7cb99b433888..30c1eadbc5be 100644
>>>> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>>>> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
>>>> @@ -13,7 +13,9 @@ 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 -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>>>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
>>>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
>>>> +		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->uptr:string" || \
>>>>  		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>>>>  	fi
>>>>  }
>>>
>>> This looks no good (depends on architecture or debuginfo). In fs/namei.c,
>>>
>>> struct filename *
>>> getname_flags(const char __user *filename, int flags, int *empty)
>>> ...
>>>         kname = (char *)result->iname;
>>>         result->name = kname;
>>> ...
>>>         result->uptr = filename;
>>>         result->aname = NULL;
>>>         audit_getname(result);
>>>         return result;
>>> }
>>>
>>> And the line number script, egreps below line.
>>>
>>>         result->uptr = filename;
>>>
>>> However, the probe on this line will hit *before* execute this line.
>>> Note that kprobes is a breakpoint, which breaks into this line execution,
>>> not after executed.
>>>
>>> So, I thik at this point, result->uptr should be NULL, but filename and
>>> result->name already have assigned value.
>>>
>>> Thus, the fix should be something like below.
>>>
>>>> 		perf probe -q       "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
>>>> - 		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
>>>> +		perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring" || \
>>>
>>> Thomas, is this OK for you too, or would you have any reason to trace
>>> result->uptr?
>>>
>>> Thank you,
>>>
>>
>> Thank you very much for your help!!!
>>
>> I started from scratch and just installed linux 5.6.0rc1 without
>> any changes and got this failure:
>>
>> [root@m35lp76 perf]# ./perf test  66 67
>> 66: Use vfs_getname probe to get syscall args filenames   : FAILED!
>> 67: Check open filename arg using perf trace + vfs_getname: FAILED!
>> [root@m35lp76 perf]#
>>
>> Now I applied Masami's patch and this is the result
>>
>> [root@m35lp76 perf]# ./perf test  66 67
>> 66: Use vfs_getname probe to get syscall args filenames   : Ok
>> 67: Check open filename arg using perf trace + vfs_getname: Ok
>> [root@m35lp76 perf        
>>
>> Can we commit this patch?
>> Thanks a lot
> 
> So, I'll keep authorship to Thomas but will add a committer note stating
> Masami's correction, is that ok?
> 
> - Arnaldo
> 

Sure go ahead.


-- 
Thomas Richter, Dept 3252, IBM s390 Linux Development, Boeblingen, Germany
--
Vorsitzender des Aufsichtsrats: Matthias Hartmann
Geschäftsführung: Dirk Wittkopp
Sitz der Gesellschaft: Böblingen / Registergericht: Amtsgericht Stuttgart, HRB 243294


^ permalink raw reply	[flat|nested] 10+ messages in thread
end of thread, other threads:[~2020-02-14 13:54 UTC | newest]

Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-02-13 12:20 [PATCH v3] perf test: Fix test trace+probe_vfs_getname.sh Thomas Richter
2020-02-13 14:30 ` Arnaldo Carvalho de Melo
2020-02-13 17:01   ` Masami Hiramatsu
2020-02-13 18:11     ` Arnaldo Carvalho de Melo
2020-02-14  0:45       ` Masami Hiramatsu
2020-02-14  9:44         ` Thomas Richter
2020-02-14 13:00           ` Arnaldo Carvalho de Melo
2020-02-14 13:54             ` Thomas Richter
2020-02-14 10:02         ` Thomas Richter
2020-02-14 13:04         ` Arnaldo Carvalho de Melo

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).