> On Jan 22, 2019, at 7:21 AM, Jiri Olsa <jo...@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
