Re: [PATCH v9 perf,bpf 09/15] perf, bpf: save btf information as headers to perf.data

[Arnaldo Carvalho de Melo <arnaldo.melo@gmail.com>]

Em Tue, Mar 12, 2019 at 05:29:03PM +0000, Song Liu escreveu:
> > On Mar 12, 2019, at 10:05 AM, Arnaldo Carvalho de Melo <arnaldo.melo@gmail.com> wrote:
> > Em Tue, Mar 12, 2019 at 04:26:17PM +0000, Song Liu escreveu:
> >>> On Mar 12, 2019, at 8:16 AM, Arnaldo Carvalho de Melo <arnaldo.melo@gmail.com> wrote:
> >>> Em Tue, Mar 12, 2019 at 12:14:05PM -0300, Arnaldo Carvalho de Melo escreveu:
> >>>> Em Mon, Mar 11, 2019 at 10:30:45PM -0700, Song Liu escreveu:
> >>>>> +static void print_bpf_btf(struct feat_fd *ff, FILE *fp)
> >>>>> +{
> >>>>> +	struct perf_env *env = &ff->ph->env;
> >>>>> +	struct rb_root *root;
> >>>>> +	struct rb_node *next;
> >>>>> +
> >>>>> +	down_read(&env->bpf_progs.lock);
> >>>>> +
> >>>>> +	root = &env->bpf_progs.btfs;
> >>>>> +	next = rb_first(root);
> >>>>> +
> >>>>> +	while (next) {
> >>>>> +		struct btf_node *node;
> >>>>> +
> >>>>> +		node = rb_entry(next, struct btf_node, rb_node);
> >>>>> +		next = rb_next(&node->rb_node);
> >>>>> +		fprintf(fp, "# btf info of id %u\n", node->id);
> >>>> 
> >>>> So, I couldn't get this to work right now, and I have BPF programs that
> >>>> are loaded and that have BTF info:
> >>>> 
> >>>> [root@quaco ~]# bpftool prog | tail -6
> >>>> 208: tracepoint  name sys_enter  tag 819967866022f1e1  gpl
> >>>> 	loaded_at 2019-03-12T11:16:55-0300  uid 0
> >>>> 	xlated 528B  jited 381B  memlock 4096B  map_ids 107,106,105
> >>>> 209: tracepoint  name sys_exit  tag c1bd85c092d6e4aa  gpl
> >>>> 	loaded_at 2019-03-12T11:16:55-0300  uid 0
> >>>> 	xlated 256B  jited 191B  memlock 4096B  map_ids 107,106
> >>>> [root@quaco ~]#
> >>>> 
> >>>> 
> >>>> [root@quaco ~]# bpftool map  | tail -6
> >>>> 105: perf_event_array  name __augmented_sys  flags 0x0
> >>>> 	key 4B  value 4B  max_entries 8  memlock 4096B
> >>>> 106: array  name syscalls  flags 0x0
> >>>> 	key 4B  value 1B  max_entries 512  memlock 8192B
> >>>> 107: hash  name pids_filtered  flags 0x0
> >>>> 	key 4B  value 1B  max_entries 64  memlock 8192B
> >>>> [root@quaco ~]#
> >>>> 
> >>>> [root@quaco ~]# bpftool map dump id 107
> >>>> [{
> >>>>       "key": 8104,
> >>>>       "value": true
> >>>>   },{
> >>>>       "key": 18868,
> >>>>       "value": true
> >>>>   }
> >>>> ]
> >>>> [root@quaco ~]# ps ax|egrep 8104\|18868 | grep -v grep
> >>>> 8104 pts/8    S+     0:07 trace -e recvmmsg
> >>>> 18868 ?        Ssl   21:21 /usr/libexec/gnome-terminal-server
> >>>> [root@quaco ~]#
> >>>> 
> >>>> So I was expecting to see those btf lines there :-\
> >>>> 
> >>>> All the patches up to this point I have already merged and tested in my
> >>>> local branch.
> >>>> 
> >>>> Will continue right after lunch to try to figure out why this BTF info
> >>>> isn't landing on this new header feature...
> >>> 
> >>> I've pushed what I have to my git.kernel.org repo, branch
> >>> tmp.perf/bpf-annotate.
> >>> 
> >>> git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux.git tmp.perf/bpf-annotate
> >>> 
> >>> The HEAD is this cset.
> > 
> >> I am not sure I fully understand the problem here. 
> > 
> > Trying to say it another way, when I start 'perf record', with the
> > patches in your series up to this one ('[PATCH v9 perf,bpf 09/15] perf,
> > bpf: save btf information as headers to perf.data'), and while there is
> > a BPF program running, that has BTF attached to it as can be seen by
> > using 'bpf map dump', 'perf report --header-only' isn't showing any line
> > with 'btf' on it.
> > 
> > So, using -v I notice that it is failing to get enable attr.bpf_event
> > and attr.ksymbol, which makes me go get another coffee to check that the
> > kernel was built from my 5.1 tree that has those events and not 5.0 that
> > doesn't ;-\ Sorry for the noise, will get back here after I check all
> > this :-)
> > 
> > But to recap, the BPF events I was getting were the synthesized ones...
> 
> Yeah, to capture the short living BPF/BTF, we need patch 15/15 of the set. 

So, I continue trying to test this with the patches applied up to the
patch in the subject of this message, i.e. up to:

  09/15 perf, bpf: save btf information as headers to perf.data

While running on a kernel based on tip/perf/core, so it should have what
is needed:

  [root@quaco ~]# egrep 't perf_event_(bpf|ksymbol)_output' /proc/kallsyms
  ffffffff94211a40 t perf_event_bpf_output
  ffffffff94216550 t perf_event_ksymbol_output
  [root@quaco ~]#

But when I debug breakpointing perf_event__synthesize_one_bpf_prog(),
bpf_prog_info->btf_info is always zero, i.e. here:

        /* 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__);
                        err = -1;
                        goto out;
                }
                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);
                        err = -1;
                        btf = NULL;
                        goto out;
                }
                has_btf = true;
                perf_env__fetch_btf(env, info->btf_id, btf);
        }

So we never get into this if body and this do not call
perf__env_fetch_btf() and thus don't write BTF info to the perf.data
header.

And yes, there are BPF programs with BTF information associated:

[root@quaco perf]# bpftool map dump pids_filtered
[{
        "key": 2592,
        "value": true
    },{
        "key": 20511,
        "value": true
    }
]
[root@quaco perf]#

I.e. bpftool can find the BTF info and thus is able to show the
'pids_filtered' map keys and values pretty printed, not just as hex raw
data.

I'm trying to find out why 'bpftool map dump' finds the BTF info while
perf_event__synthesize_one_bpf_prog() doesn't.

- Arnaldo