kernel/tools/perf/tests/shell, branch linux-4.17.y

perf test: "probe libc's inet_pton" fails on s390 due to missing inline

2018-05-10T18:19:30Z

perf test "probe libc's inet_pton & backtrace it with ping" fails on 4.17.0rc3 on s/390. It turned out that function __inet_pton is reported as inline: [root@s8360047 perf]# ./perf script -i /tmp/perf.data.111 ping 12457 [000] 1584.478959: probe_libc:inet_pton: (3ffb5a347e8) 1347e8 __inet_pton (inlined) f19d7 gaih_inet.constprop.5 (/usr/lib64/libc-2.24.so) f4c3f __GI_getaddrinfo (inlined) 410b main (/usr/bin/ping) Allow __inet_pton listed as inline. Signed-off-by: Thomas Richter Cc: Heiko Carstens Cc: Hendrik Brueckner Cc: Martin Schwidefsky Link: http://lkml.kernel.org/r/20180503065837.71043-1-tmricht@linux.ibm.com Signed-off-by: Arnaldo Carvalho de Melo

perf test: Adapt test case record+probe_libc_inet_pton.sh for s390

2018-04-23T14:04:37Z

perf test case 58 (record+probe_libc_inet_pton.sh) executed on s390x using kernel 4.16.0rc3 displays this result: # perf trace --no-syscalls -e probe_libc:inet_pton/call-graph=dwarf/ ping -6 -c 1 ::1 probe_libc:inet_pton: (3ffa0240448) __GI___inet_pton (/usr/lib64/libc-2.26.so) gaih_inet (inlined) __GI_getaddrinfo (inlined) main (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) _start (/usr/bin/ping) After I installed kernel 4.16.0 the same tests uses commands: # perf record -e probe_libc:inet_pton/call-graph=dwarf/ -o /tmp/perf.data.abc ping -6 -c 1 ::1 # perf script -i /tmp/perf.data.abc and displays: ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448) 140448 __GI___inet_pton (/usr/lib64/libc-2.26.so) fbde1 gaih_inet (inlined) fe2b9 __GI_getaddrinfo (inlined) 398d main (/usr/bin/ping) Nothing else changed including glibc elfutils and other libraries picked up by the build. The entries for __libc_start_main and _start are missing. I bisected missing __libc_start_main and _start to commit Fixes: 3d20c6246690 ("perf unwind: Unwind with libdw doesn't take symfs into account") When I undo this commit I get this call stack on s390: [root@s35lp76 perf]# ./perf script -i /tmp/perf.data.abc ping 39048 [006] 84230.381198: probe_libc:inet_pton: (3ffa0240448) 140448 __GI___inet_pton (/usr/lib64/libc-2.26.so) fbde1 gaih_inet (inlined) fe2b9 __GI_getaddrinfo (inlined) 398d main (/usr/bin/ping) 22fbd __libc_start_main (/usr/lib64/libc-2.26.so) 457b _start (/usr/bin/ping) Looks like dwarf functions dwfl_xxx create different call back stack trace when using file /usr/lib/debug/usr/bin/ping-20161105-7.fc27.s390x.debug instead of file /usr/bin/ping. Fix this test case on s390 and do not expect any call back stack entry after the main() function. Also be more robust and accept a leading __GI_ prefix in front of getaddrinfo. On x86 this test case shows the same call stack using both kernel versions 4.16.0rc3 and 4.16.0 and also stops at main: [root@f27 perf]# ./perf script -i /tmp/perf.data.tmr ping 4446 [000] 172.027088: probe_libc:inet_pton: (7fdfa08c93c0) 1393c0 __GI___inet_pton (/usr/lib64/libc-2.26.so) fe60d getaddrinfo (/usr/lib64/libc-2.26.so) 2f40 main (/usr/bin/ping) [root@f27 perf]# Signed-off-by: Thomas Richter Reviewed-by: Hendrik Brueckner Cc: Heiko Carstens Cc: Martin Schwidefsky Cc: Martin Vuille Link: http://lkml.kernel.org/r/20180423082428.7930-1-tmricht@linux.ibm.com Signed-off-by: Arnaldo Carvalho de Melo

perf test: Fix exit code for record+probe_libc_inet_pton.sh

2018-03-16T16:56:31Z

This fixes record+probe_libc_inet_pton.sh from always exiting with code 0 and making the test pass even if the perf script output does not match the expected pattern. The issue can be observed if this test is run with the verbose flags as shown below: 60: probe libc's inet_pton & backtrace it with ping : ... ping 19602 [006] 16988.413767: probe_libc:inet_pton: (7fff9a2c42e8) 1842e8 __GI___inet_pton (/usr/lib64/libc-2.26.so) 130db4 getaddrinfo (/usr/lib64/libc-2.26.so) FAIL: expected backtrace entry 3 ".*$.*/bin/ping.*$$" got "" test child finished with 0 ... probe libc's inet_pton & backtrace it with ping: Ok Signed-off-by: Sandipan Das Cc: Jiri Olsa Cc: Naveen N. Rao Fixes: e07d585e2454 ("perf tests: Switch trace+probe_libc_inet_pton to use record") Link: http://lkml.kernel.org/r/20180312124450.30371-1-sandipan@linux.vnet.ibm.com Signed-off-by: Arnaldo Carvalho de Melo

perf tests: Rename trace+probe_libc_inet_pton to record+probe_libc_inet_pton

2018-03-05T12:58:42Z

Because the test is no longer using perf trace but perf record instead. Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180301165215.6780-2-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf tests: Switch trace+probe_libc_inet_pton to use record

2018-03-05T12:58:42Z

There's a problem with relying on backtrace data from 'perf trace' the way the trace+probe_libc_inet_pton does. This test inserts uprobe within ping binary and checks that it gets its sample using 'perf trace'. It also checks it gets proper backtrace from sample and that's where the issue is. The 'perf trace' does not sort events (by definition) so it can happen that it processes the event sample before the ping binary memory map event. This can (very rarely) happen as proved by this events dump output (from custom added debug output): ... 7680/7680: [0x7f4e29718000(0x204000) @ 0 fd:00 33611321 4230892504]: r-xp /usr/lib64/libdl-2.17.so 7680/7680: [0x7f4e29502000(0x216000) @ 0 fd:00 33617257 2606846872]: r-xp /usr/lib64/libz.so.1.2.7 (IP, 0x2): 7680/7680: 0x7f4e29c2ed60 period: 1 addr: 0 7680/7680: [0x564842ef0000(0x233000) @ 0 fd:00 83 1989280200]: r-xp /usr/bin/ping 7680/7680: [0x7f4e2aca2000(0x224000) @ 0 fd:00 33611308 1219144940]: r-xp /usr/lib64/ld-2.17.so ... In this case 'perf trace' fails to resolve the last callchain IP (within the ping binary) because it does not know about the ping binary memory map yet and the test fails like this: PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.037 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.037/0.037/0.037/0.000 ms 0.000 probe_libc:inet_pton:(7f4e29c2ed60)) __GI___inet_pton (/usr/lib64/libc-2.17.so) getaddrinfo (/usr/lib64/libc-2.17.so) [0] ([unknown]) FAIL: expected backtrace entry 8 ".*$.*/bin/ping.*$$" got "[0] ([unknown])" Switching the test to use 'perf record' and 'perf script' instead of 'perf trace'. Signed-off-by: Jiri Olsa Tested-by: Arnaldo Carvalho de Melo Cc: Alexander Shishkin Cc: David Ahern Cc: Namhyung Kim Cc: Peter Zijlstra Link: http://lkml.kernel.org/r/20180301165215.6780-1-jolsa@kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf tests shell lib: Use a wildcard to remove the vfs_getname probe

2018-02-16T18:31:12Z

In some situations the vfs_getname is being added both as requested and with a _1 suffix (inlines?): probe:vfs_getname_1 (on getname_flags:63@acme/git/linux/fs/namei.c with pathname) This ends up making the cleanup to miss that one, as it removes just 'probe:vfs_getname', which makes the second test to use this probe point to fail, since it finds that leftover from the first test, use a wildcard to remove both. Before: # perf test 60 61 62 63 60: Use vfs_getname probe to get syscall args filenames : FAILED! 61: probe libc's inet_pton & backtrace it with ping : Ok 62: Check open filename arg using perf trace + vfs_getname: FAILED! 63: Add vfs_getname probe to get syscall args filenames : Ok After: # perf test 60 61 62 63 60: Use vfs_getname probe to get syscall args filenames : Ok 61: probe libc's inet_pton & backtrace it with ping : Ok 62: Check open filename arg using perf trace + vfs_getname: Ok 63: Add vfs_getname probe to get syscall args filenames : Ok # Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Masami Hiramatsu Cc: Namhyung Kim Cc: Thomas Richter Cc: Wang Nan Link: https://lkml.kernel.org/n/tip-2k5kutwr4ds36adiakyb4yvy@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf test: Fix test case inet_pton to accept inlines.

2018-02-16T18:16:58Z

Using Fedora 27 and latest Linux kernel the test case trace+probe_libc_inet_pton.sh fails again on s390. This time is the inlining of functions which does not match. After an update of the glibc (from 2.26-16 to 2.26-24) the output is different The expected output is: __inet_pton (/usr/lib64/libc-2.26.so) gaih_inet (inlined) .... The actual output is: 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.061/0.061/0.061/0.000 ms 0.000 probe_libc:inet_pton:(3ffb2140448)) __inet_pton (inlined) gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so) ... Fix this by being less strict on 'inlined' verses library name and accept both Signed-off-by: Thomas Richter Cc: Heiko Carstens Cc: Hendrik Brueckner Cc: Martin Schwidefsky Link: http://lkml.kernel.org/r/20180214070303.55757-1-tmricht@linux.vnet.ibm.com Signed-off-by: Arnaldo Carvalho de Melo

perf test: Fix test trace+probe_libc_inet_pton.sh for s390x

2018-02-15T12:57:47Z

On Intel test case trace+probe_libc_inet_pton.sh succeeds and the output is: [root@f27 perf]# ./perf trace --no-syscalls -e probe_libc:inet_pton/max-stack=3/ ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.037 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.037/0.037/0.037/0.000 ms 0.000 probe_libc:inet_pton:(7fa40ac618a0)) __GI___inet_pton (/usr/lib64/libc-2.26.so) getaddrinfo (/usr/lib64/libc-2.26.so) main (/usr/bin/ping) The kernel stack unwinder is used, it is specified implicitly as call-graph=fp (frame pointer). On s390x only dwarf is available for stack unwinding. It is also done in user space. This requires different parameter setup and result checking for s390x and Intel. This patch adds separate perf trace setup and result checking for Intel and s390x. On s390x specify this command line to get a call-graph and handle the different call graph result checking: [root@s35lp76 perf]# ./perf trace --no-syscalls -e probe_libc:inet_pton/call-graph=dwarf/ ping -6 -c 1 ::1 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.041 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.041/0.041/0.041/0.000 ms 0.000 probe_libc:inet_pton:(3ffb9942060)) __GI___inet_pton (/usr/lib64/libc-2.26.so) gaih_inet (inlined) __GI_getaddrinfo (inlined) main (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) _start (/usr/bin/ping) [root@s35lp76 perf]# Before: [root@s8360047 perf]# ./perf test -vv 58 58: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 26349 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.079 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.079/0.079/0.079/0.000 ms 0.000 probe_libc:inet_pton:(3ff925c2060)) test child finished with -1 ---- end ---- probe libc's inet_pton & backtrace it with ping: FAILED! [root@s8360047 perf]# After: [root@s35lp76 perf]# ./perf test -vv 57 57: probe libc's inet_pton & backtrace it with ping : --- start --- test child forked, pid 38708 PING ::1(::1) 56 data bytes 64 bytes from ::1: icmp_seq=1 ttl=64 time=0.038 ms --- ::1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.038/0.038/0.038/0.000 ms 0.000 probe_libc:inet_pton:(3ff87342060)) __GI___inet_pton (/usr/lib64/libc-2.26.so) gaih_inet (inlined) __GI_getaddrinfo (inlined) main (/usr/bin/ping) __libc_start_main (/usr/lib64/libc-2.26.so) _start (/usr/bin/ping) test child finished with 0 ---- end ---- probe libc's inet_pton & backtrace it with ping: Ok [root@s35lp76 perf]# On Intel the test case runs unchanged and succeeds. Signed-off-by: Thomas Richter Reviewed-by: Hendrik Brueckner Tested-by: Arnaldo Carvalho de Melo Cc: Heiko Carstens Cc: Martin Schwidefsky Link: http://lkml.kernel.org/r/20180117083831.101001-1-tmricht@linux.vnet.ibm.com Signed-off-by: Arnaldo Carvalho de Melo

perf test shell: Fix check open filename arg using 'perf trace'

2017-12-27T15:15:56Z

Commit f231af789b11 ("perf test shell: Fix check open filename arg using 'perf trace' on s390x") added an exception for s390x to use openat() instead of open() in the test that intercepts a open syscall to look for the filename argument as obtained by the vfs_getname 'perf probe' it puts in place at the getname_flags kernel function. Its not just s390x that uses openat() instead of open(), so use 'perf list' to look for the syscall:sys_enter_open(at)? present in the system being tested instead of checking if the system is s390x. In fact Namhyung pointed out that glibc 2.26 changed this behaviour, as described in https://lwn.net/Articles/738694/, so systems where glibc is >= 2.26 will need this patch for this test to work, which already took place in some distros for architectures such as s390x, while Fedora 26 x86_64 is at glibc 2.25, i.e. still uses open(). Signed-off-by: Michael Petlan Tested-by: Arnaldo Carvalho de Melo Tested-by: Thomas Richter Link: https://lkml.kernel.org/r/ab23fe42-1080-a46b-503e-744e097f414f@linux.vnet.ibm.com Cc: Adrian Hunter Cc: David Ahern Cc: Hendrik Brueckner Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan LPU-Reference: 1275675985.12835754.1513095723265.JavaMail.zimbra@redhat.com Link: https://lkml.kernel.org/n/tip-j2wbz9av1rw3thr3t0g4dtuk@git.kernel.org Signed-off-by: Arnaldo Carvalho de Melo

perf test shell: Fix test case probe libc's inet_pton on s390x

2017-11-16T17:50:00Z

The 'perf test' case "probe libc's inet_pton & backtrace it with ping" fails on s390x. The reason is the 'realpath /lib64/ld*.so.* | uniq' line which returns 2 libraries: root@s35lp76 shell]# realpath /lib64/ld*.so.* | uniq /usr/lib64/ld-2.26.so /usr/lib64/ld_pre_smc.so.1.0.1 [root@s35lp76 shell] This output makes the "perf probe" command lines invalid. Use ldd tool to find out the libraries required by "bash" and check if symbol "inet_pton" is part of the "libc" library. Some distros do not have a /lib64 directory. I have also added a check for the existence of an IPv6 network interface before it is being used. Committer changes: We can't really use ldd for libc, as in some systems, such as x86_64, it has hardlinks and then ldd sees one and the kernel the other, so grep for libc in /proc/self/maps to get the one we'll receive from PERF_RECORD_MMAP. Thomas checked this change and acked it. Signed-off-by: Thomas-Mich Richter Tested-by: Arnaldo Carvalho de Melo Suggested-by: Hendrik Brückner Reviewed-by: Hendrik Brückner Link: http://lkml.kernel.org/r/20171114133409.GN8836@kernel.org Signed-off-by: Arnaldo Carvalho de Melo