public inbox for bpf@vger.kernel.org
 help / color / mirror / Atom feed
From: Eduard Zingerman <eddyz87@gmail.com>
To: Matt Bobrowski <mattbobrowski@google.com>
Cc: bpf@vger.kernel.org, andrii@kernel.org, acme@redhat.com
Subject: Re: bpf: Question about odd BPF verifier behaviour
Date: Fri, 24 Feb 2023 16:14:44 +0200	[thread overview]
Message-ID: <8f8f9d43d2f3f6d19c477c28d05527250cc6213d.camel@gmail.com> (raw)
In-Reply-To: <Y/hLsgSO3B+2g9iF@google.com>

On Fri, 2023-02-24 at 05:31 +0000, Matt Bobrowski wrote:
[...]
> > 
> > Could you please copy-paste output of the `fentry` application, I'd
> > like to see the log output of the libbpf while it processes
> > relocations, e.g. here is what it prints for me:
> > 
> >     # /home/eddy/work/libbpf-bootstrap/examples/c/fentry
> >     libbpf: loading object 'fentry_bpf' from buffer
> >     libbpf: elf: section(3) lsm.s/bprm_committed_creds, size 136, link 0, flags 6, type=1
> >     libbpf: sec 'lsm.s/bprm_committed_creds': found program 'dbg' at insn offset 0 (0 bytes), code size 17 insns (136 bytes)
> >     libbpf: elf: section(4) license, size 13, link 0, flags 3, type=1
> >     libbpf: license of fentry_bpf is Dual BSD/GPL
> >     libbpf: elf: section(5) .BTF, size 5114, link 0, flags 0, type=1
> >     libbpf: elf: section(7) .BTF.ext, size 188, link 0, flags 0, type=1
> >     libbpf: elf: section(10) .symtab, size 96, link 1, flags 0, type=2
> >     libbpf: looking for externs among 4 symbols...
> >     libbpf: collected 0 externs total
> >     libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
> >     libbpf: sec 'lsm.s/bprm_committed_creds': found 1 CO-RE relocations
> >     libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [7241] struct linux_binprm in [vmlinux]
> >     libbpf: prog 'dbg': relo #0: <byte_off> [6] struct linux_binprm.file (0:11 @ offset 64)
> >     libbpf: prog 'dbg': relo #0: matching candidate #0 <byte_off> [7241] struct linux_binprm.file (0:11 @ offset 64)
> >     libbpf: prog 'dbg': relo #0: patched insn #10 (LDX/ST/STX) off 64 -> 64
> >     Successfully started! Please run `sudo cat /sys/kernel/debug/tracing/trace_pipe` to see output of the BPF programs.
> 
> Sure, here it is:
> 
> # ./fentry
> libbpf: loading object 'fentry_bpf' from buffer
> libbpf: elf: section(3) lsm.s/bprm_committed_creds, size 136, link 0, flags 6, type=1
> libbpf: sec 'lsm.s/bprm_committed_creds': found program 'dbg' at insn offset 0 (0 bytes), code size 17 insns (136 bytes)
> libbpf: elf: section(4) license, size 13, link 0, flags 3, type=1
> libbpf: license of fentry_bpf is Dual BSD/GPL
> libbpf: elf: section(5) .BTF, size 5149, link 0, flags 0, type=1
> libbpf: elf: section(7) .BTF.ext, size 188, link 0, flags 0, type=1
> libbpf: elf: section(10) .symtab, size 96, link 1, flags 0, type=2
> libbpf: looking for externs among 4 symbols...
> libbpf: collected 0 externs total
> libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
> libbpf: sec 'lsm.s/bprm_committed_creds': found 1 CO-RE relocations
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [3971] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [9214] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [36310] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [36973] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [122219] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [151720] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [163602] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [175117] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [176645] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [179130] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [189263] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [237046] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [240978] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [264207] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [268773] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [276058] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [295158] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [306160] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [347067] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [349932] struct linux_binprm in [vmlinux]
> libbpf: CO-RE relocating [6] struct linux_binprm: found target candidate [380629] struct linux_binprm in [vmlinux]
> libbpf: prog 'dbg': relo #0: <byte_off> [6] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #0 <byte_off> [3971] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #1 <byte_off> [9214] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #2 <byte_off> [36310] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #3 <byte_off> [36973] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #4 <byte_off> [122219] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #5 <byte_off> [151720] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #6 <byte_off> [163602] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #7 <byte_off> [175117] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #8 <byte_off> [176645] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #9 <byte_off> [179130] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #10 <byte_off> [189263] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #11 <byte_off> [237046] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #12 <byte_off> [240978] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #13 <byte_off> [264207] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #14 <byte_off> [268773] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #15 <byte_off> [276058] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #16 <byte_off> [295158] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #17 <byte_off> [306160] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #18 <byte_off> [347067] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #19 <byte_off> [349932] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: matching candidate #20 <byte_off> [380629] struct linux_binprm.file (0:11 @ offset 64)
> libbpf: prog 'dbg': relo #0: patched insn #10 (LDX/ST/STX) off 64 -> 64
> libbpf: prog 'dbg': BPF program load failed: Permission denied
> libbpf: prog 'dbg': -- BEGIN PROG LOAD LOG --
> reg type unsupported for arg#0 function dbg#5
> 0: R1=ctx(off=0,imm=0) R10=fp0
> ; int BPF_PROG(dbg, struct linux_binprm *bprm)
> 0: (79) r1 = *(u64 *)(r1 +0)
> func 'bpf_lsm_bprm_committed_creds' arg0 has btf_id 176645 type STRUCT 'linux_binprm'
> 1: R1_w=trusted_ptr_linux_binprm(off=0,imm=0)
> 1: (b7) r2 = 0                        ; R2_w=0
> ; char buf[64] = {0};
> 2: (7b) *(u64 *)(r10 -8) = r2         ; R2_w=0 R10=fp0 fp-8_w=00000000
> 3: (7b) *(u64 *)(r10 -16) = r2        ; R2_w=0 R10=fp0 fp-16_w=00000000
> 4: (7b) *(u64 *)(r10 -24) = r2        ; R2_w=0 R10=fp0 fp-24_w=00000000
> 5: (7b) *(u64 *)(r10 -32) = r2        ; R2_w=0 R10=fp0 fp-32_w=00000000
> 6: (7b) *(u64 *)(r10 -40) = r2        ; R2_w=0 R10=fp0 fp-40_w=00000000
> 7: (7b) *(u64 *)(r10 -48) = r2        ; R2_w=0 R10=fp0 fp-48_w=00000000
> 8: (7b) *(u64 *)(r10 -56) = r2        ; R2_w=0 R10=fp0 fp-56_w=00000000
> 9: (7b) *(u64 *)(r10 -64) = r2        ; R2_w=0 R10=fp0 fp-64_w=00000000
> ; bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
> 10: (79) r1 = *(u64 *)(r1 +64)        ; R1_w=ptr_file(off=0,imm=0)
> 11: (bf) r2 = r10                     ; R2_w=fp0 R10=fp0
> ; 
> 12: (07) r2 += -64                    ; R2_w=fp-64
> ; bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
> 13: (b7) r3 = 64                      ; R3_w=64
> 14: (85) call bpf_ima_file_hash#193
> cannot access ptr member next with moff 0 in struct llist_node with off 0 size 1
> R1 is of type file but file is expected
> processed 15 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0
> -- END PROG LOAD LOG --
> libbpf: prog 'dbg': failed to load: -13
> libbpf: failed to load object 'fentry_bpf'
> libbpf: failed to load BPF skeleton 'fentry_bpf': -13
> Failed to open BPF skeleton
> 
> It looks like there are a lot more relocations attempted by libbpf,
> but I suspect that's a result of their being multiple definitions of
> that same struct within the running kernel's BTF?

This shouldn't really be the case, as pahole de-duplicates BTF
definitions when BTF is added to vmlinux.

One scenario I can think of is when `linux_binprm` data structure
comes from multiple modules but not from `vmlinux` itself. 
However, the log would be a bit different in such case:

    libbpf: CO-RE relocating [107] struct bpf_testmod_struct_arg_2: found target candidate [90383] struct bpf_testmod_struct_arg_2 in [bpf_testmod]
    libbpf: CO-RE relocating [107] struct bpf_testmod_struct_arg_2: found target candidate [90353] struct bpf_testmod_struct_arg_2 in [bpf_testmod1]

Note `in [bpf_testmod]` and `in [bpf_testmod1]` which are my test modules.
In your log it says `in [vmlinux]`.

Which suggests that there are multiple _conflicting_ definitions of
`linux_binprm` in your `vmlinux` and these definitions could not be
de-duplicated. Could you please run the following command inside QEMU and
share the output?

    bpftool btf dump file /sys/kernel/btf/vmlinux | grep "'linux_binprm'" -A 30
    
Or outside the VM:

    bpftool btf dump file {kernel}/vmlinux | grep "'linux_binprm'" -A 30

Also, could you please share full `.config`?
Do you use any non-standard compilation flags?

> 
> > Also, could you please compile `veristat` tool as below:
> > 
> >     cd ${kernel}/tools/testing/selftests/bpf
> >     make -j16 veristat
> > 
> > And post the output of the following command (from within QEMU):
> > 
> >     ./veristat -l7 -v ${path-to-libbpf-bootstrap-within-vm}/examples/c/.output/fentry.bpf.o
> > 
> > It should produce the verification log as an output.
> > 
> > The reason I'm asking is that your verification log looks kinda strange:
> > 
> > >    ; bpf_ima_file_hash(bprm->file, buf, 64);
> > >    13: (b7) r3 = 64                      ; R3_w=64
> > >    14: (85) call bpf_ima_file_hash#193
> > >    cannot access ptr member next with moff 0 in struct llist_node with off 0 size 1
> > >    R1 is of type file but file is expected
> > >    processed 15 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0
> > 
> > I don't understand why it mentions `struct llist_node` here and don't
> > have such messages in my log ([2]).
> 
> Yes, I also found this strange and couldn't find a valid explanation
> for it either. Looking at the BPF verifier code in the kernel, we hit
> this case when performing the struct member walk in btf_struct_walk().

To be honest, it looks like something is off with BTF ids and `llist_node`
gets randomly picked, but that's a speculation w/o hard evidence.

Thanks,
Eduard

  reply	other threads:[~2023-02-24 14:14 UTC|newest]

Thread overview: 21+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2023-02-20 22:35 bpf: Question about odd BPF verifier behaviour Matt Bobrowski
2023-02-21 20:00 ` Matt Bobrowski
2023-02-22 15:28 ` Eduard Zingerman
2023-02-23  9:37   ` Matt Bobrowski
2023-02-23 12:42     ` Eduard Zingerman
2023-02-23 14:15       ` Eduard Zingerman
2023-02-24  5:31       ` Matt Bobrowski
2023-02-24 14:14         ` Eduard Zingerman [this message]
2023-02-25 20:50           ` Matt Bobrowski
2023-02-26  1:03             ` Eduard Zingerman
2023-02-27 14:17               ` Eduard Zingerman
2023-02-27 17:31                 ` Andrii Nakryiko
2023-02-27 18:04                   ` KP Singh
2023-02-27 18:10                     ` KP Singh
2023-02-27 19:24                     ` Andrii Nakryiko
2023-02-27 19:29                       ` Eduard Zingerman
2023-02-27 19:31                         ` Andrii Nakryiko
2023-02-27 20:48                           ` Eduard Zingerman
2023-02-28  2:55                             ` KP Singh
2023-02-28 18:08                               ` Eduard Zingerman
2023-02-28 18:56                                 ` Andrii Nakryiko

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=8f8f9d43d2f3f6d19c477c28d05527250cc6213d.camel@gmail.com \
    --to=eddyz87@gmail.com \
    --cc=acme@redhat.com \
    --cc=andrii@kernel.org \
    --cc=bpf@vger.kernel.org \
    --cc=mattbobrowski@google.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox