Em Tue, Jan 19, 2021 at 09:54:50PM +0000, Song Liu escreveu: > > > > On Jan 19, 2021, at 8:31 AM, Arnaldo Carvalho de Melo <a...@kernel.org> > > wrote: > > > > Em Tue, Jan 19, 2021 at 11:42:49AM -0300, Arnaldo Carvalho de Melo escreveu: > >> 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 > >>>>> <a...@kernel.org> 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) > > > > Out to lunch, will continue later, but this may help you figure this out > > till then :) > > > > Starting program: /root/bin/perf stat -e cycles -b 244 -I 1000 > > [Thread debugging using libthread_db enabled] > > Using host libthread_db library "/lib64/libthread_db.so.1". > > > > Breakpoint 1, bpf_program_profiler_load_one (evsel=0xce02c0, prog_id=244) > > at util/bpf_counter.c:96 > > 96 { > > (gdb) n > > 104 prog_fd = bpf_prog_get_fd_by_id(prog_id); > > (gdb) > > 105 if (prog_fd < 0) { > > (gdb) > > 109 counter = bpf_counter_alloc(); > > (gdb) > > 110 if (!counter) { > > (gdb) n > > 115 skel = bpf_prog_profiler_bpf__open(); > > (gdb) p counter > > $9 = (struct bpf_counter *) 0xce09e0 > > (gdb) p *counter > > $10 = {skel = 0x0, list = {next = 0xce09e8, prev = 0xce09e8}} > > (gdb) p *counter > > $11 = {skel = 0x0, list = {next = 0xce09e8, prev = 0xce09e8}} > > (gdb) n > > libbpf: elf: skipping unrecognized data section(9) .eh_frame > > libbpf: elf: skipping relo section(15) .rel.eh_frame for section(9) > > .eh_frame > > 116 if (!skel) { > > (gdb) > > 121 skel->rodata->num_cpu = evsel__nr_cpus(evsel); > > (gdb) > > 123 bpf_map__resize(skel->maps.events, evsel__nr_cpus(evsel)); > > (gdb) > > 124 bpf_map__resize(skel->maps.fentry_readings, 1); > > (gdb) > > 125 bpf_map__resize(skel->maps.accum_readings, 1); > > (gdb) > > 127 prog_name = bpf_target_prog_name(prog_fd); > > (gdb) > > 128 if (!prog_name) { > > (gdb) > > 133 bpf_object__for_each_program(prog, skel->obj) { > > (gdb) > > 134 err = bpf_program__set_attach_target(prog, prog_fd, > > prog_name); > > (gdb) > > 135 if (err) { > > (gdb) > > 133 bpf_object__for_each_program(prog, skel->obj) { > > (gdb) p evsel > > $12 = (struct evsel *) 0xce02c0 > > (gdb) p evsel->name > > $13 = 0xce04e0 "cycles" > > (gdb) n > > 134 err = bpf_program__set_attach_target(prog, prog_fd, > > prog_name); > > (gdb) > > 135 if (err) { > > (gdb) > > 133 bpf_object__for_each_program(prog, skel->obj) { > > (gdb) > > 141 set_max_rlimit(); > > (gdb) > > 142 err = bpf_prog_profiler_bpf__load(skel); > > (gdb) > > 143 if (err) { > > (gdb) > > 148 assert(skel != NULL); > > (gdb) > > 149 counter->skel = skel; > > (gdb) > > 150 list_add(&counter->list, &evsel->bpf_counter_list); > > (gdb) c > > Continuing. > > > > Breakpoint 4, bpf_program_profiler__install_pe (evsel=0xce02c0, cpu=0, > > fd=3) at util/bpf_counter.c:247 > > 247 { > > (gdb) n > > 252 list_for_each_entry(counter, &evsel->bpf_counter_list, list) { > > (gdb) > > 253 skel = counter->skel; > > (gdb) watch counter->skel > > Hardware watchpoint 6: counter->skel > > (gdb) p counter->skel > > $14 = (void *) 0xce0a00 > > (gdb) n > > 254 assert(skel != NULL); > > (gdb) p skel > > $15 = (struct bpf_prog_profiler_bpf *) 0xce0a00 > > (gdb) c > > Continuing. > > > > Hardware watchpoint 6: counter->skel > > > > Old value = (void *) 0xce0a00 > > New value = (void *) 0x0 > > 0x00000000005cf45e in bpf_program_profiler__install_pe (evsel=0xce02c0, > > cpu=0, fd=3) at util/bpf_counter.c:252 > > 252 list_for_each_entry(counter, &evsel->bpf_counter_list, list) { > > So it was the list operation that set counter->skel to NULL? I am really > confused...
Yep, I'm confused as well and trying to reproduce this, but got sidetracked... - Arnaldo > Song > > > (gdb) info b > > Num Type Disp Enb Address What > > 1 breakpoint keep y 0x00000000005ceb44 in > > bpf_program_profiler_load_one at util/bpf_counter.c:96 > > breakpoint already hit 1 time > > 2 breakpoint keep y 0x00000000005cef2e in > > bpf_program_profiler__enable at util/bpf_counter.c:192 > > 3 breakpoint keep y 0x00000000005cf00a in > > bpf_program_profiler__read at util/bpf_counter.c:208 > > 4 breakpoint keep y 0x00000000005cf3ba in > > bpf_program_profiler__install_pe at util/bpf_counter.c:247 > > breakpoint already hit 1 time > > 5 breakpoint keep y 0x00000000005ce8d4 in > > bpf_program_profiler__destroy at util/bpf_counter.c:47 > > 6 hw watchpoint keep y counter->skel > > breakpoint already hit 1 time > > (gdb) p evsel > > $16 = (struct evsel *) 0xce02c0 > > (gdb) bt > > #0 0x00000000005cf45e in bpf_program_profiler__install_pe (evsel=0xce02c0, > > cpu=0, fd=3) at util/bpf_counter.c:252 > > #1 0x00000000005cf4f3 in bpf_counter__install_pe (evsel=0xce02c0, cpu=0, > > fd=3) at util/bpf_counter.c:276 > > #2 0x00000000004f3ef1 in evsel__open_cpu (evsel=0xce02c0, cpus=0xce0500, > > threads=0xce75c0, start_cpu=0, end_cpu=1) at util/evsel.c:1792 > > #3 0x00000000004f4aa7 in evsel__open_per_cpu (evsel=0xce02c0, > > cpus=0xce0500, cpu=0) at util/evsel.c:1996 > > #4 0x000000000057f6f2 in create_perf_stat_counter (evsel=0xce02c0, > > config=0xa97860 <stat_config>, target=0xa97660 <target>, cpu=0) at > > util/stat.c:568 > > #5 0x0000000000435d96 in __run_perf_stat (argc=0, argv=0x7fffffffdb60, > > run_idx=0) at builtin-stat.c:790 > > #6 0x00000000004367e3 in run_perf_stat (argc=0, argv=0x7fffffffdb60, > > run_idx=0) at builtin-stat.c:1001 > > #7 0x0000000000439e35 in cmd_stat (argc=0, argv=0x7fffffffdb60) at > > builtin-stat.c:2415 > > #8 0x00000000004cf058 in run_builtin (p=0xaabe00 <commands+288>, argc=7, > > argv=0x7fffffffdb60) at perf.c:312 > > #9 0x00000000004cf2c5 in handle_internal_command (argc=7, > > argv=0x7fffffffdb60) at perf.c:364 > > #10 0x00000000004cf40c in run_argv (argcp=0x7fffffffd9ac, > > argv=0x7fffffffd9a0) at perf.c:408 > > #11 0x00000000004cf7d8 in main (argc=7, argv=0x7fffffffdb60) at perf.c:538 > > (gdb) n > > 261 return 0; > > > -- - Arnaldo