From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-5.5 required=3.0 tests=HEADER_FROM_DIFFERENT_DOMAINS, INCLUDES_PATCH,MAILING_LIST_MULTI,SPF_PASS,USER_AGENT_MUTT autolearn=unavailable autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id A2457C282C5 for ; Tue, 22 Jan 2019 15:28:39 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 7AD79217D6 for ; Tue, 22 Jan 2019 15:28:39 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1729404AbfAVPVv (ORCPT ); Tue, 22 Jan 2019 10:21:51 -0500 Received: from mx1.redhat.com ([209.132.183.28]:59996 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1728829AbfAVPVu (ORCPT ); Tue, 22 Jan 2019 10:21:50 -0500 Received: from smtp.corp.redhat.com (int-mx08.intmail.prod.int.phx2.redhat.com [10.5.11.23]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.redhat.com (Postfix) with ESMTPS id B8B9FC04959C; Tue, 22 Jan 2019 15:21:49 +0000 (UTC) Received: from krava (ovpn-204-197.brq.redhat.com [10.40.204.197]) by smtp.corp.redhat.com (Postfix) with SMTP id 5975B2654C; Tue, 22 Jan 2019 15:21:46 +0000 (UTC) Date: Tue, 22 Jan 2019 16:21:45 +0100 From: Jiri Olsa To: Arnaldo Carvalho de Melo Cc: Song Liu , Jiri Olsa , Namhyung Kim , linux-kernel@vger.kernel.org, netdev@vger.kernel.org, peterz@infradead.org, ast@kernel.org, daniel@iogearbox.net, kernel-team@fb.com Subject: Re: [PATCH v11 perf, bpf-next 7/9] perf tools: synthesize PERF_RECORD_* for loaded BPF programs Message-ID: <20190122152145.GG27625@krava> References: <20190117161521.1341602-1-songliubraving@fb.com> <20190117161521.1341602-8-songliubraving@fb.com> <20190118144655.GM5823@kernel.org> <20190122141320.GF14973@kernel.org> <20190122143117.GG14973@kernel.org> <20190122145119.GF27625@krava> <20190122145805.GI14973@kernel.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20190122145805.GI14973@kernel.org> User-Agent: Mutt/1.10.1 (2018-07-13) X-Scanned-By: MIMEDefang 2.84 on 10.5.11.23 X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.31]); Tue, 22 Jan 2019 15:21:49 +0000 (UTC) Sender: netdev-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: netdev@vger.kernel.org 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],