Re: [PATCH v11 perf, bpf-next 7/9] perf tools: synthesize PERF_RECORD_* for loaded BPF programs
From: Arnaldo Carvalho de Melo
Date: Tue Jan 22 2019 - 09:39:25 EST
Em Tue, Jan 22, 2019 at 12:13:20PM -0200, Arnaldo Carvalho de Melo escreveu:
> Em Fri, Jan 18, 2019 at 11:46:55AM -0300, Arnaldo Carvalho de Melo escreveu:
> > Em Thu, Jan 17, 2019 at 08:15:19AM -0800, Song Liu escreveu:
> > > This patch synthesize PERF_RECORD_KSYMBOL and PERF_RECORD_BPF_EVENT for
> > > BPF programs loaded before perf-record. This is achieved by gathering
> > > information about all BPF programs via sys_bpf.
> >
> > Ditto
>
> This is breaking 'perf sched', see below, the fix seems trivial:
>
> [root@quaco ~]# perf sched record -a sleep 2
> [ perf record: Woken up 1 times to write data ]
> 0x5b60 [0x138]: failed to process type: 17
> [ perf record: Captured and wrote 1.539 MB perf.data ]
> [root@quaco ~]# perf sched lat
> 0x5b60 [0x138]: failed to process type: 17
> Failed to process events, error -22
> [root@quaco ~]#
So:
perf_session__process_event (event->header.type = 17 (PERF_RECORD_KSYMBOL)
if (tool->ordered_events)
ret = perf_evlist__parse_sample_timestamp(evlist, event, ×tamp);
if (ret && ret != -1)
return ret;
So it returns here with -EFAULT, i.e. this is failing:
int perf_evlist__parse_sample_timestamp(struct perf_evlist *evlist,
union perf_event *event,
u64 *timestamp)
{
struct perf_evsel *evsel = perf_evlist__event2evsel(evlist, event);
if (!evsel)
return -EFAULT;
return perf_evsel__parse_sample_timestamp(evsel, event, timestamp);
}
It isn't mapping the event ID it finds back to an evsel.. Jiri, ideas?
This is happening so far only for 'perf sched', perf record with two
events works.
- Arnaldo
> [acme@quaco perf]$ git bisect good
> 7b612e291a5affb12b9d0b87332c71bcbe9c5db4 is the first bad commit
> commit 7b612e291a5affb12b9d0b87332c71bcbe9c5db4
> Author: Song Liu <songliubraving@xxxxxx>
> Date: Thu Jan 17 08:15:19 2019 -0800
>
> perf tools: Synthesize PERF_RECORD_* for loaded BPF programs
>
> This patch synthesize PERF_RECORD_KSYMBOL and PERF_RECORD_BPF_EVENT for
> BPF programs loaded before perf-record. This is achieved by gathering
> information about all BPF programs via sys_bpf.
>
> Committer notes:
>
> Fix the build on some older systems such as amazonlinux:1 where it was
> breaking with:
>
> util/bpf-event.c: In function 'perf_event__synthesize_one_bpf_prog':
> util/bpf-event.c:52:9: error: missing initializer for field 'type' of 'struct bpf_prog_info' [-Werror=missing-field-initializers]
> struct bpf_prog_info info = {};
> ^
> In file included from /git/linux/tools/lib/bpf/bpf.h:26:0,
> from util/bpf-event.c:3:
> /git/linux/tools/include/uapi/linux/bpf.h:2699:8: note: 'type' declared here
> __u32 type;
> ^
> cc1: all warnings being treated as errors
>
> Further fix on a centos:6 system:
>
> cc1: warnings being treated as errors
> util/bpf-event.c: In function 'perf_event__synthesize_one_bpf_prog':
> util/bpf-event.c:50: error: 'func_info_rec_size' may be used uninitialized in this function
>
> The compiler is wrong, but to silence it, initialize that variable to
> zero.
>
> One more fix, this time for debian:experimental-x-mips, x-mips64 and
> x-mipsel:
>
> util/bpf-event.c: In function 'perf_event__synthesize_one_bpf_prog':
> util/bpf-event.c:93:16: error: implicit declaration of function 'calloc' [-Werror=implicit-function-declaration]
> func_infos = calloc(sub_prog_cnt, func_info_rec_size);
> ^~~~~~
> util/bpf-event.c:93:16: error: incompatible implicit declaration of built-in function 'calloc' [-Werror]
> util/bpf-event.c:93:16: note: include '<stdlib.h>' or provide a declaration of 'calloc'
>
> Add the missing header.
>
> Committer testing:
>
> # perf record --bpf-event sleep 1
> [ perf record: Woken up 1 times to write data ]
> [ perf record: Captured and wrote 0.021 MB perf.data (7 samples) ]
> # perf report -D | grep PERF_RECORD_BPF_EVENT | nl
> 1 0 0x4b10 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 13
> 2 0 0x4c60 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 14
> 3 0 0x4db0 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 15
> 4 0 0x4f00 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 16
> 5 0 0x5050 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 17
> 6 0 0x51a0 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 18
> 7 0 0x52f0 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 21
> 8 0 0x5440 [0x18]: PERF_RECORD_BPF_EVENT bpf event with type 1, flags 0, id 22
> # bpftool prog
> 13: cgroup_skb tag 7be49e3934a125ba gpl
> loaded_at 2019-01-19T09:09:43-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 13,14
> 14: cgroup_skb tag 2a142ef67aaad174 gpl
> loaded_at 2019-01-19T09:09:43-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 13,14
> 15: cgroup_skb tag 7be49e3934a125ba gpl
> loaded_at 2019-01-19T09:09:43-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 15,16
> 16: cgroup_skb tag 2a142ef67aaad174 gpl
> loaded_at 2019-01-19T09:09:43-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 15,16
> 17: cgroup_skb tag 7be49e3934a125ba gpl
> loaded_at 2019-01-19T09:09:44-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 17,18
> 18: cgroup_skb tag 2a142ef67aaad174 gpl
> loaded_at 2019-01-19T09:09:44-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 17,18
> 21: cgroup_skb tag 7be49e3934a125ba gpl
> loaded_at 2019-01-19T09:09:45-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 21,22
> 22: cgroup_skb tag 2a142ef67aaad174 gpl
> loaded_at 2019-01-19T09:09:45-0300 uid 0
> xlated 296B jited 229B memlock 4096B map_ids 21,22
> #
>
> # perf report -D | grep -B22 PERF_RECORD_KSYMBOL
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 ff 44 06 c0 ff ff ff ff ......8..D......
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 37 62 65 34 39 65 33 39 33 34 61 31 32 35 62 _7be49e3934a125b
> . 0030: 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 7b e4 9e 39 34 a1 25 ba 00 00 00 00 00 00 00 00 {..94.%.........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x49d8 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc00644ff len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 48 6d 06 c0 ff ff ff ff ......8.Hm......
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 32 61 31 34 32 65 66 36 37 61 61 61 64 31 37 _2a142ef67aaad17
> . 0030: 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 2a 14 2e f6 7a aa d1 74 00 00 00 00 00 00 00 00 *...z..t........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x4b28 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0066d48 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 04 cf 03 c0 ff ff ff ff ......8.........
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 37 62 65 34 39 65 33 39 33 34 61 31 32 35 62 _7be49e3934a125b
> . 0030: 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 7b e4 9e 39 34 a1 25 ba 00 00 00 00 00 00 00 00 {..94.%.........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x4c78 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc003cf04 len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 96 28 04 c0 ff ff ff ff ......8..(......
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 32 61 31 34 32 65 66 36 37 61 61 61 64 31 37 _2a142ef67aaad17
> . 0030: 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 2a 14 2e f6 7a aa d1 74 00 00 00 00 00 00 00 00 *...z..t........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x4dc8 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0042896 len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 05 13 17 c0 ff ff ff ff ......8.........
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 37 62 65 34 39 65 33 39 33 34 61 31 32 35 62 _7be49e3934a125b
> . 0030: 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 7b e4 9e 39 34 a1 25 ba 00 00 00 00 00 00 00 00 {..94.%.........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x4f18 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0171305 len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 0a 8c 23 c0 ff ff ff ff ......8...#.....
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 32 61 31 34 32 65 66 36 37 61 61 61 64 31 37 _2a142ef67aaad17
> . 0030: 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 2a 14 2e f6 7a aa d1 74 00 00 00 00 00 00 00 00 *...z..t........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x5068 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0238c0a len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 2a a5 a4 c0 ff ff ff ff ......8.*.......
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 37 62 65 34 39 65 33 39 33 34 61 31 32 35 62 _7be49e3934a125b
> . 0030: 61 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 7b e4 9e 39 34 a1 25 ba 00 00 00 00 00 00 00 00 {..94.%.........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x51b8 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0a4a52a len 229 type 1 flags 0x0 name bpf_prog_7be49e3934a125ba
> --
> . ... raw event: size 312 bytes
> . 0000: 11 00 00 00 00 00 38 01 9b c9 a4 c0 ff ff ff ff ......8.........
> . 0010: e5 00 00 00 01 00 00 00 62 70 66 5f 70 72 6f 67 ........bpf_prog
> . 0020: 5f 32 61 31 34 32 65 66 36 37 61 61 61 64 31 37 _2a142ef67aaad17
> . 0030: 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4...............
> <SNIP zeroes>
> . 0110: 00 00 00 00 00 00 00 00 21 00 00 00 00 00 00 00 ........!.......
> . 0120: 2a 14 2e f6 7a aa d1 74 00 00 00 00 00 00 00 00 *...z..t........
> . 0130: 00 00 00 00 00 00 00 00 ........
>
> 0 0x5308 [0x138]: PERF_RECORD_KSYMBOL ksymbol event with addr ffffffffc0a4c99b len 229 type 1 flags 0x0 name bpf_prog_2a142ef67aaad174
>
> Signed-off-by: Song Liu <songliubraving@xxxxxx>
> Reviewed-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> Tested-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
> Cc: Alexei Starovoitov <ast@xxxxxxxxxx>
> Cc: Daniel Borkmann <daniel@xxxxxxxxxxxxx>
> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> Cc: kernel-team@xxxxxx
> Cc: netdev@xxxxxxxxxxxxxxx
> Link: http://lkml.kernel.org/r/20190117161521.1341602-8-songliubraving@xxxxxx
> Signed-off-by: Arnaldo Carvalho de Melo <acme@xxxxxxxxxx>
>
> :040000 040000 811377248529490fc3977be729bd1ac6ab515920 3f1cc9a3e8c92d0d5a23a21c33286b7cdf758534 M tools
> [acme@quaco perf]$
--
- Arnaldo