Re: [PATCH v7 3/3] perf-stat: enable counting events for BPF programs

From: Arnaldo Carvalho de Melo
Date: Tue Jan 19 2021 - 10:11:13 EST

Em Tue, Jan 19, 2021 at 11:31:44AM -0300, Arnaldo Carvalho de Melo escreveu:
> Em Tue, Jan 19, 2021 at 12:48:19AM +0000, Song Liu escreveu:
> > > On Jan 18, 2021, at 11:38 AM, Arnaldo Carvalho de Melo <acme@xxxxxxxxxx> wrote:
> > We are looking at two issues:
> > 1. Cannot recursively attach;
> > 2. prog FD 3 doesn't have valid btf.

> > #1 was caused by the verifier disallowing attaching fentry/fexit program
> > to program with type BPF_PROG_TYPE_TRACING (in bpf_check_attach_target).
> > This constraint was added when we only had fentry/fexit in the TRACING
> > type. We have extended the TRACING type to many other use cases, like
> > "tp_btf/", "fmod_ret" and "iter/". Therefore, it is good time to revisit
> > this constraint. I will work on this.

> > For #2, we require the target program to have BTF. I guess we won't remove
> > this requirement.

> > While I work on improving #1, could you please test with some kprobe
> > programs? For example, we can use fileslower.py from bcc.

> Sure, and please consider improving the error messages to state what you
> described above.

Terminal 1:

[root@five perf]# perf trace -e 5sec.c
^C
[root@five perf]# cat 5sec.c
#include <bpf.h>

#define NSEC_PER_SEC 1000000000L

int probe(hrtimer_nanosleep, rqtp)(void *ctx, int err, long long sec)
{
return sec / NSEC_PER_SEC == 5;
}

license(GPL);
[root@five perf]# perf trace -e 5sec.c/max-stack=16/
0.000 sleep/3739435 perf_bpf_probe:hrtimer_nanosleep(__probe_ip: -1743337312, rqtp: 5000000000)
hrtimer_nanosleep ([kernel.kallsyms])
common_nsleep ([kernel.kallsyms])
__x64_sys_clock_nanosleep ([kernel.kallsyms])
do_syscall_64 ([kernel.kallsyms])
entry_SYSCALL_64_after_hwframe ([kernel.kallsyms])
__clock_nanosleep_2 (/usr/lib64/libc-2.32.so)


Terminal 2:

[root@five ~]# perf stat -e cycles -b 180 -I 1000
libbpf: elf: skipping unrecognized data section(9) .eh_frame
libbpf: elf: skipping relo section(15) .rel.eh_frame for section(9) .eh_frame
perf: util/bpf_counter.c:227: bpf_program_profiler__read: Assertion `skel != NULL' failed.
Aborted (core dumped)
[root@five ~]# gdb perf
GNU gdb (GDB) Fedora 10.1-2.fc33
<SNIP>
Reading symbols from perf...
(gdb) run stat -e cycles -b 180 -I 1000
Starting program: /root/bin/perf stat -e cycles -b 180 -I 1000
Missing separate debuginfos, use: dnf debuginfo-install glibc-2.32-2.fc33.x86_64
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
libbpf: elf: skipping unrecognized data section(9) .eh_frame
libbpf: elf: skipping relo section(15) .rel.eh_frame for section(9) .eh_frame
perf: util/bpf_counter.c:227: bpf_program_profiler__read: Assertion `skel != NULL' failed.

Program received signal SIGABRT, Aborted.
0x00007ffff75149d5 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: dnf debuginfo-install bzip2-libs-1.0.8-4.fc33.x86_64 cyrus-sasl-lib-2.1.27-6.fc33.x86_64 elfutils-debuginfod-client-0.182-1.fc33.x86_64 elfutils-libelf-0.182-1.fc33.x86_64 elfutils-libs-0.182-1.fc33.x86_64 keyutils-libs-1.6.1-1.fc33.x86_64 krb5-libs-1.18.2-29.fc33.x86_64 libbabeltrace-1.5.8-3.fc33.x86_64 libbrotli-1.0.9-3.fc33.x86_64 libcap-2.26-8.fc33.x86_64 libcom_err-1.45.6-4.fc33.x86_64 libcurl-7.71.1-8.fc33.x86_64 libgcc-10.2.1-9.fc33.x86_64 libidn2-2.3.0-4.fc33.x86_64 libnghttp2-1.41.0-3.fc33.x86_64 libpsl-0.21.1-2.fc33.x86_64 libselinux-3.1-2.fc33.x86_64 libssh-0.9.5-1.fc33.x86_64 libunistring-0.9.10-9.fc33.x86_64 libunwind-1.4.0-4.fc33.x86_64 libuuid-2.36.1-1.fc33.x86_64 libxcrypt-4.4.17-1.fc33.x86_64 libzstd-1.4.7-1.fc33.x86_64 numactl-libs-2.0.14-1.fc33.x86_64 openldap-2.4.50-5.fc33.x86_64 openssl-libs-1.1.1i-1.fc33.x86_64 pcre-8.44-2.fc33.x86_64 pcre2-10.36-1.fc33.x86_64 perl-libs-5.32.0-465.fc33.x86_64 popt-1.18-2.fc33.x86_64 python3-libs-3.9.1-1.fc33.x86_64 slang-2.3.2-8.fc33.x86_64 xz-libs-5.2.5-4.fc33.x86_64 zlib-1.2.11-23.fc33.x86_64
(gdb) bt
#0 0x00007ffff75149d5 in raise () from /lib64/libc.so.6
#1 0x00007ffff74fd8a4 in abort () from /lib64/libc.so.6
#2 0x00007ffff74fd789 in __assert_fail_base.cold () from /lib64/libc.so.6
#3 0x00007ffff750d026 in __assert_fail () from /lib64/libc.so.6
#4 0x00000000005661c3 in bpf_program_profiler__read (evsel=0xc3a2c0) at util/bpf_counter.c:227
#5 0x0000000000000000 in ?? ()
(gdb)

207 static int bpf_program_profiler__read(struct evsel *evsel)
208 {
209 int num_cpu = evsel__nr_cpus(evsel);
210 struct bpf_perf_event_value values[num_cpu];
211 struct bpf_counter *counter;
212 int reading_map_fd;
213 __u32 key = 0;
214 int err, cpu;
215
216 if (list_empty(&evsel->bpf_counter_list))
217 return -EAGAIN;
218
219 for (cpu = 0; cpu < num_cpu; cpu++) {
220 perf_counts(evsel->counts, cpu, 0)->val = 0;
221 perf_counts(evsel->counts, cpu, 0)->ena = 0;
222 perf_counts(evsel->counts, cpu, 0)->run = 0;
223 }
224 list_for_each_entry(counter, &evsel->bpf_counter_list, list) {
225 struct bpf_prog_profiler_bpf *skel = counter->skel;
226
227 assert(skel != NULL);
228 reading_map_fd = bpf_map__fd(skel->maps.accum_readings);
229
230 err = bpf_map_lookup_elem(reading_map_fd, &key, values);
231 if (err) {
232 pr_err("failed to read value\n");
233 return err;
234 }
235
236 for (cpu = 0; cpu < num_cpu; cpu++) {
237 perf_counts(evsel->counts, cpu, 0)->val += values[cpu].counter;
238 perf_counts(evsel->counts, cpu, 0)->ena += values[cpu].enabled;
239 perf_counts(evsel->counts, cpu, 0)->run += values[cpu].running;
240 }
241 }
242 return 0;
243 }

- Arnaldo