Re: [PATCH bpf-next] libbpf: add debug message for each created program

["Toke Høiland-Jørgensen" <toke@redhat.com>]

Alexei Starovoitov <alexei.starovoitov@gmail.com> writes:

> On Tue, Jun 23, 2020 at 11:59:40PM -0700, Andrii Nakryiko wrote:
>> On Tue, Jun 23, 2020 at 11:47 PM Alexei Starovoitov
>> <alexei.starovoitov@gmail.com> wrote:
>> >
>> > On Tue, Jun 23, 2020 at 5:34 PM Andrii Nakryiko <andriin@fb.com> wrote:
>> > >
>> > > Similar message for map creation is extremely useful, so add similar for BPF
>> > > programs.
>> >
>> > 'extremely useful' is quite subjective.
>> > If we land this patch then everyone will be allowed to add pr_debug()
>> > everywhere in libbpf with the same reasoning: "it's extremely useful pr_debug".
>> 
>> We print this for maps, making it clear which maps and with which FD
>> were created. Having this for programs is just as useful. It doesn't
>> overwhelm output (and it's debug one either way). "everyone will be
>> allowed to add pr_debug()" is a big stretch, you can't just sneak in
>> or force random pr_debug, we do review patches and if something
>> doesn't make sense we can and we do reject it, regardless of claimed
>> usefulness by the patch author.
>> 
>> So far, libbpf debug logs were extremely helpful (subjective, of
>> course, but what isn't?) to debug "remotely" various issues that BPF
>> users had. They don't feel overwhelmingly verbose and don't have a lot
>> of unnecessary info. Adding a few lines (how many BPF programs are
>> there per each BPF object?) for listing BPF programs is totally ok.
>
> None of the above were mentioned in the commit log.
> And no examples were given where this extra line would actually help.
>
> I think libbpf pr_debug is extremely verbose instead of extremely useful.
> Just typical output:
> ./test_progs -vv -t lsm
> libbpf: loading object 'lsm' from buffer
> libbpf: section(1) .strtab, size 306, link 0, flags 0, type=3
> libbpf: skip section(1) .strtab
> libbpf: section(2) .text, size 0, link 0, flags 6, type=1
> libbpf: skip section(2) .text
> libbpf: section(3) lsm/file_mprotect, size 192, link 0, flags 6, type=1
> libbpf: found program lsm/file_mprotect
> libbpf: section(4) .rellsm/file_mprotect, size 32, link 25, flags 0, type=9
> libbpf: section(5) lsm/bprm_committed_creds, size 104, link 0, flags 6, type=1
> libbpf: found program lsm/bprm_committed_creds
> libbpf: section(6) .rellsm/bprm_committed_creds, size 32, link 25, flags 0, type=9
>
> How's above useful for anyone?
> libbpf says that there are '.strtab' and '.text' sections in the elf file.
> That's wet water. Any elf file has that.
> Then it says it's skipping '.text' ?
> That reads surprising. Why library would skip the code?
> And so on and so forth.
> That output is useful to only few core libbpf developers.
>
> I don't mind more thought through debug prints, but
> saying that existing pr_debugs are 'extremely useful' is a stretch.

Agreed. I had to demote libbpf debug output to an (additional) 'verbose'
level in xdp-tools because there was just too much output.

Personally I think the additional 'program loading succeeded' message
would be useful *if* some of the more verbose stuff (like what you
posted above) was cleared out.

-Toke