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: 3d20c62466 ("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 <tmricht@linux.ibm.com>
Reviewed-by: Hendrik Brueckner <brueckner@linux.ibm.com>
Cc: Heiko Carstens <heiko.carstens@de.ibm.com>
Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
Cc: Martin Vuille <jpmv27@aim.com>
Link: http://lkml.kernel.org/r/20180423082428.7930-1-tmricht@linux.ibm.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Since e145242ea0 ("syscalls/core, syscalls/x86: Clean up syscall stub
naming convention") changed the main syscall function for 'epoll_pwait'
to something other than the expected 'SyS_epoll_pwait the' 'perf test
BPF' entries started failing, fix it by using something called from the
main syscall function instead, 'epoll_wait', which should keep this test
working in older kernels too.
Before:
# perf test BPF
40: BPF filter :
40.1: Basic BPF filtering : FAILED!
40.2: BPF pinning : Skip
40.3: BPF prologue generation : Skip
40.4: BPF relocation checker : Skip
If we use -v for that test we see the problem:
Probe point 'SyS_epoll_pwait' not found.
After:
# perf test BPF
40: BPF filter :
40.1: Basic BPF filtering : Ok
40.2: BPF pinning : Ok
40.3: BPF prologue generation : Ok
40.4: BPF relocation checker : Ok
#
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Dominik Brodowski <linux@dominikbrodowski.net>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/r/tip-y24nmn70cs2am8jh4i344dng@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
In the 'perf test "mmap interface"' we try creating events for several
tracepoints, but when perf_evsel__new() fails we're not showing which
one is failing, fix that to help diagnosing problems, such as the
syscall tracepoints ones being found and fixes in this merge window.
Now the failing tests shows:
# perf test -v "mmap interface"
4: Read samples using the mmap interface :
--- start ---
test child forked, pid 14311
<SNIP>
perf_evsel__new(sys_enter_getppid)
test child finished with -1
---- end ----
Read samples using the mmap interface: FAILED!
#
Now to check why the syscalls:sys_enter_getppid is failing...
# ls -la /sys/kernel/debug/tracing/events/syscalls/sys_enter_getppid
ls: cannot access '/sys/kernel/debug/tracing/events/syscalls/sys_enter_getppid': No such file or directory
#
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Dominik Brodowski <linux@dominikbrodowski.net>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/n/tip-44xk0ycdzrfzx1o9rklf5itl@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
With gcc 8 we get new set of snprintf() warnings that breaks the
compilation, one example:
tests/mem.c: In function ‘check’:
tests/mem.c:19:48: error: ‘%s’ directive output may be truncated writing \
up to 99 bytes into a region of size 89 [-Werror=format-truncation=]
snprintf(failure, sizeof failure, "unexpected %s", out);
The gcc docs says:
To avoid the warning either use a bigger buffer or handle the
function's return value which indicates whether or not its output
has been truncated.
Given that all these warnings are harmless, because the code either
properly fails due to uncomplete file path or we don't care for
truncated output at all, I'm changing all those snprintf() calls to
scnprintf(), which actually 'checks' for the snprint return value so the
gcc stays silent.
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Josh Poimboeuf <jpoimboe@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Link: http://lkml.kernel.org/r/20180319082902.4518-1-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
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 <sandipan@linux.vnet.ibm.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com>
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 <acme@redhat.com>
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 <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20180301165215.6780-1-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
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 <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Thomas Richter <tmricht@linux.vnet.ibm.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/n/tip-2k5kutwr4ds36adiakyb4yvy@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
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 <tmricht@linux.vnet.ibm.com>
Cc: Heiko Carstens <heiko.carstens@de.ibm.com>
Cc: Hendrik Brueckner <brueckner@linux.vnet.ibm.com>
Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
Link: http://lkml.kernel.org/r/20180214070303.55757-1-tmricht@linux.vnet.ibm.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
The symbol search called by machine__find_kernel_symbol_by_name is using
internally arch__compare_symbol_names function to compare 2 symbol
names, because different archs have different ways of comparing symbols.
Mostly for skipping '.' prefixes and similar.
In test 1 when we try to find matching symbols in kallsyms and vmlinux,
by address and by symbol name. When either is found we compare the pair
symbol names by simple strcmp, which is not good enough for reasons
explained in previous paragraph.
On powerpc this can cause lockup, because even thought we found the
pair, the compared names are different and don't match simple strcmp.
Following code path is executed, that leads to lockup:
- we find the pair in kallsyms by sym->start
next_pair:
- we compare the names and it fails
- we find the pair by sym->name
- the pair addresses match so we call goto next_pair
because we assume the names match in this case
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com>
Acked-by: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Fixes: 031b84c407 ("perf probe ppc: Enable matching against dot symbols automatically")
Link: http://lkml.kernel.org/r/20180215122635.24029-10-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
When we strip the perf binary, dwarf unwind test stop
to work. The reason is that strip will remove static
function symbols, which we need to check for unwind.
This change will keep this test working in cases where
the global symbols are put into dynamic symbol table,
which is the case on x86. It still won't work on powerpc.
Making those 5 local functions global, and adding
'test_dwarf_unwind__' to their names.
Committer testing:
Before:
# perf test dwarf
58: DWARF unwind : Ok
# strip ~/bin/perf
# perf test dwarf
58: DWARF unwind : FAILED!
# perf test -v dwarf
58: DWARF unwind :
--- start ---
test child forked, pid 6590
unwind: thread map already set, dso=/home/acme/bin/perf
<SNIP>
unwind: access_mem addr 0x7ffce6c48098 val 48563f, offset 1144
unwind: test__dwarf_unwind:ip = 0x4a54e5 (0xa54e5)
got: test__dwarf_unwind 0xa54e5, expecting test__dwarf_unwind
unwind: '':ip = 0x4a50bb (0xa50bb)
failed: got unresolved address 0xa50bb
unwind failed
test child finished with -1
---- end ----
DWARF unwind: FAILED!
#
After:
# perf test dwarf
58: DWARF unwind : Ok
# strip ~/bin/perf
# perf test dwarf
58: DWARF unwind : Ok
#
# perf test -v dwarf
58: DWARF unwind :
--- start ---
test child forked, pid 7219
unwind: thread map already set, dso=/home/acme/bin/perf
<SNIP>
unwind: access_mem addr 0x7fff007da2c8 val 48575f, offset 1144
unwind: test__arch_unwind_sample:ip = 0x589044 (0x189044)
got: test__arch_unwind_sample 0x189044, expecting test__arch_unwind_sample
unwind: test_dwarf_unwind__thread:ip = 0x4a52f7 (0xa52f7)
got: test_dwarf_unwind__thread 0xa52f7, expecting test_dwarf_unwind__thread
unwind: test_dwarf_unwind__compare:ip = 0x4a5468 (0xa5468)
got: test_dwarf_unwind__compare 0xa5468, expecting test_dwarf_unwind__compare
unwind: bsearch:ip = 0x7f6608ae94d8 (0x394d8)
got: bsearch 0x394d8, expecting bsearch
unwind: test_dwarf_unwind__krava_3:ip = 0x4a54d1 (0xa54d1)
got: test_dwarf_unwind__krava_3 0xa54d1, expecting test_dwarf_unwind__krava_3
unwind: test_dwarf_unwind__krava_2:ip = 0x4a550b (0xa550b)
got: test_dwarf_unwind__krava_2 0xa550b, expecting test_dwarf_unwind__krava_2
unwind: test_dwarf_unwind__krava_1:ip = 0x4a554b (0xa554b)
got: test_dwarf_unwind__krava_1 0xa554b, expecting test_dwarf_unwind__krava_1
unwind: test__dwarf_unwind:ip = 0x4a5605 (0xa5605)
got: test__dwarf_unwind 0xa5605, expecting test__dwarf_unwind
test child finished with 0
---- end ----
DWARF unwind: Ok
#
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20180206181813.10943-17-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
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 <tmricht@linux.vnet.ibm.com>
Reviewed-by: Hendrik Brueckner <brueckner@linux.vnet.ibm.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Heiko Carstens <heiko.carstens@de.ibm.com>
Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
Link: http://lkml.kernel.org/r/20180117083831.101001-1-tmricht@linux.vnet.ibm.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
When setting up DWARF callchains on specific events, without using
'record' or 'trace' --call-graph, but instead doing it like:
perf trace -e cycles/call-graph=dwarf/
The unwind__prepare_access() call in thread__insert_map() when we
process PERF_RECORD_MMAP(2) metadata events were not being performed,
precluding us from using per-event DWARF callchains, handling them just
when we asked for all events to be DWARF, using "--call-graph dwarf".
We do it in the PERF_RECORD_MMAP because we have to look at one of the
executable maps to figure out the executable type (64-bit, 32-bit) of
the DSO laid out in that mmap. Also to look at the architecture where
the perf.data file was recorded.
All this probably should be deferred to when we process a sample for
some thread that has callchains, so that we do this processing only for
the threads with samples, not for all of them.
For now, fix using DWARF on specific events.
Before:
# 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.048 ms
--- ::1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.048/0.048/0.048/0.000 ms
0.000 probe_libc:inet_pton:(7fe9597bb350))
Problem processing probe_libc:inet_pton callchain, skipping...
#
After:
# 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.060 ms
--- ::1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.060/0.060/0.060/0.000 ms
0.000 probe_libc:inet_pton:(7fd4aa930350))
__inet_pton (inlined)
gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
__GI_getaddrinfo (inlined)
[0xffffaa804e51af3f] (/usr/bin/ping)
__libc_start_main (/usr/lib64/libc-2.26.so)
[0xffffaa804e51b379] (/usr/bin/ping)
#
# perf trace --call-graph=dwarf --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.057 ms
--- ::1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.057/0.057/0.057/0.000 ms
0.000 probe_libc:inet_pton:(7f9363b9e350))
__inet_pton (inlined)
gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
__GI_getaddrinfo (inlined)
[0xffffa9e8a14e0f3f] (/usr/bin/ping)
__libc_start_main (/usr/lib64/libc-2.26.so)
[0xffffa9e8a14e1379] (/usr/bin/ping)
#
# perf trace --call-graph=fp --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.077 ms
--- ::1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.077/0.077/0.077/0.000 ms
0.000 probe_libc:inet_pton:(7f4947e1c350))
__inet_pton (inlined)
gaih_inet.constprop.7 (/usr/lib64/libc-2.26.so)
__GI_getaddrinfo (inlined)
[0xffffaa716d88ef3f] (/usr/bin/ping)
__libc_start_main (/usr/lib64/libc-2.26.so)
[0xffffaa716d88f379] (/usr/bin/ping)
#
# perf trace --no-syscalls -e probe_libc:inet_pton/call-graph=fp/ ping -6 -c 1 ::1
PING ::1(::1) 56 data bytes
64 bytes from ::1: icmp_seq=1 ttl=64 time=0.078 ms
--- ::1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.078/0.078/0.078/0.000 ms
0.000 probe_libc:inet_pton:(7fa157696350))
__GI___inet_pton (/usr/lib64/libc-2.26.so)
getaddrinfo (/usr/lib64/libc-2.26.so)
[0xffffa9ba39c74f40] (/usr/bin/ping)
#
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Hendrick Brueckner <brueckner@linux.vnet.ibm.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Thomas Richter <tmricht@linux.vnet.ibm.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/r/20180116182650.GE16107@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
The 'perf test bpf' was hooking a eBPF program on the SyS_epoll_wait()
kernel function, that was what the epoll_wait() glibc function ended up
calling, but since at least glibc 2.26, the one that comes with, for
instance, Fedora 27, glibc ends up calling SyS_epoll_pwait() when
epoll_wait() is used, causing this 'perf test' entry to fail.
So switch to using epoll_pwait() and hook the eBPF program to the
SyS_epoll_pwait() kernel function to make it work on a wider range of
glibc and kernel versions.
Tested-by: Wang Nan <wangnan0@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lkml.kernel.org/n/tip-zynvquy63er8s5mrgsz65pto@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
When failing on one of the BPF tests we were just stating:
BPF filter result incorrect
Add some more info to help figuring out the problem:
BPF filter result incorrect, expected 56, got 0 samples
This came out while investigating this failure, first seen after
updating the kernel to the 4.15.0-rc6 tag:
[root@jouet ~]# perf test bpf
39: BPF filter :
39.1: Basic BPF filtering : FAILED!
39.2: BPF pinning : Skip
39.3: BPF prologue generation: Skip
39.4: BPF relocation checker : Skip
[root@jouet ~]#
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: https://lkml.kernel.org/n/tip-403npu7daupv6b2bmxliv5pk@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
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 <tmricht@linux.vnet.ibm.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Suggested-by: Hendrik Brückner <brueckner@linux.vnet.ibm.com>
Reviewed-by: Hendrik Brückner <brueckner@linux.vnet.ibm.com>
Link: http://lkml.kernel.org/r/20171114133409.GN8836@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
