perf test shell: Fix pathname arg in probe_vfs_getname.sh

PATCH In review Michael Petlan 2 participants 4 messages Dec 12, 2017 – Dec 13, 2017 1 message not in the archive perf events

lore

Share & tools

lore

A message that is not in the archive (sent off-list or not yet received): b6d31ae26f8615d6bd020f4392980950d4c70c96.1513095505.git.mpetlan@redhat.com

Michael Petlan

author

2017-12-12 16:22 UTC #1 lore raw

PATCH 2/2 perf test shell: Fix pathname arg in probe_vfs_getname.sh

Having 'filename' variable there seems to be more stable, since 'result->name' has recently changed to 'result->uptr'.

Signed-off-by Michael Petlan <[email protected]>

---
 tools/perf/tests/shell/lib/probe_vfs_getname.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/tests/shell/lib/probe_vfs_getname.sh +1 -1

index 30a950c..3759582 100644
@@ -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
 }

Signature · 1 line

1.8.3.1

Arnaldo Carvalho de Melo

maintainer

2017-12-12 17:11 UTC #2 lore raw

Em Tue, Dec 12, 2017 at 11:22:32AM -0500, Michael Petlan escreveu:

Quoted 2 lines

Having 'filename' variable there seems to be more stable, since 'result->name' has recently changed to 'result->uptr'.

Here it fails:

[root@jouet perf]# perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)

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

perf record -e probe:vfs_getname -aR sleep 1

[root@jouet perf]# perf trace -e open,openat touch /tmp/temporary_file.zbMD1

     0.042 ( 0.017 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.096 ( 0.018 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.679 ( 0.040 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.817 ( 0.252 ms): touch/7761 open(filename: , flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3

[root@jouet perf]#

And result->name is still there:

[root@jouet perf]# pahole -C filename ../build/v4.15.0-rc2+/fs/namei.o struct filename {

	const char  *              name;                 /*     0     8 */
	const char  *              uptr;                 /*     8     8 */
	struct audit_names *       aname;                /*    16     8 */
	int                        refcnt;               /*    24     4 */
	const char const           iname;                /*    28     0 */

	/* size: 32, cachelines: 1, members: 5 */
	/* padding: 4 */
	/* last cacheline: 32 bytes */
};

[root@jouet perf]#

At getname_flags:72 result->name has it as expected, at least up to v4.15.0-rc2+, where are you experiencing problems?

- Arnaldo

Quoted 25 lines

Signed-off-by Michael Petlan <[email protected]>

---
 tools/perf/tests/shell/lib/probe_vfs_getname.sh | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

tools/perf/tests/shell/lib/probe_vfs_getname.sh +1 -1

index 30a950c..3759582 100644
@@ -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
 }

Signature · 6 lines

1.8.3.1

--
To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Michael Petlan

author

2017-12-13 14:23 UTC #3 lore raw

Quoted 31 lines · Arnaldo Carvalho de Melo

Em Tue, Dec 12, 2017 at 11:22:32AM -0500, Michael Petlan escreveu:
Quoted 2 lines
Having 'filename' variable there seems to be more stable, since 'result->name' has recently changed to 'result->uptr'.
Here it fails:
[root@jouet perf]# perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_getname -aR sleep 1
[root@jouet perf]# perf trace -e open,openat touch /tmp/temporary_file.zbMD1
     0.042 ( 0.017 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.096 ( 0.018 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.679 ( 0.040 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.817 ( 0.252 ms): touch/7761 open(filename: , flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3
[root@jouet perf]#
And result->name is still there:
[root@jouet perf]# pahole -C filename ../build/v4.15.0-rc2+/fs/namei.o struct filename {
	const char  *              name;                 /*     0     8 */
	const char  *              uptr;                 /*     8     8 */
	struct audit_names *       aname;                /*    16     8 */
	int                        refcnt;               /*    24     4 */
	const char const           iname;                /*    28     0 */

Quoted 8 lines

	/* size: 32, cachelines: 1, members: 5 */
	/* padding: 4 */
	/* last cacheline: 32 bytes */
};
[root@jouet perf]#
At getname_flags:72 result->name has it as expected, at least up to v4.15.0-rc2+, where are you experiencing problems?

[root@muflon-1 ~]# uname -r
4.15.0-rc1

[root@muflon-1 ~]# perf -v
perf version 4.15.rc1.g4fbd8d

[root@muflon-1 ~]# perf probe 'vfs_getname=getname_flags:72 pathname=result->name:string' Failed to find 'result' in this function.
Error: Failed to add events.

[root@muflon-1 ~]# perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)

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

perf record -e probe:vfs_getname -aR sleep 1

[root@muflon-1 ~]# perf trace -e open,openat touch /tmp/temporary_file.zbMD1

     0.024 ( 0.013 ms): touch/31276 open(filename: /etc/ld.so.cache, flags: CLOEXEC                       ) = 3
     0.052 ( 0.014 ms): touch/31276 open(filename: /lib64/libc.so.6, flags: CLOEXEC                       ) = 3
     0.281 ( 0.019 ms): touch/31276 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC         ) = 3
     0.344 ( 0.016 ms): touch/31276 open(filename: /tmp/temporary_file.zbMD1, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3

Arnaldo Carvalho de Melo

maintainer

2017-12-13 14:59 UTC #4 lore raw

Em Wed, Dec 13, 2017 at 03:23:39PM +0100, Michael Petlan escreveu:

Quoted 44 lines · Arnaldo Carvalho de Melo

Quoted 31 lines
Em Tue, Dec 12, 2017 at 11:22:32AM -0500, Michael Petlan escreveu:
Quoted 2 lines
Having 'filename' variable there seems to be more stable, since 'result->name' has recently changed to 'result->uptr'.
Here it fails:
[root@jouet perf]# perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_getname -aR sleep 1
[root@jouet perf]# perf trace -e open,openat touch /tmp/temporary_file.zbMD1
     0.042 ( 0.017 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.096 ( 0.018 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.679 ( 0.040 ms): touch/7761 open(filename: , flags: CLOEXEC                                       ) = 3
     0.817 ( 0.252 ms): touch/7761 open(filename: , flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3
[root@jouet perf]#
And result->name is still there:
[root@jouet perf]# pahole -C filename ../build/v4.15.0-rc2+/fs/namei.o struct filename {
	const char  *              name;                 /*     0     8 */
	const char  *              uptr;                 /*     8     8 */
	struct audit_names *       aname;                /*    16     8 */
	int                        refcnt;               /*    24     4 */
	const char const           iname;                /*    28     0 */
Quoted 8 lines
	/* size: 32, cachelines: 1, members: 5 */
	/* padding: 4 */
	/* last cacheline: 32 bytes */
};
[root@jouet perf]#
At getname_flags:72 result->name has it as expected, at least up to v4.15.0-rc2+, where are you experiencing problems?
[root@muflon-1 ~]# uname -r
4.15.0-rc1

Quoted 6 lines

[root@muflon-1 ~]# perf -v
perf version 4.15.rc1.g4fbd8d
[root@muflon-1 ~]# perf probe 'vfs_getname=getname_flags:72 pathname=result->name:string' Failed to find 'result' in this function.
Error: Failed to add events.

Ok, so we need to dig further, as, on a f26 x86_64 system updated yesterday to 4.15-rc3 I get:

[root@jouet ~]# 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

[root@jouet ~]# uname -a
Linux jouet 4.15.0-rc3+ #3 SMP Wed Dec 13 10:14:18 -03 2017 x86_64 x86_64 x86_64 GNU/Linux [root@jouet ~]#
[root@jouet ~]# perf trace -e open,probe:vfs_getname/max-stack=3/

     0.000 ( 0.036 ms): lighttpd/9653 open(filename: /proc/loadavg, mode: ISGID|IXOTH                       ) ...
     0.036 (         ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/proc/loadavg")
                                       getname_flags ([kernel.kallsyms])
                                       do_sys_open ([kernel.kallsyms])
                                       do_syscall_64 ([kernel.kallsyms])
     0.000 ( 0.104 ms): lighttpd/9653  ... [continued]: open()) = 8
    22.681 (         ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/etc/localtime")
                                       getname_flags ([kernel.kallsyms])
                                       user_path_at_empty ([kernel.kallsyms])
                                       vfs_statx ([kernel.kallsyms])

850.746 ( ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/var/cache/app-info/yaml")
getname_flags ([kernel.kallsyms]) user_path_at_empty ([kernel.kallsyms]) sys_inotify_add_watch ([kernel.kallsyms])
850.781 ( ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/var/lib/app-info/xmls")
getname_flags ([kernel.kallsyms]) user_path_at_empty ([kernel.kallsyms]) sys_inotify_add_watch ([kernel.kallsyms])
850.799 ( ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/var/lib/app-info/yaml")
getname_flags ([kernel.kallsyms]) user_path_at_empty ([kernel.kallsyms]) sys_inotify_add_watch ([kernel.kallsyms])
850.813 ( ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/usr/share/app-info/yaml")
getname_flags ([kernel.kallsyms]) user_path_at_empty ([kernel.kallsyms]) sys_inotify_add_watch ([kernel.kallsyms])
850.832 ( ): probe:vfs_getname:(ffffffff8227c9f3) pathname="/usr/local/share/app-info/xmls")
getname_flags ([kernel.kallsyms]) user_path_at_empty ([kernel.kallsyms])

What system is this? Distro, release, gcc, etc?

- ARnaldo

Quoted 13 lines

[root@muflon-1 ~]# perf probe 'vfs_getname=getname_flags:72 pathname=filename:string' Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_getname -aR sleep 1
[root@muflon-1 ~]# perf trace -e open,openat touch /tmp/temporary_file.zbMD1
     0.024 ( 0.013 ms): touch/31276 open(filename: /etc/ld.so.cache, flags: CLOEXEC                       ) = 3
     0.052 ( 0.014 ms): touch/31276 open(filename: /lib64/libc.so.6, flags: CLOEXEC                       ) = 3
     0.281 ( 0.019 ms): touch/31276 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC         ) = 3
     0.344 ( 0.016 ms): touch/31276 open(filename: /tmp/temporary_file.zbMD1, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: IRUGO|IWUGO) = 3