| Message ID | 20190117161521.1341602-8-songliubraving@fb.com |
|---|---|
| State | Not Applicable |
| Delegated to: | BPF Maintainers |
| Headers | show |
| Series | reveal invisible bpf programs | expand |
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 > Signed-off-by: Song Liu <songliubraving@fb.com> > --- > tools/perf/builtin-record.c | 6 + > tools/perf/util/bpf-event.c | 241 ++++++++++++++++++++++++++++++++++++ > tools/perf/util/bpf-event.h | 5 + > 3 files changed, 252 insertions(+) > > diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c > index deaf9b902094..88ea11d57c6f 100644 > --- a/tools/perf/builtin-record.c > +++ b/tools/perf/builtin-record.c > @@ -41,6 +41,7 @@ > #include "util/perf-hooks.h" > #include "util/time-utils.h" > #include "util/units.h" > +#include "util/bpf-event.h" > #include "asm/bug.h" > > #include <errno.h> > @@ -1082,6 +1083,11 @@ static int record__synthesize(struct record *rec, bool tail) > return err; > } > > + err = perf_event__synthesize_bpf_events(tool, process_synthesized_event, > + machine, opts); > + if (err < 0) > + pr_warning("Couldn't synthesize bpf events.\n"); > + > err = __machine__synthesize_threads(machine, tool, &opts->target, rec->evlist->threads, > process_synthesized_event, opts->sample_address, > 1); > diff --git a/tools/perf/util/bpf-event.c b/tools/perf/util/bpf-event.c > index 87004706874f..126f9728a756 100644 > --- a/tools/perf/util/bpf-event.c > +++ b/tools/perf/util/bpf-event.c > @@ -1,10 +1,24 @@ > // SPDX-License-Identifier: GPL-2.0 > #include <errno.h> > #include <bpf/bpf.h> > +#include <bpf/btf.h> > +#include <linux/btf.h> > #include "bpf-event.h" > #include "debug.h" > #include "symbol.h" > > +#define ptr_to_u64(ptr) ((__u64)(unsigned long)(ptr)) > + > +static int snprintf_hex(char *buf, size_t size, unsigned char *data, size_t len) > +{ > + int ret = 0; > + size_t i; > + > + for (i = 0; i < len; i++) > + ret += snprintf(buf + ret, size - ret, "%02x", data[i]); > + return ret; > +} > + > int machine__process_bpf_event(struct machine *machine __maybe_unused, > union perf_event *event, > struct perf_sample *sample __maybe_unused) > @@ -13,3 +27,230 @@ int machine__process_bpf_event(struct machine *machine __maybe_unused, > perf_event__fprintf_bpf_event(event, stdout); > return 0; > } > + > +/* > + * Synthesize PERF_RECORD_KSYMBOL and PERF_RECORD_BPF_EVENT for one bpf > + * program. One PERF_RECORD_BPF_EVENT is generated for the program. And > + * one PERF_RECORD_KSYMBOL is generated for each sub program. > + * > + * Returns: > + * 0 for success; > + * -1 for failures; > + * -2 for lack of kernel support. > + */ > +static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, > + perf_event__handler_t process, > + struct machine *machine, > + int fd, > + union perf_event *event, > + struct record_opts *opts) > +{ > + struct ksymbol_event *ksymbol_event = &event->ksymbol_event; > + struct bpf_event *bpf_event = &event->bpf_event; > + u32 sub_prog_cnt, i, func_info_rec_size; > + u8 (*prog_tags)[BPF_TAG_SIZE] = NULL; > + struct bpf_prog_info info = {}; > + u32 info_len = sizeof(info); > + void *func_infos = NULL; > + u64 *prog_addrs = NULL; > + struct btf *btf = NULL; > + u32 *prog_lens = NULL; > + bool has_btf = false; > + char errbuf[512]; > + int err = 0; > + > + /* Call bpf_obj_get_info_by_fd() to get sizes of arrays */ > + err = bpf_obj_get_info_by_fd(fd, &info, &info_len); > + > + if (err) { > + pr_debug("%s: failed to get BPF program info: %s, aborting\n", > + __func__, str_error_r(errno, errbuf, sizeof(errbuf))); > + return -1; > + } > + if (info_len < offsetof(struct bpf_prog_info, prog_tags)) { > + pr_debug("%s: the kernel is too old, aborting\n", __func__); > + return -2; > + } > + > + /* number of ksyms, func_lengths, and tags should match */ > + sub_prog_cnt = info.nr_jited_ksyms; > + if (sub_prog_cnt != info.nr_prog_tags || > + sub_prog_cnt != info.nr_jited_func_lens) > + return -1; > + > + /* check BTF func info support */ > + if (info.btf_id && info.nr_func_info && info.func_info_rec_size) { > + /* btf func info number should be same as sub_prog_cnt */ > + if (sub_prog_cnt != info.nr_func_info) { > + pr_debug("%s: mismatch in BPF sub program count and BTF function info count, aborting\n", __func__); > + return -1; > + } > + if (btf__get_from_id(info.btf_id, &btf)) { > + pr_debug("%s: failed to get BTF of id %u, aborting\n", __func__, info.btf_id); > + return -1; > + } > + func_info_rec_size = info.func_info_rec_size; > + func_infos = calloc(sub_prog_cnt, func_info_rec_size); > + if (!func_infos) { > + pr_debug("%s: failed to allocate memory for func_infos, aborting\n", __func__); > + return -1; > + } > + has_btf = true; > + } > + > + /* > + * We need address, length, and tag for each sub program. > + * Allocate memory and call bpf_obj_get_info_by_fd() again > + */ > + prog_addrs = calloc(sub_prog_cnt, sizeof(u64)); > + if (!prog_addrs) { > + pr_debug("%s: failed to allocate memory for prog_addrs, aborting\n", __func__); > + goto out; > + } > + prog_lens = calloc(sub_prog_cnt, sizeof(u32)); > + if (!prog_lens) { > + pr_debug("%s: failed to allocate memory for prog_lens, aborting\n", __func__); > + goto out; > + } > + prog_tags = calloc(sub_prog_cnt, BPF_TAG_SIZE); > + if (!prog_tags) { > + pr_debug("%s: failed to allocate memory for prog_tags, aborting\n", __func__); > + goto out; > + } > + > + memset(&info, 0, sizeof(info)); > + info.nr_jited_ksyms = sub_prog_cnt; > + info.nr_jited_func_lens = sub_prog_cnt; > + info.nr_prog_tags = sub_prog_cnt; > + info.jited_ksyms = ptr_to_u64(prog_addrs); > + info.jited_func_lens = ptr_to_u64(prog_lens); > + info.prog_tags = ptr_to_u64(prog_tags); > + info_len = sizeof(info); > + if (has_btf) { > + info.nr_func_info = sub_prog_cnt; > + info.func_info_rec_size = func_info_rec_size; > + info.func_info = ptr_to_u64(func_infos); > + } > + > + err = bpf_obj_get_info_by_fd(fd, &info, &info_len); > + if (err) { > + pr_debug("%s: failed to get BPF program info, aborting\n", __func__); > + goto out; > + } > + > + /* Synthesize PERF_RECORD_KSYMBOL */ > + for (i = 0; i < sub_prog_cnt; i++) { > + const struct bpf_func_info *finfo; > + const char *short_name = NULL; > + const struct btf_type *t; > + int name_len; > + > + *ksymbol_event = (struct ksymbol_event){ > + .header = { > + .type = PERF_RECORD_KSYMBOL, > + .size = sizeof(struct ksymbol_event), > + }, > + .addr = prog_addrs[i], > + .len = prog_lens[i], > + .ksym_type = PERF_RECORD_KSYMBOL_TYPE_BPF, > + .flags = 0, > + }; > + name_len = snprintf(ksymbol_event->name, KSYM_NAME_LEN, > + "bpf_prog_"); > + name_len += snprintf_hex(ksymbol_event->name + name_len, > + KSYM_NAME_LEN - name_len, > + prog_tags[i], BPF_TAG_SIZE); > + if (has_btf) { > + finfo = func_infos + i * info.func_info_rec_size; > + t = btf__type_by_id(btf, finfo->type_id); > + short_name = btf__name_by_offset(btf, t->name_off); > + } else if (i == 0 && sub_prog_cnt == 1) { > + /* no subprog */ > + if (info.name[0]) > + short_name = info.name; > + } else > + short_name = "F"; > + if (short_name) > + name_len += snprintf(ksymbol_event->name + name_len, > + KSYM_NAME_LEN - name_len, > + "_%s", short_name); > + > + ksymbol_event->header.size += PERF_ALIGN(name_len + 1, > + sizeof(u64)); > + err = perf_tool__process_synth_event(tool, event, > + machine, process); > + } > + > + /* Synthesize PERF_RECORD_BPF_EVENT */ > + if (opts->bpf_event) { > + *bpf_event = (struct bpf_event){ > + .header = { > + .type = PERF_RECORD_BPF_EVENT, > + .size = sizeof(struct bpf_event), > + }, > + .type = PERF_BPF_EVENT_PROG_LOAD, > + .flags = 0, > + .id = info.id, > + }; > + memcpy(bpf_event->tag, prog_tags[i], BPF_TAG_SIZE); > + err = perf_tool__process_synth_event(tool, event, > + machine, process); > + } > + > +out: > + free(prog_tags); > + free(prog_lens); > + free(prog_addrs); > + free(func_infos); > + free(btf); > + return err ? -1 : 0; > +} > + > +int perf_event__synthesize_bpf_events(struct perf_tool *tool, > + perf_event__handler_t process, > + struct machine *machine, > + struct record_opts *opts) > +{ > + union perf_event *event; > + __u32 id = 0; > + int err; > + int fd; > + > + event = malloc(sizeof(event->bpf_event) + KSYM_NAME_LEN); > + if (!event) > + return -1; > + while (true) { > + err = bpf_prog_get_next_id(id, &id); > + if (err) { > + if (errno == ENOENT) { > + err = 0; > + break; > + } > + pr_debug("%s: can't get next program: %s%s", > + __func__, strerror(errno), > + errno == EINVAL ? " -- kernel too old?" : ""); > + /* don't report error on old kernel */ > + err = (errno == EINVAL) ? 0 : -1; > + break; > + } > + fd = bpf_prog_get_fd_by_id(id); > + if (fd < 0) { > + pr_debug("%s: failed to get fd for prog_id %u\n", > + __func__, id); > + continue; > + } > + > + err = perf_event__synthesize_one_bpf_prog(tool, process, > + machine, fd, > + event, opts); > + close(fd); > + if (err) { > + /* do not return error for old kernel */ > + if (err == -2) > + err = 0; > + break; > + } > + } > + free(event); > + return err; > +} > diff --git a/tools/perf/util/bpf-event.h b/tools/perf/util/bpf-event.h > index d5ca355dd298..38aee4040f12 100644 > --- a/tools/perf/util/bpf-event.h > +++ b/tools/perf/util/bpf-event.h > @@ -8,4 +8,9 @@ int machine__process_bpf_event(struct machine *machine, > union perf_event *event, > struct perf_sample *sample); > > +int perf_event__synthesize_bpf_events(struct perf_tool *tool, > + perf_event__handler_t process, > + struct machine *machine, > + struct record_opts *opts); > + > #endif > -- > 2.17.1
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 ~]# [acme@quaco perf]$ git bisect good 7b612e291a5affb12b9d0b87332c71bcbe9c5db4 is the first bad commit commit 7b612e291a5affb12b9d0b87332c71bcbe9c5db4 Author: Song Liu <songliubraving@fb.com> 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@fb.com> Reviewed-by: Arnaldo Carvalho de Melo <acme@redhat.com> Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> Cc: Alexei Starovoitov <ast@kernel.org> Cc: Daniel Borkmann <daniel@iogearbox.net> Cc: Peter Zijlstra <peterz@infradead.org> Cc: kernel-team@fb.com Cc: netdev@vger.kernel.org Link: http://lkml.kernel.org/r/20190117161521.1341602-8-songliubraving@fb.com Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> :040000 040000 811377248529490fc3977be729bd1ac6ab515920 3f1cc9a3e8c92d0d5a23a21c33286b7cdf758534 M tools [acme@quaco perf]$
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@fb.com> > 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@fb.com> > Reviewed-by: Arnaldo Carvalho de Melo <acme@redhat.com> > Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com> > Cc: Alexei Starovoitov <ast@kernel.org> > Cc: Daniel Borkmann <daniel@iogearbox.net> > Cc: Peter Zijlstra <peterz@infradead.org> > Cc: kernel-team@fb.com > Cc: netdev@vger.kernel.org > Link: http://lkml.kernel.org/r/20190117161521.1341602-8-songliubraving@fb.com > Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com> > > :040000 040000 811377248529490fc3977be729bd1ac6ab515920 3f1cc9a3e8c92d0d5a23a21c33286b7cdf758534 M tools > [acme@quaco perf]$
Em Tue, Jan 22, 2019 at 12:31:17PM -0200, Arnaldo Carvalho de Melo escreveu: > 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. So it fails for tracepoints with plain 'perf record': [root@quaco tmp]# perf record -e sched:sched* sleep 1 [ perf record: Woken up 29 times to write data ] 0x6658 [0x138]: failed to process type: 17 [ perf record: Captured and wrote 0.029 MB perf.data ] [root@quaco tmp]# perf script 0x6658 [0x138]: failed to process type: 17 [root@quaco tmp]# [ perf record: Woken up 1 times to write data ] Breakpoint 1, reader__process_events (rd=0x7ffffffe4160, session=0xab66a0, prog=0x7ffffffe4180) at util/session.c:1911 1911 pr_err("%#" PRIx64 " [%#x]: failed to process type: %d\n", Missing separate debuginfos, use: dnf debuginfo-install bzip2-libs-1.0.6-28.fc29.x86_64 elfutils-libelf-0.174-5.fc29.x86_64 elfutils-libs-0.174-5.fc29.x86_64 glib2-2.58.2-1.fc29.x86_64 libbabeltrace-1.5.6-1.fc29.x86_64 libunwind-1.2.1-6.fc29.x86_64 libuuid-2.32.1-1.fc29.x86_64 libxcrypt-4.4.2-3.fc29.x86_64 numactl-libs-2.0.12-1.fc29.x86_64 openssl-libs-1.1.1a-1.fc29.x86_64 pcre-8.42-6.fc29.x86_64 perl-libs-5.28.1-427.fc29.x86_64 popt-1.16-15.fc29.x86_64 python2-libs-2.7.15-11.fc29.x86_64 slang-2.3.2-4.fc29.x86_64 xz-libs-5.2.4-3.fc29.x86_64 (gdb) bt #0 reader__process_events (rd=0x7ffffffe4160, session=0xab66a0, prog=0x7ffffffe4180) at util/session.c:1911 #1 0x0000000000540deb in __perf_session__process_events (session=0xab66a0) at util/session.c:1955 #2 0x0000000000540f1c in perf_session__process_events (session=0xab66a0) at util/session.c:1988 #3 0x0000000000445feb in process_buildids (rec=0x9202a0 <record>) at builtin-record.c:689 #4 0x0000000000446597 in record__finish_output (rec=0x9202a0 <record>) at builtin-record.c:846 #5 0x0000000000447b8c in __cmd_record (rec=0x9202a0 <record>, argc=2, argv=0xab4720) at builtin-record.c:1429 #6 0x0000000000448d64 in cmd_record (argc=2, argv=0xab4720) at builtin-record.c:2153 #7 0x00000000004406dd in __cmd_record (argc=3, argv=0x7fffffffdb30) at builtin-sched.c:3339 #8 0x00000000004411ff in cmd_sched (argc=3, argv=0x7fffffffdb30) at builtin-sched.c:3486 #9 0x00000000004d46e3 in run_builtin (p=0x932c50 <commands+432>, argc=4, argv=0x7fffffffdb30) at perf.c:302 #10 0x00000000004d4950 in handle_internal_command (argc=4, argv=0x7fffffffdb30) at perf.c:354 #11 0x00000000004d4a9f in run_argv (argcp=0x7fffffffd98c, argv=0x7fffffffd980) at perf.c:398 #12 0x00000000004d4e0b in main (argc=4, argv=0x7fffffffdb30) at perf.c:520 (gdb) [root@quaco tmp]# perf c2c record ^C[ perf record: Woken up 1 times to write data ] 0x5698 [0x138]: failed to process type: 17 [ perf record: Captured and wrote 7.110 MB perf.data ] [root@quaco tmp]# perf kmem record ^C[ perf record: Woken up 1 times to write data ] 0x5998 [0x138]: failed to process type: 17 [ perf record: Captured and wrote 1.470 MB perf.data ] [root@quaco tmp]#
On Tue, Jan 22, 2019 at 12:31:17PM -0200, Arnaldo Carvalho de Melo wrote: > 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. I saw also perf mem failing because of this.. will check jirka
Em Tue, Jan 22, 2019 at 03:51:19PM +0100, Jiri Olsa escreveu: > On Tue, Jan 22, 2019 at 12:31:17PM -0200, Arnaldo Carvalho de Melo wrote: > > 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. > > I saw also perf mem failing because of this.. will check Right, seems something with the synthesizing of existing bpf progs, which always there are some nowadays, for instance, on this fedora29 system: [root@quaco tmp]# bpftool prog 13: cgroup_skb tag 7be49e3934a125ba gpl loaded_at 2019-01-21T13:30:27-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 13,14 14: cgroup_skb tag 2a142ef67aaad174 gpl loaded_at 2019-01-21T13:30:27-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 13,14 15: cgroup_skb tag 7be49e3934a125ba gpl loaded_at 2019-01-21T13:30:27-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 15,16 16: cgroup_skb tag 2a142ef67aaad174 gpl loaded_at 2019-01-21T13:30:27-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 15,16 17: cgroup_skb tag 7be49e3934a125ba gpl loaded_at 2019-01-21T13:30:29-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 17,18 18: cgroup_skb tag 2a142ef67aaad174 gpl loaded_at 2019-01-21T13:30:29-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 17,18 21: cgroup_skb tag 7be49e3934a125ba gpl loaded_at 2019-01-21T13:30:29-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 21,22 22: cgroup_skb tag 2a142ef67aaad174 gpl loaded_at 2019-01-21T13:30:29-0200 uid 0 xlated 296B jited 229B memlock 4096B map_ids 21,22 [root@quaco tmp]# When with a bunch of tracepoints, that is what 'perf mem', 'perf kmem', 'perf sched', etc does, it ends up failing here: ret = perf_evlist__parse_sample_timestamp(evlist, event, ×tamp); So it is not passed to ret = perf_session__queue_event(session, event, timestamp, file_offset); in perf_session__process_event, this happens right when processing buildids in 'perf record', and also in 'perf report', so that is something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. - Arnaldo
On Tue, Jan 22, 2019 at 12:58:05PM -0200, Arnaldo Carvalho de Melo wrote: > Em Tue, Jan 22, 2019 at 03:51:19PM +0100, Jiri Olsa escreveu: > > On Tue, Jan 22, 2019 at 12:31:17PM -0200, Arnaldo Carvalho de Melo wrote: > > > 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. > > > > I saw also perf mem failing because of this.. will check > > Right, seems something with the synthesizing of existing bpf progs, > which always there are some nowadays, for instance, on this fedora29 > system: > > [root@quaco tmp]# bpftool prog > 13: cgroup_skb tag 7be49e3934a125ba gpl > loaded_at 2019-01-21T13:30:27-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 13,14 > 14: cgroup_skb tag 2a142ef67aaad174 gpl > loaded_at 2019-01-21T13:30:27-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 13,14 > 15: cgroup_skb tag 7be49e3934a125ba gpl > loaded_at 2019-01-21T13:30:27-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 15,16 > 16: cgroup_skb tag 2a142ef67aaad174 gpl > loaded_at 2019-01-21T13:30:27-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 15,16 > 17: cgroup_skb tag 7be49e3934a125ba gpl > loaded_at 2019-01-21T13:30:29-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 17,18 > 18: cgroup_skb tag 2a142ef67aaad174 gpl > loaded_at 2019-01-21T13:30:29-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 17,18 > 21: cgroup_skb tag 7be49e3934a125ba gpl > loaded_at 2019-01-21T13:30:29-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 21,22 > 22: cgroup_skb tag 2a142ef67aaad174 gpl > loaded_at 2019-01-21T13:30:29-0200 uid 0 > xlated 296B jited 229B memlock 4096B map_ids 21,22 > [root@quaco tmp]# > > When with a bunch of tracepoints, that is what 'perf mem', 'perf kmem', > 'perf sched', etc does, it ends up failing here: > > ret = perf_evlist__parse_sample_timestamp(evlist, event, ×tamp); > > So it is not passed to > > ret = perf_session__queue_event(session, event, timestamp, file_offset); > > in perf_session__process_event, this happens right when processing > buildids in 'perf record', and also in 'perf report', so that is > something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. it's reproducible with simple: perf record -e cycles,instructions ls as you said on irc, it's the machine->id_hdr_size size missing there's one more glitch, attached patch fixes that for me you can't use sizeof(struct ksymbol_event), because it includes the name as well.. which screws the size but I don't know that code that much.. might be still something missing jirka --- diff --git a/tools/perf/util/bpf-event.c b/tools/perf/util/bpf-event.c index 01e1dc1bb7fb..d86b61cc635f 100644 --- a/tools/perf/util/bpf-event.c +++ b/tools/perf/util/bpf-event.c @@ -7,6 +7,7 @@ #include "bpf-event.h" #include "debug.h" #include "symbol.h" +#include "machine.h" #define ptr_to_u64(ptr) ((__u64)(unsigned long)(ptr)) @@ -149,7 +150,7 @@ static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, *ksymbol_event = (struct ksymbol_event){ .header = { .type = PERF_RECORD_KSYMBOL, - .size = sizeof(struct ksymbol_event), + .size = offsetof(struct ksymbol_event, name) + machine->id_hdr_size, }, .addr = prog_addrs[i], .len = prog_lens[i],
> On Jan 22, 2019, at 7:21 AM, Jiri Olsa <jolsa@redhat.com> wrote: > > On Tue, Jan 22, 2019 at 12:58:05PM -0200, Arnaldo Carvalho de Melo wrote: >> Em Tue, Jan 22, 2019 at 03:51:19PM +0100, Jiri Olsa escreveu: >>> On Tue, Jan 22, 2019 at 12:31:17PM -0200, Arnaldo Carvalho de Melo wrote: >>>> 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. >>> >>> I saw also perf mem failing because of this.. will check >> >> Right, seems something with the synthesizing of existing bpf progs, >> which always there are some nowadays, for instance, on this fedora29 >> system: >> >> [root@quaco tmp]# bpftool prog >> 13: cgroup_skb tag 7be49e3934a125ba gpl >> loaded_at 2019-01-21T13:30:27-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 13,14 >> 14: cgroup_skb tag 2a142ef67aaad174 gpl >> loaded_at 2019-01-21T13:30:27-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 13,14 >> 15: cgroup_skb tag 7be49e3934a125ba gpl >> loaded_at 2019-01-21T13:30:27-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 15,16 >> 16: cgroup_skb tag 2a142ef67aaad174 gpl >> loaded_at 2019-01-21T13:30:27-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 15,16 >> 17: cgroup_skb tag 7be49e3934a125ba gpl >> loaded_at 2019-01-21T13:30:29-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 17,18 >> 18: cgroup_skb tag 2a142ef67aaad174 gpl >> loaded_at 2019-01-21T13:30:29-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 17,18 >> 21: cgroup_skb tag 7be49e3934a125ba gpl >> loaded_at 2019-01-21T13:30:29-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 21,22 >> 22: cgroup_skb tag 2a142ef67aaad174 gpl >> loaded_at 2019-01-21T13:30:29-0200 uid 0 >> xlated 296B jited 229B memlock 4096B map_ids 21,22 >> [root@quaco tmp]# >> >> When with a bunch of tracepoints, that is what 'perf mem', 'perf kmem', >> 'perf sched', etc does, it ends up failing here: >> >> ret = perf_evlist__parse_sample_timestamp(evlist, event, ×tamp); >> >> So it is not passed to >> >> ret = perf_session__queue_event(session, event, timestamp, file_offset); >> >> in perf_session__process_event, this happens right when processing >> buildids in 'perf record', and also in 'perf report', so that is >> something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. > > it's reproducible with simple: > perf record -e cycles,instructions ls > > as you said on irc, it's the machine->id_hdr_size size missing > there's one more glitch, attached patch fixes that for me > you can't use sizeof(struct ksymbol_event), because it includes > the name as well.. which screws the size > > but I don't know that code that much.. might be still something > missing > > jirka Hi Arnaldo and Jiri, Thanks for catching and fixing the bug. I guess the following is OK? *bpf_event = (struct bpf_event){ .header = { .type = PERF_RECORD_BPF_EVENT, .size = sizeof(struct bpf_event), }, .type = PERF_BPF_EVENT_PROG_LOAD, .flags = 0, .id = info.id, }; as struct bpf_event doesn't have variable length name: struct bpf_event { struct perf_event_header header; u16 type; u16 flags; u32 id; /* for bpf_prog types */ u8 tag[BPF_TAG_SIZE]; // prog tag }; Or we need similar fix? Song
On Tue, Jan 22, 2019 at 06:38:56PM +0000, Song Liu wrote: SNIP > >> in perf_session__process_event, this happens right when processing > >> buildids in 'perf record', and also in 'perf report', so that is > >> something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. > > > > it's reproducible with simple: > > perf record -e cycles,instructions ls > > > > as you said on irc, it's the machine->id_hdr_size size missing > > there's one more glitch, attached patch fixes that for me > > you can't use sizeof(struct ksymbol_event), because it includes > > the name as well.. which screws the size > > > > but I don't know that code that much.. might be still something > > missing > > > > jirka > > Hi Arnaldo and Jiri, > > Thanks for catching and fixing the bug. > > I guess the following is OK? > > *bpf_event = (struct bpf_event){ > .header = { > .type = PERF_RECORD_BPF_EVENT, > .size = sizeof(struct bpf_event), > }, > .type = PERF_BPF_EVENT_PROG_LOAD, > .flags = 0, > .id = info.id, > }; > > as struct bpf_event doesn't have variable length name: > > struct bpf_event { > struct perf_event_header header; > u16 type; > u16 flags; > u32 id; > > /* for bpf_prog types */ > u8 tag[BPF_TAG_SIZE]; // prog tag > }; > > Or we need similar fix? yep, looks good.. also don't forget to add the 'machine->id_hdr_size' jirka
> On Jan 22, 2019, at 11:15 AM, Jiri Olsa <jolsa@redhat.com> wrote: > > On Tue, Jan 22, 2019 at 06:38:56PM +0000, Song Liu wrote: > > SNIP > >>>> in perf_session__process_event, this happens right when processing >>>> buildids in 'perf record', and also in 'perf report', so that is >>>> something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. >>> >>> it's reproducible with simple: >>> perf record -e cycles,instructions ls >>> >>> as you said on irc, it's the machine->id_hdr_size size missing >>> there's one more glitch, attached patch fixes that for me >>> you can't use sizeof(struct ksymbol_event), because it includes >>> the name as well.. which screws the size >>> >>> but I don't know that code that much.. might be still something >>> missing >>> >>> jirka >> >> Hi Arnaldo and Jiri, >> >> Thanks for catching and fixing the bug. >> >> I guess the following is OK? >> >> *bpf_event = (struct bpf_event){ >> .header = { >> .type = PERF_RECORD_BPF_EVENT, >> .size = sizeof(struct bpf_event), >> }, >> .type = PERF_BPF_EVENT_PROG_LOAD, >> .flags = 0, >> .id = info.id, >> }; >> >> as struct bpf_event doesn't have variable length name: >> >> struct bpf_event { >> struct perf_event_header header; >> u16 type; >> u16 flags; >> u32 id; >> >> /* for bpf_prog types */ >> u8 tag[BPF_TAG_SIZE]; // prog tag >> }; >> >> Or we need similar fix? > > yep, looks good.. also don't forget to add the 'machine->id_hdr_size' > > jirka So we still need something like? diff --git i/tools/perf/util/bpf-event.c w/tools/perf/util/bpf-event.c index 01e1dc1bb7fb..d7bf45485820 100644 --- i/tools/perf/util/bpf-event.c +++ w/tools/perf/util/bpf-event.c @@ -4,6 +4,7 @@ #include <bpf/bpf.h> #include <bpf/btf.h> #include <linux/btf.h> +#include "machine.h" #include "bpf-event.h" #include "debug.h" #include "symbol.h" @@ -187,7 +188,7 @@ static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, *bpf_event = (struct bpf_event){ .header = { .type = PERF_RECORD_BPF_EVENT, - .size = sizeof(struct bpf_event), + .size = sizeof(struct bpf_event) + machine->id_hdr_size, }, .type = PERF_BPF_EVENT_PROG_LOAD, .flags = 0, Would you send the official patch? Or would you prefer me sending it? Thanks, Song
On Tue, Jan 22, 2019 at 07:24:43PM +0000, Song Liu wrote: > > > > On Jan 22, 2019, at 11:15 AM, Jiri Olsa <jolsa@redhat.com> wrote: > > > > On Tue, Jan 22, 2019 at 06:38:56PM +0000, Song Liu wrote: > > > > SNIP > > > >>>> in perf_session__process_event, this happens right when processing > >>>> buildids in 'perf record', and also in 'perf report', so that is > >>>> something badly synthesized that hits perf.data for PERF_RECORD_KSYMBOL. > >>> > >>> it's reproducible with simple: > >>> perf record -e cycles,instructions ls > >>> > >>> as you said on irc, it's the machine->id_hdr_size size missing > >>> there's one more glitch, attached patch fixes that for me > >>> you can't use sizeof(struct ksymbol_event), because it includes > >>> the name as well.. which screws the size > >>> > >>> but I don't know that code that much.. might be still something > >>> missing > >>> > >>> jirka > >> > >> Hi Arnaldo and Jiri, > >> > >> Thanks for catching and fixing the bug. > >> > >> I guess the following is OK? > >> > >> *bpf_event = (struct bpf_event){ > >> .header = { > >> .type = PERF_RECORD_BPF_EVENT, > >> .size = sizeof(struct bpf_event), > >> }, > >> .type = PERF_BPF_EVENT_PROG_LOAD, > >> .flags = 0, > >> .id = info.id, > >> }; > >> > >> as struct bpf_event doesn't have variable length name: > >> > >> struct bpf_event { > >> struct perf_event_header header; > >> u16 type; > >> u16 flags; > >> u32 id; > >> > >> /* for bpf_prog types */ > >> u8 tag[BPF_TAG_SIZE]; // prog tag > >> }; > >> > >> Or we need similar fix? > > > > yep, looks good.. also don't forget to add the 'machine->id_hdr_size' > > > > jirka > > So we still need something like? > > diff --git i/tools/perf/util/bpf-event.c w/tools/perf/util/bpf-event.c > index 01e1dc1bb7fb..d7bf45485820 100644 > --- i/tools/perf/util/bpf-event.c > +++ w/tools/perf/util/bpf-event.c > @@ -4,6 +4,7 @@ > #include <bpf/bpf.h> > #include <bpf/btf.h> > #include <linux/btf.h> > +#include "machine.h" > #include "bpf-event.h" > #include "debug.h" > #include "symbol.h" > @@ -187,7 +188,7 @@ static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, > *bpf_event = (struct bpf_event){ > .header = { > .type = PERF_RECORD_BPF_EVENT, > - .size = sizeof(struct bpf_event), > + .size = sizeof(struct bpf_event) + machine->id_hdr_size, > }, > .type = PERF_BPF_EVENT_PROG_LOAD, > .flags = 0, > > Would you send the official patch? Or would you prefer me sending it? plese send it, thanks jirka
Em Tue, Jan 22, 2019 at 07:24:43PM +0000, Song Liu escreveu: > +#include "machine.h" > #include "bpf-event.h" > #include "debug.h" > #include "symbol.h" > @@ -187,7 +188,7 @@ static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, > *bpf_event = (struct bpf_event){ > .header = { > .type = PERF_RECORD_BPF_EVENT, > - .size = sizeof(struct bpf_event), > + .size = sizeof(struct bpf_event) + machine->id_hdr_size, > }, > .type = PERF_BPF_EVENT_PROG_LOAD, > .flags = 0, > > Would you send the official patch? Or would you prefer me sending it? Nevermind, I'll fix this, its just that I'm now travelling. - Arnaldo
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c index deaf9b902094..88ea11d57c6f 100644 --- a/tools/perf/builtin-record.c +++ b/tools/perf/builtin-record.c @@ -41,6 +41,7 @@ #include "util/perf-hooks.h" #include "util/time-utils.h" #include "util/units.h" +#include "util/bpf-event.h" #include "asm/bug.h" #include <errno.h> @@ -1082,6 +1083,11 @@ static int record__synthesize(struct record *rec, bool tail) return err; } + err = perf_event__synthesize_bpf_events(tool, process_synthesized_event, + machine, opts); + if (err < 0) + pr_warning("Couldn't synthesize bpf events.\n"); + err = __machine__synthesize_threads(machine, tool, &opts->target, rec->evlist->threads, process_synthesized_event, opts->sample_address, 1); diff --git a/tools/perf/util/bpf-event.c b/tools/perf/util/bpf-event.c index 87004706874f..126f9728a756 100644 --- a/tools/perf/util/bpf-event.c +++ b/tools/perf/util/bpf-event.c @@ -1,10 +1,24 @@ // SPDX-License-Identifier: GPL-2.0 #include <errno.h> #include <bpf/bpf.h> +#include <bpf/btf.h> +#include <linux/btf.h> #include "bpf-event.h" #include "debug.h" #include "symbol.h" +#define ptr_to_u64(ptr) ((__u64)(unsigned long)(ptr)) + +static int snprintf_hex(char *buf, size_t size, unsigned char *data, size_t len) +{ + int ret = 0; + size_t i; + + for (i = 0; i < len; i++) + ret += snprintf(buf + ret, size - ret, "%02x", data[i]); + return ret; +} + int machine__process_bpf_event(struct machine *machine __maybe_unused, union perf_event *event, struct perf_sample *sample __maybe_unused) @@ -13,3 +27,230 @@ int machine__process_bpf_event(struct machine *machine __maybe_unused, perf_event__fprintf_bpf_event(event, stdout); return 0; } + +/* + * Synthesize PERF_RECORD_KSYMBOL and PERF_RECORD_BPF_EVENT for one bpf + * program. One PERF_RECORD_BPF_EVENT is generated for the program. And + * one PERF_RECORD_KSYMBOL is generated for each sub program. + * + * Returns: + * 0 for success; + * -1 for failures; + * -2 for lack of kernel support. + */ +static int perf_event__synthesize_one_bpf_prog(struct perf_tool *tool, + perf_event__handler_t process, + struct machine *machine, + int fd, + union perf_event *event, + struct record_opts *opts) +{ + struct ksymbol_event *ksymbol_event = &event->ksymbol_event; + struct bpf_event *bpf_event = &event->bpf_event; + u32 sub_prog_cnt, i, func_info_rec_size; + u8 (*prog_tags)[BPF_TAG_SIZE] = NULL; + struct bpf_prog_info info = {}; + u32 info_len = sizeof(info); + void *func_infos = NULL; + u64 *prog_addrs = NULL; + struct btf *btf = NULL; + u32 *prog_lens = NULL; + bool has_btf = false; + char errbuf[512]; + int err = 0; + + /* Call bpf_obj_get_info_by_fd() to get sizes of arrays */ + err = bpf_obj_get_info_by_fd(fd, &info, &info_len); + + if (err) { + pr_debug("%s: failed to get BPF program info: %s, aborting\n", + __func__, str_error_r(errno, errbuf, sizeof(errbuf))); + return -1; + } + if (info_len < offsetof(struct bpf_prog_info, prog_tags)) { + pr_debug("%s: the kernel is too old, aborting\n", __func__); + return -2; + } + + /* number of ksyms, func_lengths, and tags should match */ + sub_prog_cnt = info.nr_jited_ksyms; + if (sub_prog_cnt != info.nr_prog_tags || + sub_prog_cnt != info.nr_jited_func_lens) + return -1; + + /* check BTF func info support */ + if (info.btf_id && info.nr_func_info && info.func_info_rec_size) { + /* btf func info number should be same as sub_prog_cnt */ + if (sub_prog_cnt != info.nr_func_info) { + pr_debug("%s: mismatch in BPF sub program count and BTF function info count, aborting\n", __func__); + return -1; + } + if (btf__get_from_id(info.btf_id, &btf)) { + pr_debug("%s: failed to get BTF of id %u, aborting\n", __func__, info.btf_id); + return -1; + } + func_info_rec_size = info.func_info_rec_size; + func_infos = calloc(sub_prog_cnt, func_info_rec_size); + if (!func_infos) { + pr_debug("%s: failed to allocate memory for func_infos, aborting\n", __func__); + return -1; + } + has_btf = true; + } + + /* + * We need address, length, and tag for each sub program. + * Allocate memory and call bpf_obj_get_info_by_fd() again + */ + prog_addrs = calloc(sub_prog_cnt, sizeof(u64)); + if (!prog_addrs) { + pr_debug("%s: failed to allocate memory for prog_addrs, aborting\n", __func__); + goto out; + } + prog_lens = calloc(sub_prog_cnt, sizeof(u32)); + if (!prog_lens) { + pr_debug("%s: failed to allocate memory for prog_lens, aborting\n", __func__); + goto out; + } + prog_tags = calloc(sub_prog_cnt, BPF_TAG_SIZE); + if (!prog_tags) { + pr_debug("%s: failed to allocate memory for prog_tags, aborting\n", __func__); + goto out; + } + + memset(&info, 0, sizeof(info)); + info.nr_jited_ksyms = sub_prog_cnt; + info.nr_jited_func_lens = sub_prog_cnt; + info.nr_prog_tags = sub_prog_cnt; + info.jited_ksyms = ptr_to_u64(prog_addrs); + info.jited_func_lens = ptr_to_u64(prog_lens); + info.prog_tags = ptr_to_u64(prog_tags); + info_len = sizeof(info); + if (has_btf) { + info.nr_func_info = sub_prog_cnt; + info.func_info_rec_size = func_info_rec_size; + info.func_info = ptr_to_u64(func_infos); + } + + err = bpf_obj_get_info_by_fd(fd, &info, &info_len); + if (err) { + pr_debug("%s: failed to get BPF program info, aborting\n", __func__); + goto out; + } + + /* Synthesize PERF_RECORD_KSYMBOL */ + for (i = 0; i < sub_prog_cnt; i++) { + const struct bpf_func_info *finfo; + const char *short_name = NULL; + const struct btf_type *t; + int name_len; + + *ksymbol_event = (struct ksymbol_event){ + .header = { + .type = PERF_RECORD_KSYMBOL, + .size = sizeof(struct ksymbol_event), + }, + .addr = prog_addrs[i], + .len = prog_lens[i], + .ksym_type = PERF_RECORD_KSYMBOL_TYPE_BPF, + .flags = 0, + }; + name_len = snprintf(ksymbol_event->name, KSYM_NAME_LEN, + "bpf_prog_"); + name_len += snprintf_hex(ksymbol_event->name + name_len, + KSYM_NAME_LEN - name_len, + prog_tags[i], BPF_TAG_SIZE); + if (has_btf) { + finfo = func_infos + i * info.func_info_rec_size; + t = btf__type_by_id(btf, finfo->type_id); + short_name = btf__name_by_offset(btf, t->name_off); + } else if (i == 0 && sub_prog_cnt == 1) { + /* no subprog */ + if (info.name[0]) + short_name = info.name; + } else + short_name = "F"; + if (short_name) + name_len += snprintf(ksymbol_event->name + name_len, + KSYM_NAME_LEN - name_len, + "_%s", short_name); + + ksymbol_event->header.size += PERF_ALIGN(name_len + 1, + sizeof(u64)); + err = perf_tool__process_synth_event(tool, event, + machine, process); + } + + /* Synthesize PERF_RECORD_BPF_EVENT */ + if (opts->bpf_event) { + *bpf_event = (struct bpf_event){ + .header = { + .type = PERF_RECORD_BPF_EVENT, + .size = sizeof(struct bpf_event), + }, + .type = PERF_BPF_EVENT_PROG_LOAD, + .flags = 0, + .id = info.id, + }; + memcpy(bpf_event->tag, prog_tags[i], BPF_TAG_SIZE); + err = perf_tool__process_synth_event(tool, event, + machine, process); + } + +out: + free(prog_tags); + free(prog_lens); + free(prog_addrs); + free(func_infos); + free(btf); + return err ? -1 : 0; +} + +int perf_event__synthesize_bpf_events(struct perf_tool *tool, + perf_event__handler_t process, + struct machine *machine, + struct record_opts *opts) +{ + union perf_event *event; + __u32 id = 0; + int err; + int fd; + + event = malloc(sizeof(event->bpf_event) + KSYM_NAME_LEN); + if (!event) + return -1; + while (true) { + err = bpf_prog_get_next_id(id, &id); + if (err) { + if (errno == ENOENT) { + err = 0; + break; + } + pr_debug("%s: can't get next program: %s%s", + __func__, strerror(errno), + errno == EINVAL ? " -- kernel too old?" : ""); + /* don't report error on old kernel */ + err = (errno == EINVAL) ? 0 : -1; + break; + } + fd = bpf_prog_get_fd_by_id(id); + if (fd < 0) { + pr_debug("%s: failed to get fd for prog_id %u\n", + __func__, id); + continue; + } + + err = perf_event__synthesize_one_bpf_prog(tool, process, + machine, fd, + event, opts); + close(fd); + if (err) { + /* do not return error for old kernel */ + if (err == -2) + err = 0; + break; + } + } + free(event); + return err; +} diff --git a/tools/perf/util/bpf-event.h b/tools/perf/util/bpf-event.h index d5ca355dd298..38aee4040f12 100644 --- a/tools/perf/util/bpf-event.h +++ b/tools/perf/util/bpf-event.h @@ -8,4 +8,9 @@ int machine__process_bpf_event(struct machine *machine, union perf_event *event, struct perf_sample *sample); +int perf_event__synthesize_bpf_events(struct perf_tool *tool, + perf_event__handler_t process, + struct machine *machine, + struct record_opts *opts); + #endif
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. Signed-off-by: Song Liu <songliubraving@fb.com> --- tools/perf/builtin-record.c | 6 + tools/perf/util/bpf-event.c | 241 ++++++++++++++++++++++++++++++++++++ tools/perf/util/bpf-event.h | 5 + 3 files changed, 252 insertions(+)