[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20190122152145.GG27625@krava>
Date: Tue, 22 Jan 2019 16:21:45 +0100
From: Jiri Olsa <jolsa@...hat.com>
To: Arnaldo Carvalho de Melo <acme@...nel.org>
Cc: Song Liu <songliubraving@...com>, Jiri Olsa <jolsa@...nel.org>,
Namhyung Kim <namhyung@...nel.org>,
linux-kernel@...r.kernel.org, netdev@...r.kernel.org,
peterz@...radead.org, ast@...nel.org, daniel@...earbox.net,
kernel-team@...com
Subject: Re: [PATCH v11 perf, bpf-next 7/9] perf tools: synthesize
PERF_RECORD_* for loaded BPF programs
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@...co ~]# 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@...co ~]# perf sched lat
> > > > 0x5b60 [0x138]: failed to process type: 17
> > > > Failed to process events, error -22
> > > > [root@...co ~]#
> > >
> > > 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@...co 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@...co 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],
Powered by blists - more mailing lists