Re: perf test BPF failing on 4.15.0-rc6

From: Arnaldo Carvalho de Melo
Date: Wed Jan 03 2018 - 13:27:15 EST

Next message: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Previous message: Stefan Chulski: "RE: [EXT] Re: [PATCH net-next 5/6] arm64: dts: marvell: mcbin: enable the fourth network interface"
In reply to: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Next in thread: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Em Wed, Jan 03, 2018 at 01:58:44PM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Wed, Jan 03, 2018 at 12:58:26PM +0800, Wangnan (F) escreveu:
> > And please check if the kprobe created by
> >
> > $ perf probe -v SyS_epoll_wait
>
> [root@seventh ~]# perf probe -v SyS_epoll_wait
> probe-definition(0): SyS_epoll_wait
> symbol:SyS_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
> 0 arguments
> Looking at the vmlinux_path (8 entries long)
> Using /usr/lib/debug/lib/modules/4.14.8-300.fc27.x86_64/vmlinux for symbols
> Open Debuginfo file: /usr/lib/debug/lib/modules/4.14.8-300.fc27.x86_64/vmlinux
> Try to find probe point from debuginfo.
> Matched function: SyS_epoll_wait [314b563]
> found inline addr: 0xffffffff812d8087
> Probe point found: compat_SyS_epoll_pwait+151
> found inline addr: 0xffffffff812d7e5a
> Probe point found: SyS_epoll_pwait+138
> found inline addr: 0xffffffff812d7cf0
> Probe point found: SyS_epoll_wait+0
> Found 3 probe_trace_events.
> Opening /sys/kernel/debug/tracing//kprobe_events write=1
> Writing event: p:probe/SyS_epoll_wait _text+2982023
> Writing event: p:probe/SyS_epoll_wait_1 _text+2981466
> Writing event: p:probe/SyS_epoll_wait_2 _text+2981104
> Added new events:
> probe:SyS_epoll_wait (on SyS_epoll_wait)
> probe:SyS_epoll_wait_1 (on SyS_epoll_wait)
> probe:SyS_epoll_wait_2 (on SyS_epoll_wait)
>
> You can now use it in all perf tools, such as:
>
> perf record -e probe:SyS_epoll_wait_2 -aR sleep 1
>
> [root@seventh ~]#
>
> Then, with your proggie, it seems its glibc that now maps epoll_wait()
> to a different syscall than in older systems:
>
> [root@seventh ~]# trace -e probe:SyS_epoll_wait* ~acme/epoll
> 0.018 ( 0.001 ms): epoll/20444 brk( ) = 0x2600000
> 0.029 ( 0.004 ms): epoll/20444 access(filename: 0xe874ec0, mode: R ) = -1 ENOENT No such file or directory
> 0.035 ( 0.003 ms): epoll/20444 openat(dfd: CWD, filename: 0xe872726, flags: CLOEXEC ) = 3
> 0.040 ( 0.002 ms): epoll/20444 fstat(fd: 3, statbuf: 0x7fffcc37b830 ) = 0
> 0.042 ( 0.002 ms): epoll/20444 mmap(len: 109538, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fc50ea5d000
> 0.045 ( 0.001 ms): epoll/20444 close(fd: 3 ) = 0
> 0.052 ( 0.003 ms): epoll/20444 openat(dfd: CWD, filename: 0xea7ace0, flags: CLOEXEC ) = 3
> 0.056 ( 0.001 ms): epoll/20444 read(fd: 3, buf: 0x7fffcc37b9f8, count: 832 ) = 832
> 0.059 ( 0.001 ms): epoll/20444 fstat(fd: 3, statbuf: 0x7fffcc37b890 ) = 0
> 0.060 ( 0.002 ms): epoll/20444 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1 ) = 0x7fc50ea5b000
> 0.065 ( 0.003 ms): epoll/20444 mmap(len: 4074112, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3 ) = 0x7fc50e46e000
> 0.068 ( 0.004 ms): epoll/20444 mprotect(start: 0x7fc50e648000, len: 2093056 ) = 0
> 0.073 ( 0.004 ms): epoll/20444 mmap(addr: 0x7fc50e847000, len: 24576, prot: READ|WRITE, flags: PRIVATE|DENYWRITE|FIXED, fd: 3, off: 1937408) = 0x7fc50e847000
> 0.079 ( 0.002 ms): epoll/20444 mmap(addr: 0x7fc50e84d000, len: 14976, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS|FIXED, fd: -1) = 0x7fc50e84d000
> 0.085 ( 0.001 ms): epoll/20444 close(fd: 3 ) = 0
> 0.093 ( 0.001 ms): epoll/20444 arch_prctl(option: 4098, arg2: 140484331029696 ) = 0
> 0.128 ( 0.003 ms): epoll/20444 mprotect(start: 0x7fc50e847000, len: 16384, prot: READ ) = 0
> 0.133 ( 0.002 ms): epoll/20444 mprotect(start: 0x600000, len: 4096, prot: READ ) = 0
> 0.137 ( 0.002 ms): epoll/20444 mprotect(start: 0x7fc50ea78000, len: 4096, prot: READ ) = 0
> 0.140 ( 0.005 ms): epoll/20444 munmap(addr: 0x7fc50ea5d000, len: 109538 ) = 0
> 0.159 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -1, sigsetsize: 8 ) = -22
> 0.160 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -2, sigsetsize: 8 ) = -22
> 0.162 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -3, sigsetsize: 8 ) = -22
> 0.163 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -4, sigsetsize: 8 ) = -22
> 0.165 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -5, sigsetsize: 8 ) = -22
> <SNIP>
> 0.279 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -85, sigsetsize: 8 ) = -22
> 0.280 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -86, sigsetsize: 8 ) = -22
> 0.282 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -87, sigsetsize: 8 ) = -22
> 0.283 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -88, sigsetsize: 8 ) = -22
> 0.284 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -89, sigsetsize: 8 ) = -22
> 0.286 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -90, sigsetsize: 8 ) = -22
> 0.287 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -91, sigsetsize: 8 ) = -22
> 0.289 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -92, sigsetsize: 8 ) = -22
> 0.290 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -93, sigsetsize: 8 ) = -22
> 0.292 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -94, sigsetsize: 8 ) = -22
> 0.293 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -95, sigsetsize: 8 ) = -22
> 0.294 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -96, sigsetsize: 8 ) = -22
> 0.296 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -97, sigsetsize: 8 ) = -22
> 0.297 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -98, sigsetsize: 8 ) = -22
> 0.299 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -99, sigsetsize: 8 ) = -22
> 0.300 ( 0.001 ms): epoll/20444 epoll_pwait(epfd: -100, sigsetsize: 8 ) = -22
> 0.305 ( ? ): epoll/20444 exit_group( )
> [root@seventh ~]#
>
> This is on a Fedora 27 system, that has glibc 2.26, while on a RHEL7
> machine, that has glibc 2.17, it still uses epoll_wait() and we get:
>
> [root@felicio ~]# trace ./epoll
> 0.018 ( 0.001 ms): epoll/2818 brk( ) = 0x8e5000
> 0.033 ( 0.002 ms): epoll/2818 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7f3f738e3000
> 0.041 ( 0.004 ms): epoll/2818 access(filename: 0x736e2160, mode: R ) = -1 ENOENT No such file or directory
> 0.051 ( 0.003 ms): epoll/2818 open(filename: 0x736e0a58, flags: CLOEXEC ) = 3
> 0.056 ( 0.001 ms): epoll/2818 fstat(fd: 3, statbuf: 0x7fff8b35f5b0 ) = 0
> 0.057 ( 0.002 ms): epoll/2818 mmap(len: 78559, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7f3f738cf000
> 0.060 ( 0.001 ms): epoll/2818 close(fd: 3 ) = 0
> 0.070 ( 0.005 ms): epoll/2818 open(filename: 0x738e3640, flags: CLOEXEC ) = 3
> 0.076 ( 0.001 ms): epoll/2818 read(fd: 3, buf: 0x7fff8b35f770, count: 832 ) = 832
> 0.079 ( 0.001 ms): epoll/2818 fstat(fd: 3, statbuf: 0x7fff8b35f610 ) = 0
> 0.082 ( 0.003 ms): epoll/2818 mmap(len: 3932672, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3 ) = 0x7f3f73304000
> 0.086 ( 0.005 ms): epoll/2818 mprotect(start: 0x7f3f734bb000, len: 2093056 ) = 0
> 0.091 ( 0.005 ms): epoll/2818 mmap(addr: 0x7f3f736ba000, len: 24576, prot: READ|WRITE, flags: PRIVATE|DENYWRITE|FIXED, fd: 3, off: 1794048) = 0x7f3f736ba000
> 0.100 ( 0.003 ms): epoll/2818 mmap(addr: 0x7f3f736c0000, len: 16896, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS|FIXED) = 0x7f3f736c0000
> 0.106 ( 0.001 ms): epoll/2818 close(fd: 3 ) = 0
> 0.115 ( 0.002 ms): epoll/2818 mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7f3f738ce000
> 0.119 ( 0.002 ms): epoll/2818 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7f3f738cc000
> 0.123 ( 0.001 ms): epoll/2818 arch_prctl(option: 4098, arg2: 139910498273088, arg3: 139910498275408, arg4: 34, arg5: -1) = 0
> 0.181 ( 0.003 ms): epoll/2818 mprotect(start: 0x7f3f736ba000, len: 16384, prot: READ ) = 0
> 0.186 ( 0.002 ms): epoll/2818 mprotect(start: 0x600000, len: 4096, prot: READ ) = 0
> 0.190 ( 0.002 ms): epoll/2818 mprotect(start: 0x7f3f738e4000, len: 4096, prot: READ ) = 0
> 0.193 ( 0.004 ms): epoll/2818 munmap(addr: 0x7f3f738cf000, len: 78559 ) = 0
> 0.218 ( 0.001 ms): epoll/2818 epoll_wait(epfd: -1 ) = -1 EINVAL Invalid argument
> 0.220 ( 0.000 ms): epoll/2818 epoll_wait(epfd: -2 ) = -1 EINVAL Invalid argument
> 0.221 ( 0.000 ms): epoll/2818 epoll_wait(epfd: -3 ) = -1 EINVAL Invalid argument
> 0.221 ( 0.000 ms): epoll/2818 epoll_wait(epfd: -4 ) = -1 EINVAL Invalid argument
> 0.222 ( 0.000 ms): epoll/2818 epoll_wait(epfd: -5 ) = -1 EINVAL Invalid argument
> <SNIP>
>
> It thought that this part would cover it:
>
> Probe point found: SyS_epoll_pwait+138
> found inline addr: 0xffffffff812d7cf0
>
> Continuing investigation...

After applying the fallback patch to allow new tools to work with older
kernels:

[root@felicio ~]# perf test bpf
39: BPF filter :
39.1: Basic BPF filtering : Ok
39.2: BPF pinning : Ok
39.3: BPF prologue generation : Ok
39.4: BPF relocation checker : Ok
[root@felicio ~]# uname -a
Linux felicio.ghostprotocols.net 4.13.0-rc7+ #1 SMP Mon Sep 11 13:56:18 -03 2017 x86_64 x86_64 x86_64 GNU/Linux
[root@felicio ~]# rpm -q glibc
glibc-2.17-157.el7_3.2.x86_64
[root@felicio ~]#

After applying the patch below I get to, which is what I am trying to
fix now:

[root@jouet ~]# perf test bpf
39: BPF filter :
39.1: Basic BPF filtering : Ok
39.2: BPF pinning : Ok
39.3: BPF prologue generation : FAILED!
39.4: BPF relocation checker : Skip
[root@jouet ~]#

Its related to:

<stdin>:11:10: fatal error: 'uapi/linux/fs.h' file not found
#include <uapi/linux/fs.h>
^~~~~~~~~~~~~~~~~
1 error generated.
ERROR: unable to compile -
Hint: Check error message shown above.
Hint: You can also pre-compile it into .o using:
clang -target bpf -O2 -c -
with proper -I and -D options.
Failed to compile test case: 'Compile source for BPF prologue generation'
Unable to get BPF object, fix kbuild first
test child finished with -1
---- end ----
BPF filter subtest 2: FAILED!

- Arnaldo

diff --git a/tools/perf/tests/bpf-script-example.c b/tools/perf/tests/bpf-script-example.c
index 268e5f8e4aa2..d1e67e271675 100644
--- a/tools/perf/tests/bpf-script-example.c
+++ b/tools/perf/tests/bpf-script-example.c
@@ -31,7 +31,7 @@ struct bpf_map_def SEC("maps") flip_table = {
.max_entries = 1,
};

-SEC("func=SyS_epoll_wait")
+SEC("func=SyS_epoll_pwait")
int bpf_func__SyS_epoll_wait(void *ctx)
{
int ind =0;

Next message: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Previous message: Stefan Chulski: "RE: [EXT] Re: [PATCH net-next 5/6] arm64: dts: marvell: mcbin: enable the fourth network interface"
In reply to: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Next in thread: Arnaldo Carvalho de Melo: "Re: perf test BPF failing on 4.15.0-rc6"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]