bpf: Question about odd BPF verifier behaviour

bpf: Question about odd BPF verifier behaviour

[Matt Bobrowski]

Hello!

Whilst in the midst of testing a v5.19 to v6.1 kernel upgrade, we
happened to notice that one of our sleepable LSM based eBPF programs
was failing to load on the newer v6.1 kernel. Using the below trivial
eBPF program as our reproducer:

#include "vmlinux.h"
#include <bpf/bpf_helpers.h>
#include <bpf/bpf_tracing.h>

char LICENSE[] SEC("license") = "Dual BSD/GPL";

SEC("lsm.s/bprm_committed_creds")
int BPF_PROG(dbg, struct linux_binprm *bprm)
{
	char buf[64] = {0};
	bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
	return 0;
}

The verifier emits the following error message when attempting to load
the above eBPF program:

-- 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 137293 type STRUCT 'linux_binprm'
1: R1_w=ptr_linux_binprm(off=0,imm=0)
1: (b7) r2 = 0                        ; R2_w=0
; char buf[64] = {0};
[...]
; bpf_ima_file_hash(bprm->file, buf, 64);
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, 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
-- END PROG LOAD LOG --

What particularly strikes out at me is the following 2 lines returned
in the error message:

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

In this particular case, the above message suggested to me that
there's likely multiple struct file definitions that exist within the
kernel's BTF and that the verifier is possibly getting confused about
which one it should be using, or perhaps some of the struct file
definitions included in the kernel's BTF actually differ and hence
when performing the btf_struct_ids_match() check in check_reg_type()
[0] the verifier fails with this error message? Could this potentially
be a problem with the toolchain (Currently, using latest pahole/LLVM
built from source)?

Additionally, I also noticed that when we walk the BTF struct
defintions via btf_struct_walk() from btf_struct_ids_match(), the size
passed to btf_struct_walk() is explicitly set to 1. Yet, msize used
throughout btf_struct_walk() can certainly be > 1 when evaluating a
struct defintions members and hence why we're also tripping over this
condition [1] in btf_struct_walk(). Don't completely understaed this
code yet, so I don't know whether this is actually a problem or not.

Keen to here what your thoughts are on this one.

[0] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/kernel/bpf/verifier.c#n6278
[1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/kernel/bpf/btf.c#n6237

/M

Re: bpf: Question about odd BPF verifier behaviour

[Matt Bobrowski]

On Mon, Feb 20, 2023 at 10:35:55PM +0000, Matt Bobrowski wrote:
> Hello!
> 
> Whilst in the midst of testing a v5.19 to v6.1 kernel upgrade, we
> happened to notice that one of our sleepable LSM based eBPF programs
> was failing to load on the newer v6.1 kernel. Using the below trivial
> eBPF program as our reproducer:
> 
> #include "vmlinux.h"
> #include <bpf/bpf_helpers.h>
> #include <bpf/bpf_tracing.h>
> 
> char LICENSE[] SEC("license") = "Dual BSD/GPL";
> 
> SEC("lsm.s/bprm_committed_creds")
> int BPF_PROG(dbg, struct linux_binprm *bprm)
> {
> 	char buf[64] = {0};
> 	bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
> 	return 0;
> }
> 
> The verifier emits the following error message when attempting to load
> the above eBPF program:
> 
> -- 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 137293 type STRUCT 'linux_binprm'
> 1: R1_w=ptr_linux_binprm(off=0,imm=0)
> 1: (b7) r2 = 0                        ; R2_w=0
> ; char buf[64] = {0};
> [...]
> ; bpf_ima_file_hash(bprm->file, buf, 64);
> 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, 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
> -- END PROG LOAD LOG --
> 
> What particularly strikes out at me is the following 2 lines returned
> in the error message:
> 
> 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
> 
> In this particular case, the above message suggested to me that
> there's likely multiple struct file definitions that exist within the
> kernel's BTF and that the verifier is possibly getting confused about
> which one it should be using, or perhaps some of the struct file
> definitions included in the kernel's BTF actually differ and hence
> when performing the btf_struct_ids_match() check in check_reg_type()
> [0] the verifier fails with this error message? Could this potentially
> be a problem with the toolchain (Currently, using latest pahole/LLVM
> built from source)?
> 
> Additionally, I also noticed that when we walk the BTF struct
> defintions via btf_struct_walk() from btf_struct_ids_match(), the size
> passed to btf_struct_walk() is explicitly set to 1. Yet, msize used
> throughout btf_struct_walk() can certainly be > 1 when evaluating a
> struct defintions members and hence why we're also tripping over this
> condition [1] in btf_struct_walk(). Don't completely understaed this
> code yet, so I don't know whether this is actually a problem or not.
> 
> Keen to here what your thoughts are on this one.

Note that I'm using the latest pahole [0] and LLVM [1] when building
things here.

Andrii/Arnaldo, do you happen to have any pointers on debugging this
BTF ID redundancy, which I suspect is what's going on here?

[0] https://git.kernel.org/pub/scm/devel/pahole/pahole.git
[1] https://github.com/llvm/llvm-project.git

/M

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Mon, 2023-02-20 at 22:35 +0000, Matt Bobrowski wrote:
> Hello!
> 
> Whilst in the midst of testing a v5.19 to v6.1 kernel upgrade, we
> happened to notice that one of our sleepable LSM based eBPF programs
> was failing to load on the newer v6.1 kernel. Using the below trivial
> eBPF program as our reproducer:
> 
> #include "vmlinux.h"
> #include <bpf/bpf_helpers.h>
> #include <bpf/bpf_tracing.h>
> 
> char LICENSE[] SEC("license") = "Dual BSD/GPL";
> 
> SEC("lsm.s/bprm_committed_creds")
> int BPF_PROG(dbg, struct linux_binprm *bprm)
> {
> 	char buf[64] = {0};
> 	bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
> 	return 0;
> }
> 
> The verifier emits the following error message when attempting to load
> the above eBPF program:
> 
> -- 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 137293 type STRUCT 'linux_binprm'
> 1: R1_w=ptr_linux_binprm(off=0,imm=0)
> 1: (b7) r2 = 0                        ; R2_w=0
> ; char buf[64] = {0};
> [...]
> ; bpf_ima_file_hash(bprm->file, buf, 64);
> 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, 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
> -- END PROG LOAD LOG --
> 
> What particularly strikes out at me is the following 2 lines returned
> in the error message:
> 
> 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

Hi Matt,

I tried your program as a ./test_progs test using v6.1 kernel and
don't see any error messages:

VERIFIER LOG:
=============
func#0 @0
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 3061 type STRUCT 'linux_binprm'
1: R1_w=ptr_linux_binprm(off=0,imm=0)
1: (b7) r2 = 0                        ; R2_w=0
; char buf[64] = {0};
2: (7b) *(u64 *)(r10 -8) = r2
last_idx 2 first_idx 0
regs=4 stack=0 before 1: (b7) r2 = 0
3: R2_w=P0 R10=fp0 fp-8_w=00000000
3: (7b) *(u64 *)(r10 -16) = r2        ; R2_w=P0 R10=fp0 fp-16_w=00000000
4: (7b) *(u64 *)(r10 -24) = r2        ; R2_w=P0 R10=fp0 fp-24_w=00000000
5: (7b) *(u64 *)(r10 -32) = r2        ; R2_w=P0 R10=fp0 fp-32_w=00000000
6: (7b) *(u64 *)(r10 -40) = r2        ; R2_w=P0 R10=fp0 fp-40_w=00000000
7: (7b) *(u64 *)(r10 -48) = r2        ; R2_w=P0 R10=fp0 fp-48_w=00000000
8: (7b) *(u64 *)(r10 -56) = r2        ; R2_w=P0 R10=fp0 fp-56_w=00000000
9: (7b) *(u64 *)(r10 -64) = r2        ; R2_w=P0 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: (b4) w3 = 64                      ; R3_w=64
14: (85) call bpf_ima_file_hash#193
last_idx 14 first_idx 0
regs=8 stack=0 before 13: (b4) w3 = 64
15: R0_w=scalar() fp-8_w=mmmmmmmm fp-16_w=mmmmmmmm fp-24_w=mmmmmmmm fp-32_w=mmmmmmmm fp-40_w=mmmmmmmm fp-48_w=mmmmmmmm fp-56_w=mmmmmmmm fp-64_w=mmmmmmmm
; int BPF_PROG(dbg, struct linux_binprm *bprm)
15: (b4) w0 = 0                       ; R0_w=0
16: (95) exit

I use the following revision: 830b3c68c1fb "Linux 6.1".
(also works with current bpf-next master).

Could you please provide some details on how you compile/load the program?

Thanks,
Eduard

[...]

Re: bpf: Question about odd BPF verifier behaviour

[Matt Bobrowski]

Hey Eduard!


On Wed, Feb 22, 2023 at 05:28:52PM +0200, Eduard Zingerman wrote:
> On Mon, 2023-02-20 at 22:35 +0000, Matt Bobrowski wrote:
> > Hello!
> > 
> > Whilst in the midst of testing a v5.19 to v6.1 kernel upgrade, we
> > happened to notice that one of our sleepable LSM based eBPF programs
> > was failing to load on the newer v6.1 kernel. Using the below trivial
> > eBPF program as our reproducer:
> > 
> > #include "vmlinux.h"
> > #include <bpf/bpf_helpers.h>
> > #include <bpf/bpf_tracing.h>
> > 
> > char LICENSE[] SEC("license") = "Dual BSD/GPL";
> > 
> > SEC("lsm.s/bprm_committed_creds")
> > int BPF_PROG(dbg, struct linux_binprm *bprm)
> > {
> > 	char buf[64] = {0};
> > 	bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
> > 	return 0;
> > }
> > 
> > The verifier emits the following error message when attempting to load
> > the above eBPF program:
> > 
> > -- 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 137293 type STRUCT 'linux_binprm'
> > 1: R1_w=ptr_linux_binprm(off=0,imm=0)
> > 1: (b7) r2 = 0                        ; R2_w=0
> > ; char buf[64] = {0};
> > [...]
> > ; bpf_ima_file_hash(bprm->file, buf, 64);
> > 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, 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
> > -- END PROG LOAD LOG --
> > 
> > What particularly strikes out at me is the following 2 lines returned
> > in the error message:
> > 
> > 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
> 
> Hi Matt,
> 
> I tried your program as a ./test_progs test using v6.1 kernel and
> don't see any error messages:
>
> VERIFIER LOG:
> =============
> func#0 @0
> 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 3061 type STRUCT 'linux_binprm'
> 1: R1_w=ptr_linux_binprm(off=0,imm=0)
> 1: (b7) r2 = 0                        ; R2_w=0
> ; char buf[64] = {0};
> 2: (7b) *(u64 *)(r10 -8) = r2
> last_idx 2 first_idx 0
> regs=4 stack=0 before 1: (b7) r2 = 0
> 3: R2_w=P0 R10=fp0 fp-8_w=00000000
> 3: (7b) *(u64 *)(r10 -16) = r2        ; R2_w=P0 R10=fp0 fp-16_w=00000000
> 4: (7b) *(u64 *)(r10 -24) = r2        ; R2_w=P0 R10=fp0 fp-24_w=00000000
> 5: (7b) *(u64 *)(r10 -32) = r2        ; R2_w=P0 R10=fp0 fp-32_w=00000000
> 6: (7b) *(u64 *)(r10 -40) = r2        ; R2_w=P0 R10=fp0 fp-40_w=00000000
> 7: (7b) *(u64 *)(r10 -48) = r2        ; R2_w=P0 R10=fp0 fp-48_w=00000000
> 8: (7b) *(u64 *)(r10 -56) = r2        ; R2_w=P0 R10=fp0 fp-56_w=00000000
> 9: (7b) *(u64 *)(r10 -64) = r2        ; R2_w=P0 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: (b4) w3 = 64                      ; R3_w=64
> 14: (85) call bpf_ima_file_hash#193
> last_idx 14 first_idx 0
> regs=8 stack=0 before 13: (b4) w3 = 64
> 15: R0_w=scalar() fp-8_w=mmmmmmmm fp-16_w=mmmmmmmm fp-24_w=mmmmmmmm fp-32_w=mmmmmmmm fp-40_w=mmmmmmmm fp-48_w=mmmmmmmm fp-56_w=mmmmmmmm fp-64_w=mmmmmmmm
> ; int BPF_PROG(dbg, struct linux_binprm *bprm)
> 15: (b4) w0 = 0                       ; R0_w=0
> 16: (95) exit
> 
> I use the following revision: 830b3c68c1fb "Linux 6.1".
> (also works with current bpf-next master).
> 
> Could you please provide some details on how you compile/load the program?

Firstly, thanks for taking a peek at this! Secondly, I do apologies, I
should've provided some more detailed on how I'm reproducing this in
my initial email. Below you can find a transcript of how I'm
conducting my tests:

The source OS which things (kernel and BPF reproducer program) are
being built on:

 $ cat /etc/os-release 
 PRETTY_NAME="Debian GNU/Linux rodete"
 NAME="Debian GNU/Linux"
 VERSION_ID="rodete"
 VERSION="12 (rodete)"
 VERSION_CODENAME=rodete
 ID=debian

Building latest LLVM and Pahole from source:

 $ sudo apt install -y cmake

 $ cmake --version
 cmake version 3.25.1

 $ git clone https://github.com/llvm/llvm-project.git  && cd llvm-project && \
 mkdir build && \
 cd build && \
 cmake -DLLVM_ENABLE_PROJECTS=clang -DCMAKE_BUILD_TYPE=Release -G "Unix Makefiles" ../llvm && \
 make -j $(nproc) && \
 sudo make install

 $ clang --version
 clang version 17.0.0 (https://github.com/llvm/llvm-project.git bc85cf1687435f28fb01b1aa5303317e6118490c)
 Target: x86_64-unknown-linux-gnu
 Thread model: posix
 InstalledDir: /usr/local/bin

 $ sudo apt install -y libdwarf-dev libdw-dev

 $ git clone git://git.kernel.org/pub/scm/devel/pahole/pahole.git && \
 cd pahole && \
 mkdir build && \
 cd build && \
 cmake -DCMAKE_INSTALL_PREFIX=/usr -D__LIB=lib .. && \
 make -j $(nproc) && \
 sudo make install

 $ pahole --version
 v1.25

Building a test kernel:

 $ git clone https://github.com/torvalds/linux.git && cd linux

 $ make defconfig && make kvm_guest.config

 $ scripts/config \
 -e BPF \
 -e BPF_SYSCALL \
 -e BPF_LSM \
 -e BPF_JIT \
 -e BPF_EVENTS \
 -e DEBUG_INFO \
 -e DEBUG_INFO_DWARF_TOOLCHAIN_DEFAULT \
 -e DEBUG_INFO_BTF \
 -e DEBUG_INFO_BTF_MODULES \
 -e PAHOLE_HAS_SPLIT_BTF \
 -e FTRACE \
 -e DYNAMIC_FTRACE \
 -e FUNCTION_TRACER

 $ make olddefconfig

 $ make -j`nproc`

Building the BPF reproducer program:

 $ git clone https://github.com/libbpf/libbpf-bootstrap.git

 # Both libbpf and bpftool should be the latest versions here.
 $ git submodule update --init --recursive

 $ cd examples/c

 $ cat > fentry.bpf.c<<EOF
 #include "vmlinux.h"
 #include <bpf/bpf_helpers.h>
 #include <bpf/bpf_tracing.h>

 char LICENSE[] SEC("license") = "Dual BSD/GPL";

 SEC("lsm.s/bprm_committed_creds")
 int BPF_PROG(dbg, struct linux_binprm *bprm)
 {
 char buf[64] = {0};
 bpf_ima_file_hash(bprm->file, buf, sizeof(buf));
 return 0;
 }
 EOF

 $ make -j`nproc` fentry


At this point, I basically launch the built kernel using QEMU and push
the built 'fentry' BPF program to the VM and run it. At that point, I
face the BPF verifier issue.

LMK whether you need any more information.

/M

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Thu, 2023-02-23 at 09:37 +0000, Matt Bobrowski wrote:
[...]
> LMK whether you need any more information.
> 
> /M

Hi Matt,

Unfortunately I can't reproduce the issue.
Here are the versions of the tools/repos that I use:

- kernel (tried both):
  - https://github.com/torvalds/linux.git
    a5c95ca18a98 ("Merge tag 'drm-next-2023-02-23' of git://anongit.freedesktop.org/drm/drm")
  - https://git.kernel.org/pub/scm/linux/kernel/git/bpf/bpf-next.git
    830b3c68c1fb ("Linux 6.1")
- config (tried both):
  - one obtained using your instructions
  - my small debug config for executing BPF tests ([1])
- LLVM:
  https://github.com/llvm/llvm-project.git
  bc85cf168743 ("[TextAPI] Add support for TBDv5 Files to nm & tapi-diff")
- pahole:
  git@github.com:acmel/dwarves.git
  ef68019 ("pahole: Update man page for options also")
- libbpf-bootstrap (just followed your instructions):
  https://github.com/libbpf/libbpf-bootstrap
  db4f7ad ("cmake: Fix btf header missing in legacy kernel env.")
- gcc (from my distro):
  gcc version 11.3.0 (Ubuntu 11.3.0-1ubuntu1~22.04)
- cat /etc/os-release 
  NAME="Linux Mint"
  VERSION="21.1 (Vera)"
  ID=linuxmint
  ID_LIKE="ubuntu debian"
  PRETTY_NAME="Linux Mint 21.1"
  VERSION_ID="21.1"
  VERSION_CODENAME=vera
  UBUNTU_CODENAME=jammy

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.

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]).

Thanks,
Eduard

[1] My config for BPF testing
    https://gist.github.com/eddyz87/aca79692d7bf57cfdd01b283b4304fd8
[2] Veristat verification log
    https://gist.github.com/eddyz87/49b211740bf99c426a37a3555b4542a3
    

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Thu, 2023-02-23 at 14:42 +0200, Eduard Zingerman wrote:
[...]
> - pahole:
>   git@github.com:acmel/dwarves.git
>   ef68019 ("pahole: Update man page for options also")
[...]
> - gcc (from my distro):
>   gcc version 11.3.0 (Ubuntu 11.3.0-1ubuntu1~22.04)

For the sake of completeness I tried pahole `master` instead of `next`:
  431df45 ("btfdiff: Exclude Rust CUs since those are not
            yet being converted to BTF on the Linux kernel")
And gcc 12 for kernel build (looks like its the gcc version for Debian 12).
The example still works.

¯\_(ツ)_/¯

Re: bpf: Question about odd BPF verifier behaviour

[Matt Bobrowski]

On Thu, Feb 23, 2023 at 02:42:40PM +0200, Eduard Zingerman wrote:
> On Thu, 2023-02-23 at 09:37 +0000, Matt Bobrowski wrote:
> [...]
> > LMK whether you need any more information.
> > 
> > /M
> 
> Hi Matt,
> 
> Unfortunately I can't reproduce the issue.
> Here are the versions of the tools/repos that I use:
> 
> - kernel (tried both):
>   - https://github.com/torvalds/linux.git
>     a5c95ca18a98 ("Merge tag 'drm-next-2023-02-23' of git://anongit.freedesktop.org/drm/drm")
>   - https://git.kernel.org/pub/scm/linux/kernel/git/bpf/bpf-next.git
>     830b3c68c1fb ("Linux 6.1")
> - config (tried both):
>   - one obtained using your instructions
>   - my small debug config for executing BPF tests ([1])
> - LLVM:
>   https://github.com/llvm/llvm-project.git
>   bc85cf168743 ("[TextAPI] Add support for TBDv5 Files to nm & tapi-diff")
> - pahole:
>   git@github.com:acmel/dwarves.git
>   ef68019 ("pahole: Update man page for options also")
> - libbpf-bootstrap (just followed your instructions):
>   https://github.com/libbpf/libbpf-bootstrap
>   db4f7ad ("cmake: Fix btf header missing in legacy kernel env.")
> - gcc (from my distro):
>   gcc version 11.3.0 (Ubuntu 11.3.0-1ubuntu1~22.04)
> - cat /etc/os-release 
>   NAME="Linux Mint"
>   VERSION="21.1 (Vera)"
>   ID=linuxmint
>   ID_LIKE="ubuntu debian"
>   PRETTY_NAME="Linux Mint 21.1"
>   VERSION_ID="21.1"
>   VERSION_CODENAME=vera
>   UBUNTU_CODENAME=jammy
> 
> 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?

> 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().

Here is the output from the veristat utility:

./veristat -l7 -v ./fentry.bpf.o 
Processing 'fentry.bpf.o'...
libbpf: prog 'dbg': BPF program load failed: Permission denied
libbpf: prog 'dbg': failed to load: -13
libbpf: failed to load object './fentry.bpf.o'
PROCESSING ./fentry.bpf.o/dbg, DURATION US: 4903, VERDICT: failure, VERIFIER LOG:
func#0 @0
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
last_idx 2 first_idx 0
regs=4 stack=0 before 1: (b7) r2 = 0
3: R2_w=0 R10=fp0 fp-8_w=00000000
3: (7b) *(u64 *)(r10 -16) = r2
last_idx 3 first_idx 0
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
4: R2_w=0 R10=fp0 fp-16_w=00000000
4: (7b) *(u64 *)(r10 -24) = r2
last_idx 4 first_idx 0
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
5: R2_w=0 R10=fp0 fp-24_w=00000000
5: (7b) *(u64 *)(r10 -32) = r2
last_idx 5 first_idx 0
regs=4 stack=0 before 4: (7b) *(u64 *)(r10 -24) = r2
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
6: R2_w=0 R10=fp0 fp-32_w=00000000
6: (7b) *(u64 *)(r10 -40) = r2
last_idx 6 first_idx 0
regs=4 stack=0 before 5: (7b) *(u64 *)(r10 -32) = r2
regs=4 stack=0 before 4: (7b) *(u64 *)(r10 -24) = r2
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
7: R2_w=0 R10=fp0 fp-40_w=00000000
7: (7b) *(u64 *)(r10 -48) = r2
last_idx 7 first_idx 0
regs=4 stack=0 before 6: (7b) *(u64 *)(r10 -40) = r2
regs=4 stack=0 before 5: (7b) *(u64 *)(r10 -32) = r2
regs=4 stack=0 before 4: (7b) *(u64 *)(r10 -24) = r2
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
8: R2_w=0 R10=fp0 fp-48_w=00000000
8: (7b) *(u64 *)(r10 -56) = r2
last_idx 8 first_idx 0
regs=4 stack=0 before 7: (7b) *(u64 *)(r10 -48) = r2
regs=4 stack=0 before 6: (7b) *(u64 *)(r10 -40) = r2
regs=4 stack=0 before 5: (7b) *(u64 *)(r10 -32) = r2
regs=4 stack=0 before 4: (7b) *(u64 *)(r10 -24) = r2
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
9: R2_w=0 R10=fp0 fp-56_w=00000000
9: (7b) *(u64 *)(r10 -64) = r2
last_idx 9 first_idx 0
regs=4 stack=0 before 8: (7b) *(u64 *)(r10 -56) = r2
regs=4 stack=0 before 7: (7b) *(u64 *)(r10 -48) = r2
regs=4 stack=0 before 6: (7b) *(u64 *)(r10 -40) = r2
regs=4 stack=0 before 5: (7b) *(u64 *)(r10 -32) = r2
regs=4 stack=0 before 4: (7b) *(u64 *)(r10 -24) = r2
regs=4 stack=0 before 3: (7b) *(u64 *)(r10 -16) = r2
regs=4 stack=0 before 2: (7b) *(u64 *)(r10 -8) = r2
regs=4 stack=0 before 1: (b7) r2 = 0
10: 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
verification time 4903 usec
stack depth 64
processed 15 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0

File          Program  Verdict  Duration (us)  Insns  States  Peak states
------------  -------  -------  -------------  -----  ------  -----------
fentry.bpf.o  dbg      failure           4903     15       0            0
------------  -------  -------  -------------  -----  ------  -----------
Done. Processed 1 files, 0 programs. Skipped 1 files, 0 programs.

> [1] My config for BPF testing
>     https://gist.github.com/eddyz87/aca79692d7bf57cfdd01b283b4304fd8
> [2] Veristat verification log
>     https://gist.github.com/eddyz87/49b211740bf99c426a37a3555b4542a3

/M

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

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

Re: bpf: Question about odd BPF verifier behaviour

[Matt Bobrowski]

[-- Attachment #1: Type: text/plain, Size: 14233 bytes --]

Sorry Eduard, I replied late last night although the email bounced due
to exceeding the mail char limit. Let's try attaching a compressed
variant of the requested files, which includes the compiled kernel's
BTF and the kernel's config.

On Fri, Feb 24, 2023 at 04:14:44PM +0200, Eduard Zingerman wrote:
> 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?

This sounds about right, as I'm also seeing the following during the
compilation phase of the kernel:

WARN: multiple IDs found for 'linux_binprm': 3971, 380629 - using 3971
WARN: multiple IDs found for 'task_struct': 214, 384262 - using 214
WARN: multiple IDs found for 'file': 454, 384289 - using 454
WARN: multiple IDs found for 'vm_area_struct': 459, 384292 - using 459
WARN: multiple IDs found for 'seq_file': 1069, 384326 - using 1069
WARN: multiple IDs found for 'inode': 711, 384439 - using 711
WARN: multiple IDs found for 'path': 743, 384468 - using 743
WARN: multiple IDs found for 'cgroup': 765, 384477 - using 765

I don't quite see understand why this would just start being a problem
now though? Perhaps this could be an issue with pahole? But then
again, you've also managed to build pahole from source and not run
into such issues...

>     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`?

Sure, the output from both can be found within the attached archive.

> Do you use any non-standard compilation flags?

Not for the kernel, nor the BPF program.

Would it help if I also provided the raw compiled binary of the BPF
program?

> > > 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.

Yes, I agree, but I'm not 100% sure why this is happening
either. Through some rough debugging, I've literally observed the BPF
verifier passing 2 completely different BTF IDs to
btf_struct_ids_match(), but I also don't know whether this is expected
or not? :)

/M

[-- Attachment #2: kernel_config_btf_output.tar.gz --]
[-- Type: application/gzip, Size: 34129 bytes --]

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> Sorry Eduard, I replied late last night although the email bounced due
> to exceeding the mail char limit. Let's try attaching a compressed
> variant of the requested files, which includes the compiled kernel's
> BTF and the kernel's config.

Hi Matt,

I tried using your config but still can't reproduce the issue.
Will try to do it using debian 12 chroot tomorrow or on Monday.

Thanks,
Eduard

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > Sorry Eduard, I replied late last night although the email bounced due
> > to exceeding the mail char limit. Let's try attaching a compressed
> > variant of the requested files, which includes the compiled kernel's
> > BTF and the kernel's config.
> 
> Hi Matt,
> 
> I tried using your config but still can't reproduce the issue.
> Will try to do it using debian 12 chroot tomorrow or on Monday.

Hi Matt,

Short update:
I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
in Debian testing chroot, thank you for providing all details.
Attaching the instructions in the end of the email.
Need some time to analyze pahole behavior.

Thanks,
Eduard

--

host root:
  mkdir bookworm
  sudo debootstrap testing bookworm/ http://deb.debian.org/debian/
  sudo mount -t proc proc bookworm/proc/
  sudo mount -t sysfs sys bookworm/sys/
  sudo chroot bookworm/ /bin/bash

bookworm root:
  apt install python3 bc build-essential git \
    cmake libdwarf-dev libdw-dev flex bison \
    kmod cpio libncurses5-dev libelf-dev libssl-dev
  adduser eddy
  sudo eddy

bookworm user:
  cd ~
  git clone git://git.kernel.org/pub/scm/devel/pahole/pahole.git
  mkdir build && \
    cd build && \
    cmake -D__LIB=lib .. && \
    make -j $(nproc)
  export PATH=/home/eddy/pahole/build/:$PATH
  cd ~
  git clone https://github.com/torvalds/linux.git && cd linux
  make defconfig && make kvm_guest.config
  scripts/config \
   -e BPF \
   -e BPF_SYSCALL \
   -e BPF_LSM \
   -e BPF_JIT \
   -e BPF_EVENTS \
   -e DEBUG_INFO \
   -e DEBUG_INFO_DWARF_TOOLCHAIN_DEFAULT \
   -e DEBUG_INFO_BTF \
   -e DEBUG_INFO_BTF_MODULES \
   -e PAHOLE_HAS_SPLIT_BTF \
   -e FTRACE \
   -e DYNAMIC_FTRACE \
   -e FUNCTION_TRACER
  make olddefconfig
  # Multiple warnings in the end:
  #   WARN: multiple IDs found for 'task_struct': 176, 23383 - using 176
  #   WARN: multiple IDs found for 'file': 638, 23422 - using 638
  #   ...
  
  make -C ./tools/bpf/bpftool
  ./tools/bpf/bpftool/bpftool btf dump file ./vmlinux | \
    grep -c linux_binprm
  # The output is 19 for me

Repository versions:
  - kernel:
    f3a2439f20d9 ("Merge tag 'rproc-v6.3' of git://git.kernel.org/pub/scm/linux/kernel/git/remoteproc/linux")
  - pahole:
    431df45 ("btfdiff: Exclude Rust CUs since those are not yet being converted to BTF on the Linux kernel")

Re: bpf: Question about odd BPF verifier behaviour

[Andrii Nakryiko]

On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
>
> On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > Sorry Eduard, I replied late last night although the email bounced due
> > > to exceeding the mail char limit. Let's try attaching a compressed
> > > variant of the requested files, which includes the compiled kernel's
> > > BTF and the kernel's config.
> >
> > Hi Matt,
> >
> > I tried using your config but still can't reproduce the issue.
> > Will try to do it using debian 12 chroot tomorrow or on Monday.
>
> Hi Matt,
>
> Short update:
> I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> in Debian testing chroot, thank you for providing all details.
> Attaching the instructions in the end of the email.
> Need some time to analyze pahole behavior.
>

Try using [0] to pinpoint what actually is different between any two
linux_binprm definitions. I've hacked up this "tool" last time I had
to pinpoint where two BTF types diverge, maybe it will save you a bit
of time as well. I'd like to put this functionality into btfdump
([1]), but I didn't get to it yet, unfortunately.

  [0] https://github.com/libbpf/libbpf-bootstrap/tree/btfdiff-hack
  [1] https://github.com/anakryiko/btfdump


> Thanks,
> Eduard
>
> --
>
> host root:
>   mkdir bookworm
>   sudo debootstrap testing bookworm/ http://deb.debian.org/debian/
>   sudo mount -t proc proc bookworm/proc/
>   sudo mount -t sysfs sys bookworm/sys/
>   sudo chroot bookworm/ /bin/bash
>

[...]

Re: bpf: Question about odd BPF verifier behaviour

[KP Singh]

On Mon, Feb 27, 2023 at 6:32 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
> >
> > On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > > Sorry Eduard, I replied late last night although the email bounced due
> > > > to exceeding the mail char limit. Let's try attaching a compressed
> > > > variant of the requested files, which includes the compiled kernel's
> > > > BTF and the kernel's config.
> > >
> > > Hi Matt,
> > >
> > > I tried using your config but still can't reproduce the issue.
> > > Will try to do it using debian 12 chroot tomorrow or on Monday.
> >
> > Hi Matt,
> >
> > Short update:
> > I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> > in Debian testing chroot, thank you for providing all details.
> > Attaching the instructions in the end of the email.
> > Need some time to analyze pahole behavior.
> >
>
> Try using [0] to pinpoint what actually is different between any two
> linux_binprm definitions. I've hacked up this "tool" last time I had
> to pinpoint where two BTF types diverge, maybe it will save you a bit
> of time as well. I'd like to put this functionality into btfdump
> ([1]), but I didn't get to it yet, unfortunately.
>

It's not just linux_binprm but a bunch of other structs (quite a lot
of them that seem to diverge)

[...]
WARN: multiple IDs found for 'sock_common': 4400, 53212 - using 4400
WARN: multiple IDs found for 'request_sock': 4458, 53257 - using 4458
WARN: multiple IDs found for 'task_struct': 265, 55830 - using 265
WARN: multiple IDs found for 'file': 474, 55854 - using 474
WARN: multiple IDs found for 'vm_area_struct': 480, 55857 - using 480
WARN: multiple IDs found for 'seq_file': 670, 55891 - using 670
WARN: multiple IDs found for 'sock': 3623, 55918 - using 3623
WARN: multiple IDs found for 'sk_buff': 3095, 56014 - using 3095
WARN: multiple IDs found for 'fib6_info': 8129, 56069 - using 8129
WARN: multiple IDs found for 'inode': 854, 56092 - using 854
WARN: multiple IDs found for 'path': 886, 56121 - using 886
WARN: multiple IDs found for 'cgroup': 913, 56130 - using 913
WARN: multiple IDs found for 'xdp_buff': 3838, 56558 - using 3838
WARN: multiple IDs found for 'socket': 3848, 56563 - using 3848
WARN: multiple IDs found for 'sock_common': 4400, 56890 - using 4400
WARN: multiple IDs found for 'request_sock': 4458, 56938 - using 4458
WARN: multiple IDs found for 'task_struct': 265, 58141 - using 265
WARN: multiple IDs found for 'inode': 854, 58153 - using 854
WARN: multiple IDs found for 'path': 886, 58182 - using 886
WARN: multiple IDs found for 'file': 474, 58207 - using 474
WARN: multiple IDs found for 'vm_area_struct': 480, 58210 - using 480
WARN: multiple IDs found for 'seq_file': 670, 58389 - using 670
WARN: multiple IDs found for 'task_struct': 265, 58862 - using 265
WARN: multiple IDs found for 'file': 474, 58889 - using 474
WARN: multiple IDs found for 'vm_area_struct': 480, 58892 - using 480
WARN: multiple IDs found for 'inode': 854, 58954 - using 854
WARN: multiple IDs found for 'path': 886, 58983 - using 886
WARN: multiple IDs found for 'cgroup': 913, 58992 - using 913
WARN: multiple IDs found for 'seq_file': 670, 59157 - using 670
WARN: multiple IDs found for 'sock': 3623, 59309 - using 3623
WARN: multiple IDs found for 'sk_buff': 3095, 59312 - using 3095
WARN: multiple IDs found for 'xdp_buff': 3838, 59699 - using 3838
WARN: multiple IDs found for 'socket': 3848, 59704 - using 3848
WARN: multiple IDs found for 'sock_common': 4400, 60021 - using 4400
WARN: multiple IDs found for 'request_sock': 4458, 60066 - using 4458
WARN: multiple IDs found for 'file': 474, 60890 - using 474
WARN: multiple IDs found for 'task_struct': 265, 60900 - using 265
WARN: multiple IDs found for 'vm_area_struct': 480, 60932 - using 480
WARN: multiple IDs found for 'inode': 854, 60962 - using 854
WARN: multiple IDs found for 'path': 886, 60991 - using 886
WARN: multiple IDs found for 'cgroup': 913, 61000 - using 913
WARN: multiple IDs found for 'seq_file': 670, 61174 - using 670
WARN: multiple IDs found for 'task_struct': 265, 62225 - using 265
WARN: multiple IDs found for 'file': 474, 62256 - using 474
WARN: multiple IDs found for 'vm_area_struct': 480, 62259 - using 480
WARN: multiple IDs found for 'seq_file': 670, 62289 - using 670
WARN: multiple IDs found for 'inode': 854, 62573 - using 854
WARN: multiple IDs found for 'path': 886, 62602 - using 886
[...]

  BTF     .btf.vmlinux.bin.o

seems to take 10+ minutes. Something seems off here, it seems like the
deduplication is failing for a lot of types which causes pahole to run
for so long.

My pahole is at:

431df45 ("btfdiff: Exclude Rust CUs since those are not yet being
converted to BTF on the Linux kernel")

Clang at:

9e5bfa1ae30b ("[AArch64] Add some tests for multiple uses of extended
vector extracts. NFC")

and kernel at:

68bfd65fb98d ("Merge branch 'move SYS() macro to test_progs.h and run
mptcp in a dedicated netns'")

and I am using the same config as vmtest.sh.

I was able to "fix" this with using clang 16.x and the following hacky pahole:

030e3b4 - core: Add DW_TAG_unspecified_type to tag__is_tag_type() set
(HEAD) (2023-02-26 Arnaldo Carvalho de Melo)
f20515b - dwarves: support DW_TAG_atomic_type (2023-02-26 David Lamparter)
de24234 - pahole: Prep 1.24 (tag: v1.24) (2022-08-22 Arnaldo Carvalho de Melo)
d6c9528 - dwarf_loader: Encode char type as signed (2022-08-10 Yonghong Song)

and the the following patch on top:

diff --git a/btf_encoder.c b/btf_encoder.c
index daa8e3b..3a29a67 100644
--- a/btf_encoder.c
+++ b/btf_encoder.c
@@ -939,6 +939,8 @@ static int btf_encoder__encode_tag(struct
btf_encoder *encoder, struct tag *tag,
                return btf_encoder__add_enum_type(encoder, tag, conf_load);
        case DW_TAG_subroutine_type:
                return btf_encoder__add_func_proto(encoder,
tag__ftype(tag), type_id_off);
+        case DW_TAG_unspecified_type:
+                return 0;
        default:
                fprintf(stderr, "Unsupported DW_TAG_%s(0x%x)\n",
                        dwarf_tag_name(tag->tag), tag->tag);
diff --git a/dwarves.h b/dwarves.h
index f18a639..b1dc556 100644
--- a/dwarves.h
+++ b/dwarves.h
@@ -544,10 +544,8 @@ static inline int tag__is_tag_type(const struct tag *tag)
               tag->tag == DW_TAG_reference_type ||
               tag->tag == DW_TAG_restrict_type ||
               tag->tag == DW_TAG_subroutine_type ||
-              tag->tag == DW_TAG_unspecified_type ||
               tag->tag == DW_TAG_volatile_type ||
               tag->tag == DW_TAG_atomic_type ||
-              tag->tag == DW_TAG_unspecified_type ||
               tag->tag == DW_TAG_LLVM_annotation;
 }

Now this is not a clean build and still has errors like:

tag__recode_dwarf_type: couldn't find 0xe82f542 type for 0xe82f4d2 (subprogram)!
tag__recode_dwarf_type: couldn't find 0xe82f542 type for 0xe82f4e2 (subprogram)!




>   [0] https://github.com/libbpf/libbpf-bootstrap/tree/btfdiff-hack
>   [1] https://github.com/anakryiko/btfdump
>
>
> > Thanks,
> > Eduard
> >
> > --
> >
> > host root:
> >   mkdir bookworm
> >   sudo debootstrap testing bookworm/ http://deb.debian.org/debian/
> >   sudo mount -t proc proc bookworm/proc/
> >   sudo mount -t sysfs sys bookworm/sys/
> >   sudo chroot bookworm/ /bin/bash
> >
>
> [...]

Re: bpf: Question about odd BPF verifier behaviour

[KP Singh]

On Mon, Feb 27, 2023 at 7:04 PM KP Singh <kpsingh@kernel.org> wrote:
>
> On Mon, Feb 27, 2023 at 6:32 PM Andrii Nakryiko
> <andrii.nakryiko@gmail.com> wrote:
> >
> > On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > >
> > > On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > > > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > > > Sorry Eduard, I replied late last night although the email bounced due
> > > > > to exceeding the mail char limit. Let's try attaching a compressed
> > > > > variant of the requested files, which includes the compiled kernel's
> > > > > BTF and the kernel's config.
> > > >
> > > > Hi Matt,
> > > >
> > > > I tried using your config but still can't reproduce the issue.
> > > > Will try to do it using debian 12 chroot tomorrow or on Monday.
> > >
> > > Hi Matt,
> > >
> > > Short update:
> > > I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> > > in Debian testing chroot, thank you for providing all details.
> > > Attaching the instructions in the end of the email.
> > > Need some time to analyze pahole behavior.
> > >
> >
> > Try using [0] to pinpoint what actually is different between any two
> > linux_binprm definitions. I've hacked up this "tool" last time I had
> > to pinpoint where two BTF types diverge, maybe it will save you a bit
> > of time as well. I'd like to put this functionality into btfdump
> > ([1]), but I didn't get to it yet, unfortunately.
> >
>
> It's not just linux_binprm but a bunch of other structs (quite a lot
> of them that seem to diverge)

It also does not seem to matter if I build the kernel with gcc or
clang, my suspicion went to an underlying dependency (libdw /
elfutils) I tried recompiling these from HEAD and downgrading the
package version too, but to no avail.

>
> [...]
> WARN: multiple IDs found for 'sock_common': 4400, 53212 - using 4400
> WARN: multiple IDs found for 'request_sock': 4458, 53257 - using 4458
> WARN: multiple IDs found for 'task_struct': 265, 55830 - using 265
> WARN: multiple IDs found for 'file': 474, 55854 - using 474
> WARN: multiple IDs found for 'vm_area_struct': 480, 55857 - using 480
> WARN: multiple IDs found for 'seq_file': 670, 55891 - using 670
> WARN: multiple IDs found for 'sock': 3623, 55918 - using 3623
> WARN: multiple IDs found for 'sk_buff': 3095, 56014 - using 3095
> WARN: multiple IDs found for 'fib6_info': 8129, 56069 - using 8129
> WARN: multiple IDs found for 'inode': 854, 56092 - using 854
> WARN: multiple IDs found for 'path': 886, 56121 - using 886
> WARN: multiple IDs found for 'cgroup': 913, 56130 - using 913
> WARN: multiple IDs found for 'xdp_buff': 3838, 56558 - using 3838
> WARN: multiple IDs found for 'socket': 3848, 56563 - using 3848
> WARN: multiple IDs found for 'sock_common': 4400, 56890 - using 4400
> WARN: multiple IDs found for 'request_sock': 4458, 56938 - using 4458
> WARN: multiple IDs found for 'task_struct': 265, 58141 - using 265
> WARN: multiple IDs found for 'inode': 854, 58153 - using 854
> WARN: multiple IDs found for 'path': 886, 58182 - using 886
> WARN: multiple IDs found for 'file': 474, 58207 - using 474
> WARN: multiple IDs found for 'vm_area_struct': 480, 58210 - using 480
> WARN: multiple IDs found for 'seq_file': 670, 58389 - using 670
> WARN: multiple IDs found for 'task_struct': 265, 58862 - using 265
> WARN: multiple IDs found for 'file': 474, 58889 - using 474
> WARN: multiple IDs found for 'vm_area_struct': 480, 58892 - using 480
> WARN: multiple IDs found for 'inode': 854, 58954 - using 854
> WARN: multiple IDs found for 'path': 886, 58983 - using 886
> WARN: multiple IDs found for 'cgroup': 913, 58992 - using 913
> WARN: multiple IDs found for 'seq_file': 670, 59157 - using 670
> WARN: multiple IDs found for 'sock': 3623, 59309 - using 3623
> WARN: multiple IDs found for 'sk_buff': 3095, 59312 - using 3095
> WARN: multiple IDs found for 'xdp_buff': 3838, 59699 - using 3838
> WARN: multiple IDs found for 'socket': 3848, 59704 - using 3848
> WARN: multiple IDs found for 'sock_common': 4400, 60021 - using 4400
> WARN: multiple IDs found for 'request_sock': 4458, 60066 - using 4458
> WARN: multiple IDs found for 'file': 474, 60890 - using 474
> WARN: multiple IDs found for 'task_struct': 265, 60900 - using 265
> WARN: multiple IDs found for 'vm_area_struct': 480, 60932 - using 480
> WARN: multiple IDs found for 'inode': 854, 60962 - using 854
> WARN: multiple IDs found for 'path': 886, 60991 - using 886
> WARN: multiple IDs found for 'cgroup': 913, 61000 - using 913
> WARN: multiple IDs found for 'seq_file': 670, 61174 - using 670
> WARN: multiple IDs found for 'task_struct': 265, 62225 - using 265
> WARN: multiple IDs found for 'file': 474, 62256 - using 474
> WARN: multiple IDs found for 'vm_area_struct': 480, 62259 - using 480
> WARN: multiple IDs found for 'seq_file': 670, 62289 - using 670
> WARN: multiple IDs found for 'inode': 854, 62573 - using 854
> WARN: multiple IDs found for 'path': 886, 62602 - using 886
> [...]
>
>   BTF     .btf.vmlinux.bin.o
>
> seems to take 10+ minutes. Something seems off here, it seems like the
> deduplication is failing for a lot of types which causes pahole to run
> for so long.
>
> My pahole is at:
>
> 431df45 ("btfdiff: Exclude Rust CUs since those are not yet being
> converted to BTF on the Linux kernel")
>
> Clang at:
>
> 9e5bfa1ae30b ("[AArch64] Add some tests for multiple uses of extended
> vector extracts. NFC")
>
> and kernel at:
>
> 68bfd65fb98d ("Merge branch 'move SYS() macro to test_progs.h and run
> mptcp in a dedicated netns'")
>
> and I am using the same config as vmtest.sh.
>
> I was able to "fix" this with using clang 16.x and the following hacky pahole:
>
> 030e3b4 - core: Add DW_TAG_unspecified_type to tag__is_tag_type() set
> (HEAD) (2023-02-26 Arnaldo Carvalho de Melo)
> f20515b - dwarves: support DW_TAG_atomic_type (2023-02-26 David Lamparter)
> de24234 - pahole: Prep 1.24 (tag: v1.24) (2022-08-22 Arnaldo Carvalho de Melo)
> d6c9528 - dwarf_loader: Encode char type as signed (2022-08-10 Yonghong Song)
>
> and the the following patch on top:
>
> diff --git a/btf_encoder.c b/btf_encoder.c
> index daa8e3b..3a29a67 100644
> --- a/btf_encoder.c
> +++ b/btf_encoder.c
> @@ -939,6 +939,8 @@ static int btf_encoder__encode_tag(struct
> btf_encoder *encoder, struct tag *tag,
>                 return btf_encoder__add_enum_type(encoder, tag, conf_load);
>         case DW_TAG_subroutine_type:
>                 return btf_encoder__add_func_proto(encoder,
> tag__ftype(tag), type_id_off);
> +        case DW_TAG_unspecified_type:
> +                return 0;
>         default:
>                 fprintf(stderr, "Unsupported DW_TAG_%s(0x%x)\n",
>                         dwarf_tag_name(tag->tag), tag->tag);
> diff --git a/dwarves.h b/dwarves.h
> index f18a639..b1dc556 100644
> --- a/dwarves.h
> +++ b/dwarves.h
> @@ -544,10 +544,8 @@ static inline int tag__is_tag_type(const struct tag *tag)
>                tag->tag == DW_TAG_reference_type ||
>                tag->tag == DW_TAG_restrict_type ||
>                tag->tag == DW_TAG_subroutine_type ||
> -              tag->tag == DW_TAG_unspecified_type ||
>                tag->tag == DW_TAG_volatile_type ||
>                tag->tag == DW_TAG_atomic_type ||
> -              tag->tag == DW_TAG_unspecified_type ||
>                tag->tag == DW_TAG_LLVM_annotation;
>  }
>
> Now this is not a clean build and still has errors like:
>
> tag__recode_dwarf_type: couldn't find 0xe82f542 type for 0xe82f4d2 (subprogram)!
> tag__recode_dwarf_type: couldn't find 0xe82f542 type for 0xe82f4e2 (subprogram)!
>
>
>
>
> >   [0] https://github.com/libbpf/libbpf-bootstrap/tree/btfdiff-hack
> >   [1] https://github.com/anakryiko/btfdump
> >
> >
> > > Thanks,
> > > Eduard
> > >
> > > --
> > >
> > > host root:
> > >   mkdir bookworm
> > >   sudo debootstrap testing bookworm/ http://deb.debian.org/debian/
> > >   sudo mount -t proc proc bookworm/proc/
> > >   sudo mount -t sysfs sys bookworm/sys/
> > >   sudo chroot bookworm/ /bin/bash
> > >
> >
> > [...]

Re: bpf: Question about odd BPF verifier behaviour

[Andrii Nakryiko]

On Mon, Feb 27, 2023 at 10:05 AM KP Singh <kpsingh@kernel.org> wrote:
>
> On Mon, Feb 27, 2023 at 6:32 PM Andrii Nakryiko
> <andrii.nakryiko@gmail.com> wrote:
> >
> > On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > >
> > > On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > > > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > > > Sorry Eduard, I replied late last night although the email bounced due
> > > > > to exceeding the mail char limit. Let's try attaching a compressed
> > > > > variant of the requested files, which includes the compiled kernel's
> > > > > BTF and the kernel's config.
> > > >
> > > > Hi Matt,
> > > >
> > > > I tried using your config but still can't reproduce the issue.
> > > > Will try to do it using debian 12 chroot tomorrow or on Monday.
> > >
> > > Hi Matt,
> > >
> > > Short update:
> > > I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> > > in Debian testing chroot, thank you for providing all details.
> > > Attaching the instructions in the end of the email.
> > > Need some time to analyze pahole behavior.
> > >
> >
> > Try using [0] to pinpoint what actually is different between any two
> > linux_binprm definitions. I've hacked up this "tool" last time I had
> > to pinpoint where two BTF types diverge, maybe it will save you a bit
> > of time as well. I'd like to put this functionality into btfdump
> > ([1]), but I didn't get to it yet, unfortunately.
> >
>
> It's not just linux_binprm but a bunch of other structs (quite a lot
> of them that seem to diverge)

yes, task_struct is usually a thing that suffers from such
duplications, as it forms a huge graph of types. Which is where that
btfdiff "tool" comes handly, it recursively compares side-by-side two
types that are supposed to be equal (but are not), by ignoring BTF
type IDs and trying to pin point actual differences (like STRUCT vs
FWD, or extra field, or whatever). It just needs two starting type
IDs.

>
> [...]
> WARN: multiple IDs found for 'sock_common': 4400, 53212 - using 4400
> WARN: multiple IDs found for 'request_sock': 4458, 53257 - using 4458
> WARN: multiple IDs found for 'task_struct': 265, 55830 - using 265
> WARN: multiple IDs found for 'file': 474, 55854 - using 474
> WARN: multiple IDs found for 'vm_area_struct': 480, 55857 - using 480
> WARN: multiple IDs found for 'seq_file': 670, 55891 - using 670


[...]

>
> I was able to "fix" this with using clang 16.x and the following hacky pahole:
>
> 030e3b4 - core: Add DW_TAG_unspecified_type to tag__is_tag_type() set
> (HEAD) (2023-02-26 Arnaldo Carvalho de Melo)
> f20515b - dwarves: support DW_TAG_atomic_type (2023-02-26 David Lamparter)
> de24234 - pahole: Prep 1.24 (tag: v1.24) (2022-08-22 Arnaldo Carvalho de Melo)
> d6c9528 - dwarf_loader: Encode char type as signed (2022-08-10 Yonghong Song)
>
> and the the following patch on top:
>

I'd start with understanding what BTF and DWARF differences are
causing the issue before trying to come up with the fix. For that we
don't even need config or repro steps, it should be enough to share
vmlinux with BTF and DWARF, and start from there.

But I'm sure Eduard is on top of this already (especially that he can
repro the issue now).

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Mon, 2023-02-27 at 11:24 -0800, Andrii Nakryiko wrote:
> On Mon, Feb 27, 2023 at 10:05 AM KP Singh <kpsingh@kernel.org> wrote:
> > 
> > On Mon, Feb 27, 2023 at 6:32 PM Andrii Nakryiko
> > <andrii.nakryiko@gmail.com> wrote:
> > > 
> > > On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > > > 
> > > > On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > > > > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > > > > Sorry Eduard, I replied late last night although the email bounced due
> > > > > > to exceeding the mail char limit. Let's try attaching a compressed
> > > > > > variant of the requested files, which includes the compiled kernel's
> > > > > > BTF and the kernel's config.
> > > > > 
> > > > > Hi Matt,
> > > > > 
> > > > > I tried using your config but still can't reproduce the issue.
> > > > > Will try to do it using debian 12 chroot tomorrow or on Monday.
> > > > 
> > > > Hi Matt,
> > > > 
> > > > Short update:
> > > > I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> > > > in Debian testing chroot, thank you for providing all details.
> > > > Attaching the instructions in the end of the email.
> > > > Need some time to analyze pahole behavior.
> > > > 
> > > 
> > > Try using [0] to pinpoint what actually is different between any two
> > > linux_binprm definitions. I've hacked up this "tool" last time I had
> > > to pinpoint where two BTF types diverge, maybe it will save you a bit
> > > of time as well. I'd like to put this functionality into btfdump
> > > ([1]), but I didn't get to it yet, unfortunately.
> > > 
> > 
> > It's not just linux_binprm but a bunch of other structs (quite a lot
> > of them that seem to diverge)
> 
> yes, task_struct is usually a thing that suffers from such
> duplications, as it forms a huge graph of types. Which is where that
> btfdiff "tool" comes handly, it recursively compares side-by-side two
> types that are supposed to be equal (but are not), by ignoring BTF
> type IDs and trying to pin point actual differences (like STRUCT vs
> FWD, or extra field, or whatever). It just needs two starting type
> IDs.

Thank you for links to these tools!

> 
> > 
> > [...]
> > WARN: multiple IDs found for 'sock_common': 4400, 53212 - using 4400
> > WARN: multiple IDs found for 'request_sock': 4458, 53257 - using 4458
> > WARN: multiple IDs found for 'task_struct': 265, 55830 - using 265
> > WARN: multiple IDs found for 'file': 474, 55854 - using 474
> > WARN: multiple IDs found for 'vm_area_struct': 480, 55857 - using 480
> > WARN: multiple IDs found for 'seq_file': 670, 55891 - using 670
> 
> 
> [...]
> 
> > 
> > I was able to "fix" this with using clang 16.x and the following hacky pahole:
> > 
> > 030e3b4 - core: Add DW_TAG_unspecified_type to tag__is_tag_type() set
> > (HEAD) (2023-02-26 Arnaldo Carvalho de Melo)
> > f20515b - dwarves: support DW_TAG_atomic_type (2023-02-26 David Lamparter)
> > de24234 - pahole: Prep 1.24 (tag: v1.24) (2022-08-22 Arnaldo Carvalho de Melo)
> > d6c9528 - dwarf_loader: Encode char type as signed (2022-08-10 Yonghong Song)
> > 
> > and the the following patch on top:
> > 
> 
> I'd start with understanding what BTF and DWARF differences are
> causing the issue before trying to come up with the fix. For that we
> don't even need config or repro steps, it should be enough to share
> vmlinux with BTF and DWARF, and start from there.
> 

Yes, I suspect that there is some kind of unanticipated
anomaly for some DWARF encoding for some kind of objects,
just need to find the root for the diverging type hierarchies. 

> But I'm sure Eduard is on top of this already (especially that he can
> repro the issue now).

I'm working on it, nothing to report yet, but I'm working on it.

Re: bpf: Question about odd BPF verifier behaviour

[Andrii Nakryiko]

On Mon, Feb 27, 2023 at 11:29 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
>
> On Mon, 2023-02-27 at 11:24 -0800, Andrii Nakryiko wrote:
> > On Mon, Feb 27, 2023 at 10:05 AM KP Singh <kpsingh@kernel.org> wrote:
> > >
> > > On Mon, Feb 27, 2023 at 6:32 PM Andrii Nakryiko
> > > <andrii.nakryiko@gmail.com> wrote:
> > > >
> > > > On Mon, Feb 27, 2023 at 6:17 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > > > >
> > > > > On Sun, 2023-02-26 at 03:03 +0200, Eduard Zingerman wrote:
> > > > > > On Sat, 2023-02-25 at 20:50 +0000, Matt Bobrowski wrote:
> > > > > > > Sorry Eduard, I replied late last night although the email bounced due
> > > > > > > to exceeding the mail char limit. Let's try attaching a compressed
> > > > > > > variant of the requested files, which includes the compiled kernel's
> > > > > > > BTF and the kernel's config.
> > > > > >
> > > > > > Hi Matt,
> > > > > >
> > > > > > I tried using your config but still can't reproduce the issue.
> > > > > > Will try to do it using debian 12 chroot tomorrow or on Monday.
> > > > >
> > > > > Hi Matt,
> > > > >
> > > > > Short update:
> > > > > I've reproduced the issue with multiple STRUCT 'linux_binprm' BTF IDs
> > > > > in Debian testing chroot, thank you for providing all details.
> > > > > Attaching the instructions in the end of the email.
> > > > > Need some time to analyze pahole behavior.
> > > > >
> > > >
> > > > Try using [0] to pinpoint what actually is different between any two
> > > > linux_binprm definitions. I've hacked up this "tool" last time I had
> > > > to pinpoint where two BTF types diverge, maybe it will save you a bit
> > > > of time as well. I'd like to put this functionality into btfdump
> > > > ([1]), but I didn't get to it yet, unfortunately.
> > > >
> > >
> > > It's not just linux_binprm but a bunch of other structs (quite a lot
> > > of them that seem to diverge)
> >
> > yes, task_struct is usually a thing that suffers from such
> > duplications, as it forms a huge graph of types. Which is where that
> > btfdiff "tool" comes handly, it recursively compares side-by-side two
> > types that are supposed to be equal (but are not), by ignoring BTF
> > type IDs and trying to pin point actual differences (like STRUCT vs
> > FWD, or extra field, or whatever). It just needs two starting type
> > IDs.
>
> Thank you for links to these tools!
>
> >
> > >
> > > [...]
> > > WARN: multiple IDs found for 'sock_common': 4400, 53212 - using 4400
> > > WARN: multiple IDs found for 'request_sock': 4458, 53257 - using 4458
> > > WARN: multiple IDs found for 'task_struct': 265, 55830 - using 265
> > > WARN: multiple IDs found for 'file': 474, 55854 - using 474
> > > WARN: multiple IDs found for 'vm_area_struct': 480, 55857 - using 480
> > > WARN: multiple IDs found for 'seq_file': 670, 55891 - using 670
> >
> >
> > [...]
> >
> > >
> > > I was able to "fix" this with using clang 16.x and the following hacky pahole:
> > >
> > > 030e3b4 - core: Add DW_TAG_unspecified_type to tag__is_tag_type() set
> > > (HEAD) (2023-02-26 Arnaldo Carvalho de Melo)
> > > f20515b - dwarves: support DW_TAG_atomic_type (2023-02-26 David Lamparter)
> > > de24234 - pahole: Prep 1.24 (tag: v1.24) (2022-08-22 Arnaldo Carvalho de Melo)
> > > d6c9528 - dwarf_loader: Encode char type as signed (2022-08-10 Yonghong Song)
> > >
> > > and the the following patch on top:
> > >
> >
> > I'd start with understanding what BTF and DWARF differences are
> > causing the issue before trying to come up with the fix. For that we
> > don't even need config or repro steps, it should be enough to share
> > vmlinux with BTF and DWARF, and start from there.
> >
>
> Yes, I suspect that there is some kind of unanticipated
> anomaly for some DWARF encoding for some kind of objects,
> just need to find the root for the diverging type hierarchies.
>
> > But I'm sure Eduard is on top of this already (especially that he can
> > repro the issue now).
>
> I'm working on it, nothing to report yet, but I'm working on it.
>

Thanks, please keep us posted!

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Mon, 2023-02-27 at 11:31 -0800, Andrii Nakryiko wrote:
[...]
> > > I'd start with understanding what BTF and DWARF differences are
> > > causing the issue before trying to come up with the fix. For that we
> > > don't even need config or repro steps, it should be enough to share
> > > vmlinux with BTF and DWARF, and start from there.
> > > 
> > 
> > Yes, I suspect that there is some kind of unanticipated
> > anomaly for some DWARF encoding for some kind of objects,
> > just need to find the root for the diverging type hierarchies.
> > 
> > > But I'm sure Eduard is on top of this already (especially that he can
> > > repro the issue now).
> > 
> > I'm working on it, nothing to report yet, but I'm working on it.
> > 
> 
> Thanks, please keep us posted!

It is interesting how everything is interconnected. The patch for
pahole below happens to help. I prepared it last week while working on
new DWARF encoding scheme for btf_type_tag.

I still need to track down which "unspecified_type" entries caused the
issue in this particular case. Will post an update tomorrow.

Meanwhile, Matt, KP, could you please verify the patch on your side?
It is for the "next" branch of pahole.

---

From 09fac63ca08e25aea499f827283b07cc87a7daab Mon Sep 17 00:00:00 2001
From: Eduard Zingerman <eddyz87@gmail.com>
Date: Tue, 21 Feb 2023 19:23:00 +0200
Subject: [PATCH] dwarf_loader: Fix for BTF id drift caused by adding
 unspecified types

Recent changes to handle unspecified types (see [1]) cause BTF ID drift.

Specifically, the intent of commits [2], [3] and [4] is to render
references to unspecified types as void type.
However, as a consequence:
- in `die__process_unit()` call to `cu__add_tag()` allocates `small_id`
  for unspecified type tags and adds these tags to `cu->types_table`;
- `btf_encoder__encode_tag()` skips generation of BTF entries for
  `DW_TAG_unspecified_type` tags.

Such logic causes ID drift if unspecified type is not the last type
processed for compilation unit. `small_id` of each type following
unspecified type in the `cu->types_table` would have its BTF id off by -1.
Thus renders references established on recode phase invalid.

This commit reverts `unspecified_type` id/tag tracking, instead:
- `small_id` for unspecified type tags is set to 0, thus reference to
  unspecified type tag would render BTF id of a `void` on recode phase;
- unspecified type tags are not added to `cu->types_table`.

[1] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/
[2] bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
[3] cffe5e1f75e1 ("core: Record if a CU has a DW_TAG_unspecified_type")
[4] 75e0fe28bb02 ("core: Add DW_TAG_unspecified_type to tag__is_tag_type() set")

Fixes: bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
---
 btf_encoder.c  |  8 --------
 dwarf_loader.c | 25 +++++++++++++++++++------
 dwarves.h      |  8 --------
 3 files changed, 19 insertions(+), 22 deletions(-)

diff --git a/btf_encoder.c b/btf_encoder.c
index da776f4..07a9dc5 100644
--- a/btf_encoder.c
+++ b/btf_encoder.c
@@ -69,7 +69,6 @@ struct btf_encoder {
 	const char	  *filename;
 	struct elf_symtab *symtab;
 	uint32_t	  type_id_off;
-	uint32_t	  unspecified_type;
 	int		  saved_func_cnt;
 	bool		  has_index_type,
 			  need_index_type,
@@ -635,11 +634,6 @@ static int32_t btf_encoder__tag_type(struct btf_encoder *encoder, uint32_t tag_t
 	if (tag_type == 0)
 		return 0;
 
-	if (encoder->unspecified_type && tag_type == encoder->unspecified_type) {
-		// No provision for encoding this, turn it into void.
-		return 0;
-	}
-
 	return encoder->type_id_off + tag_type;
 }
 
@@ -1746,8 +1740,6 @@ int btf_encoder__encode_cu(struct btf_encoder *encoder, struct cu *cu, struct co
 
 	encoder->cu = cu;
 	encoder->type_id_off = btf__type_cnt(encoder->btf) - 1;
-	if (encoder->cu->unspecified_type.tag)
-		encoder->unspecified_type = encoder->cu->unspecified_type.type;
 
 	if (!encoder->has_index_type) {
 		/* cu__find_base_type_by_name() takes "type_id_t *id" */
diff --git a/dwarf_loader.c b/dwarf_loader.c
index 014e130..c37bd7b 100644
--- a/dwarf_loader.c
+++ b/dwarf_loader.c
@@ -2155,8 +2155,7 @@ static struct tag *__die__process_tag(Dwarf_Die *die, struct cu *cu,
 	case DW_TAG_atomic_type:
 		tag = die__create_new_tag(die, cu);		break;
 	case DW_TAG_unspecified_type:
-		cu->unspecified_type.tag =
-			tag = die__create_new_tag(die, cu);     break;
+		tag = die__create_new_tag(die, cu);		break;
 	case DW_TAG_pointer_type:
 		tag = die__create_new_pointer_tag(die, cu, conf);	break;
 	case DW_TAG_ptr_to_member_type:
@@ -2219,13 +2218,27 @@ static int die__process_unit(Dwarf_Die *die, struct cu *cu, struct conf_load *co
 			continue;
 		}
 
-		uint32_t id;
-		cu__add_tag(cu, tag, &id);
+		uint32_t id = 0;
+		/* There is no BTF representation for unspecified types.
+		 * Currently we want such types to be represented as `void`
+		 * (and thus skip BTF encoding).
+		 *
+		 * As BTF encoding is skipped, such types must not be added to type table,
+		 * otherwise an ID for a type would be allocated and we would be forced
+		 * to put something in BTF at this ID.
+		 * Thus avoid `cu__add_tag()` call for such types.
+		 *
+		 * On the other hand, there might be references to this type from other
+		 * tags, so `dwarf_cu__find_tag_by_ref()` must return something.
+		 * Thus call `cu__hash()` for such types.
+		 *
+		 * Note, that small_id of zero would be assigned to unspecified type entry.
+		 */
+		if (tag->tag != DW_TAG_unspecified_type)
+			cu__add_tag(cu, tag, &id);
 		cu__hash(cu, tag);
 		struct dwarf_tag *dtag = tag->priv;
 		dtag->small_id = id;
-		if (tag->tag == DW_TAG_unspecified_type)
-			cu->unspecified_type.type = id;
 	} while (dwarf_siblingof(die, die) == 0);
 
 	return 0;
diff --git a/dwarves.h b/dwarves.h
index 5074cf8..e92b2fd 100644
--- a/dwarves.h
+++ b/dwarves.h
@@ -236,10 +236,6 @@ struct debug_fmt_ops {
 
 #define ARCH_MAX_REGISTER_PARAMS	8
 
-/*
- * unspecified_type: If this CU has a DW_TAG_unspecified_type, as BTF doesn't have a representation for this
- * 		     and thus we need to check functions returning this to convert it to void.
- */
 struct cu {
 	struct list_head node;
 	struct list_head tags;
@@ -248,10 +244,6 @@ struct cu {
 	struct ptr_table functions_table;
 	struct ptr_table tags_table;
 	struct rb_root	 functions;
-	struct {
-		struct tag	 *tag;
-		uint32_t	 type;
-	} unspecified_type;
 	char		 *name;
 	char		 *filename;
 	void 		 *priv;
-- 
2.39.1

Re: bpf: Question about odd BPF verifier behaviour

[KP Singh]

On Mon, Feb 27, 2023 at 9:48 PM Eduard Zingerman <eddyz87@gmail.com> wrote:
>
> On Mon, 2023-02-27 at 11:31 -0800, Andrii Nakryiko wrote:
> [...]
> > > > I'd start with understanding what BTF and DWARF differences are
> > > > causing the issue before trying to come up with the fix. For that we
> > > > don't even need config or repro steps, it should be enough to share
> > > > vmlinux with BTF and DWARF, and start from there.
> > > >
> > >
> > > Yes, I suspect that there is some kind of unanticipated
> > > anomaly for some DWARF encoding for some kind of objects,
> > > just need to find the root for the diverging type hierarchies.
> > >
> > > > But I'm sure Eduard is on top of this already (especially that he can
> > > > repro the issue now).
> > >
> > > I'm working on it, nothing to report yet, but I'm working on it.
> > >
> >
> > Thanks, please keep us posted!
>
> It is interesting how everything is interconnected. The patch for
> pahole below happens to help. I prepared it last week while working on
> new DWARF encoding scheme for btf_type_tag.
>
> I still need to track down which "unspecified_type" entries caused the
> issue in this particular case. Will post an update tomorrow.
>
> Meanwhile, Matt, KP, could you please verify the patch on your side?
> It is for the "next" branch of pahole.
>
> ---
>
> From 09fac63ca08e25aea499f827283b07cc87a7daab Mon Sep 17 00:00:00 2001
> From: Eduard Zingerman <eddyz87@gmail.com>
> Date: Tue, 21 Feb 2023 19:23:00 +0200
> Subject: [PATCH] dwarf_loader: Fix for BTF id drift caused by adding
>  unspecified types
>
> Recent changes to handle unspecified types (see [1]) cause BTF ID drift.
>
> Specifically, the intent of commits [2], [3] and [4] is to render
> references to unspecified types as void type.
> However, as a consequence:
> - in `die__process_unit()` call to `cu__add_tag()` allocates `small_id`
>   for unspecified type tags and adds these tags to `cu->types_table`;
> - `btf_encoder__encode_tag()` skips generation of BTF entries for
>   `DW_TAG_unspecified_type` tags.
>
> Such logic causes ID drift if unspecified type is not the last type
> processed for compilation unit. `small_id` of each type following
> unspecified type in the `cu->types_table` would have its BTF id off by -1.
> Thus renders references established on recode phase invalid.
>
> This commit reverts `unspecified_type` id/tag tracking, instead:
> - `small_id` for unspecified type tags is set to 0, thus reference to
>   unspecified type tag would render BTF id of a `void` on recode phase;
> - unspecified type tags are not added to `cu->types_table`.
>
> [1] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/
> [2] bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> [3] cffe5e1f75e1 ("core: Record if a CU has a DW_TAG_unspecified_type")
> [4] 75e0fe28bb02 ("core: Add DW_TAG_unspecified_type to tag__is_tag_type() set")
>
> Fixes: bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>

Tested-by: KP Singh <kpsingh@kernel.org>
Reported-by: Matt Bobrowski <mattbobrowski@google.com>

Thank you so much Eduard, this worked:

* No duplicate BTF ID warnings
* No 15 minute BTF ID generation
* Matt's reproducer loads successfully.

I had a sneaky suspicion that it was these unspecified types, which is
why my hacky patch which got unspecified types out of the way got
things to *mostly* work.

Re: bpf: Question about odd BPF verifier behaviour

[Eduard Zingerman]

On Tue, 2023-02-28 at 03:55 +0100, KP Singh wrote:
> On Mon, Feb 27, 2023 at 9:48 PM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > 
> > On Mon, 2023-02-27 at 11:31 -0800, Andrii Nakryiko wrote:
> > [...]
> > > > > I'd start with understanding what BTF and DWARF differences are
> > > > > causing the issue before trying to come up with the fix. For that we
> > > > > don't even need config or repro steps, it should be enough to share
> > > > > vmlinux with BTF and DWARF, and start from there.
> > > > > 
> > > > 
> > > > Yes, I suspect that there is some kind of unanticipated
> > > > anomaly for some DWARF encoding for some kind of objects,
> > > > just need to find the root for the diverging type hierarchies.
> > > > 
> > > > > But I'm sure Eduard is on top of this already (especially that he can
> > > > > repro the issue now).
> > > > 
> > > > I'm working on it, nothing to report yet, but I'm working on it.
> > > > 
> > > 
> > > Thanks, please keep us posted!
> > 
> > It is interesting how everything is interconnected. The patch for
> > pahole below happens to help. I prepared it last week while working on
> > new DWARF encoding scheme for btf_type_tag.
> > 
> > I still need to track down which "unspecified_type" entries caused the
> > issue in this particular case. Will post an update tomorrow.
> > 
> > Meanwhile, Matt, KP, could you please verify the patch on your side?
> > It is for the "next" branch of pahole.
> > 
> > ---
> > 
> > From 09fac63ca08e25aea499f827283b07cc87a7daab Mon Sep 17 00:00:00 2001
> > From: Eduard Zingerman <eddyz87@gmail.com>
> > Date: Tue, 21 Feb 2023 19:23:00 +0200
> > Subject: [PATCH] dwarf_loader: Fix for BTF id drift caused by adding
> >  unspecified types
> > 
> > Recent changes to handle unspecified types (see [1]) cause BTF ID drift.
> > 
> > Specifically, the intent of commits [2], [3] and [4] is to render
> > references to unspecified types as void type.
> > However, as a consequence:
> > - in `die__process_unit()` call to `cu__add_tag()` allocates `small_id`
> >   for unspecified type tags and adds these tags to `cu->types_table`;
> > - `btf_encoder__encode_tag()` skips generation of BTF entries for
> >   `DW_TAG_unspecified_type` tags.
> > 
> > Such logic causes ID drift if unspecified type is not the last type
> > processed for compilation unit. `small_id` of each type following
> > unspecified type in the `cu->types_table` would have its BTF id off by -1.
> > Thus renders references established on recode phase invalid.
> > 
> > This commit reverts `unspecified_type` id/tag tracking, instead:
> > - `small_id` for unspecified type tags is set to 0, thus reference to
> >   unspecified type tag would render BTF id of a `void` on recode phase;
> > - unspecified type tags are not added to `cu->types_table`.
> > 
> > [1] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/
> > [2] bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> > [3] cffe5e1f75e1 ("core: Record if a CU has a DW_TAG_unspecified_type")
> > [4] 75e0fe28bb02 ("core: Add DW_TAG_unspecified_type to tag__is_tag_type() set")
> > 
> > Fixes: bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> > Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
> 
> Tested-by: KP Singh <kpsingh@kernel.org>
> Reported-by: Matt Bobrowski <mattbobrowski@google.com>
> 
> Thank you so much Eduard, this worked:
> 
> * No duplicate BTF ID warnings
> * No 15 minute BTF ID generation
> * Matt's reproducer loads successfully.
> 
> I had a sneaky suspicion that it was these unspecified types, which is
> why my hacky patch which got unspecified types out of the way got
> things to *mostly* work.

Hi KP,

Thanks a lot for testing!

I found the root cause for the bug (took me longer than I would like
to admit...). Using the patch below the reproducer from Matt works as
expected and warnings are gone.

Still, I think that my patch from yesterday is a more general
approach, as it correctly handles unspecified types that occur in
non-tail position, so I'll post that one.

Thanks,
Eduard

---

From daa53248e8a5087edbceaffe1fad51f9eb06e922 Mon Sep 17 00:00:00 2001
From: Eduard Zingerman <eddyz87@gmail.com>
Date: Tue, 28 Feb 2023 19:44:22 +0200
Subject: [PATCH] btf_encoder: reset encoder->unspecified_type for each CU

The field `encoder->unspecified_type` is set but not reset by function
`btf_encoder__encode_cu()` when processed `cu` has unspecified type.
The following sequence of events might occur when BTF encoding is
requested:
- CU with unspecified type is processed:
  - unspecified type id is 42
  - encoder->unspecified_type is set to 42
- CU without unspecified type is processed next using the same
  `encoder` object:
  - some `struct foo` has id 42 in this CU
  - the references to `struct foo` are set 0 by function
    `btf_encoder__tag_type()`.

This commit sets `encoder->unspecified_type` to 0 when CU does not
have unspecified type.

This issue was reported in thread [1].
See also [2].
[1] https://lore.kernel.org/bpf/Y%2FP1yxAuV6Wj3A0K@google.com/
[2] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/

Fixes: 52b25808e44a ("btf_encoder: Store type_id_off, unspecified type in encoder")
Reported-by: Matt Bobrowski <mattbobrowski@google.com>
Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
---
 btf_encoder.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/btf_encoder.c b/btf_encoder.c
index da776f4..24f4c65 100644
--- a/btf_encoder.c
+++ b/btf_encoder.c
@@ -1748,6 +1748,8 @@ int btf_encoder__encode_cu(struct btf_encoder *encoder, struct cu *cu, struct co
 	encoder->type_id_off = btf__type_cnt(encoder->btf) - 1;
 	if (encoder->cu->unspecified_type.tag)
 		encoder->unspecified_type = encoder->cu->unspecified_type.type;
+	else
+		encoder->unspecified_type = 0;
 
 	if (!encoder->has_index_type) {
 		/* cu__find_base_type_by_name() takes "type_id_t *id" */
-- 
2.39.1

Re: bpf: Question about odd BPF verifier behaviour

[Andrii Nakryiko]

On Tue, Feb 28, 2023 at 10:08 AM Eduard Zingerman <eddyz87@gmail.com> wrote:
>
> On Tue, 2023-02-28 at 03:55 +0100, KP Singh wrote:
> > On Mon, Feb 27, 2023 at 9:48 PM Eduard Zingerman <eddyz87@gmail.com> wrote:
> > >
> > > On Mon, 2023-02-27 at 11:31 -0800, Andrii Nakryiko wrote:
> > > [...]
> > > > > > I'd start with understanding what BTF and DWARF differences are
> > > > > > causing the issue before trying to come up with the fix. For that we
> > > > > > don't even need config or repro steps, it should be enough to share
> > > > > > vmlinux with BTF and DWARF, and start from there.
> > > > > >
> > > > >
> > > > > Yes, I suspect that there is some kind of unanticipated
> > > > > anomaly for some DWARF encoding for some kind of objects,
> > > > > just need to find the root for the diverging type hierarchies.
> > > > >
> > > > > > But I'm sure Eduard is on top of this already (especially that he can
> > > > > > repro the issue now).
> > > > >
> > > > > I'm working on it, nothing to report yet, but I'm working on it.
> > > > >
> > > >
> > > > Thanks, please keep us posted!
> > >
> > > It is interesting how everything is interconnected. The patch for
> > > pahole below happens to help. I prepared it last week while working on
> > > new DWARF encoding scheme for btf_type_tag.
> > >
> > > I still need to track down which "unspecified_type" entries caused the
> > > issue in this particular case. Will post an update tomorrow.
> > >
> > > Meanwhile, Matt, KP, could you please verify the patch on your side?
> > > It is for the "next" branch of pahole.
> > >
> > > ---
> > >
> > > From 09fac63ca08e25aea499f827283b07cc87a7daab Mon Sep 17 00:00:00 2001
> > > From: Eduard Zingerman <eddyz87@gmail.com>
> > > Date: Tue, 21 Feb 2023 19:23:00 +0200
> > > Subject: [PATCH] dwarf_loader: Fix for BTF id drift caused by adding
> > >  unspecified types
> > >
> > > Recent changes to handle unspecified types (see [1]) cause BTF ID drift.
> > >
> > > Specifically, the intent of commits [2], [3] and [4] is to render
> > > references to unspecified types as void type.
> > > However, as a consequence:
> > > - in `die__process_unit()` call to `cu__add_tag()` allocates `small_id`
> > >   for unspecified type tags and adds these tags to `cu->types_table`;
> > > - `btf_encoder__encode_tag()` skips generation of BTF entries for
> > >   `DW_TAG_unspecified_type` tags.
> > >
> > > Such logic causes ID drift if unspecified type is not the last type
> > > processed for compilation unit. `small_id` of each type following
> > > unspecified type in the `cu->types_table` would have its BTF id off by -1.
> > > Thus renders references established on recode phase invalid.
> > >
> > > This commit reverts `unspecified_type` id/tag tracking, instead:
> > > - `small_id` for unspecified type tags is set to 0, thus reference to
> > >   unspecified type tag would render BTF id of a `void` on recode phase;
> > > - unspecified type tags are not added to `cu->types_table`.
> > >
> > > [1] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/
> > > [2] bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> > > [3] cffe5e1f75e1 ("core: Record if a CU has a DW_TAG_unspecified_type")
> > > [4] 75e0fe28bb02 ("core: Add DW_TAG_unspecified_type to tag__is_tag_type() set")
> > >
> > > Fixes: bcc648a10cbc ("btf_encoder: Encode DW_TAG_unspecified_type returning routines as void")
> > > Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
> >
> > Tested-by: KP Singh <kpsingh@kernel.org>
> > Reported-by: Matt Bobrowski <mattbobrowski@google.com>
> >
> > Thank you so much Eduard, this worked:
> >
> > * No duplicate BTF ID warnings
> > * No 15 minute BTF ID generation
> > * Matt's reproducer loads successfully.
> >
> > I had a sneaky suspicion that it was these unspecified types, which is
> > why my hacky patch which got unspecified types out of the way got
> > things to *mostly* work.
>
> Hi KP,
>
> Thanks a lot for testing!
>
> I found the root cause for the bug (took me longer than I would like
> to admit...). Using the patch below the reproducer from Matt works as
> expected and warnings are gone.
>
> Still, I think that my patch from yesterday is a more general
> approach, as it correctly handles unspecified types that occur in
> non-tail position, so I'll post that one.

I agree, please send it to dwarves@ as a proper patch. Thank you for
digging into this and fixing it quickly!

>
> Thanks,
> Eduard
>
> ---
>
> From daa53248e8a5087edbceaffe1fad51f9eb06e922 Mon Sep 17 00:00:00 2001
> From: Eduard Zingerman <eddyz87@gmail.com>
> Date: Tue, 28 Feb 2023 19:44:22 +0200
> Subject: [PATCH] btf_encoder: reset encoder->unspecified_type for each CU
>
> The field `encoder->unspecified_type` is set but not reset by function
> `btf_encoder__encode_cu()` when processed `cu` has unspecified type.
> The following sequence of events might occur when BTF encoding is
> requested:
> - CU with unspecified type is processed:
>   - unspecified type id is 42
>   - encoder->unspecified_type is set to 42
> - CU without unspecified type is processed next using the same
>   `encoder` object:
>   - some `struct foo` has id 42 in this CU
>   - the references to `struct foo` are set 0 by function
>     `btf_encoder__tag_type()`.
>
> This commit sets `encoder->unspecified_type` to 0 when CU does not
> have unspecified type.
>
> This issue was reported in thread [1].
> See also [2].
> [1] https://lore.kernel.org/bpf/Y%2FP1yxAuV6Wj3A0K@google.com/
> [2] https://lore.kernel.org/all/Y0R7uu3s%2FimnvPzM@kernel.org/
>
> Fixes: 52b25808e44a ("btf_encoder: Store type_id_off, unspecified type in encoder")
> Reported-by: Matt Bobrowski <mattbobrowski@google.com>
> Signed-off-by: Eduard Zingerman <eddyz87@gmail.com>
> ---
>  btf_encoder.c | 2 ++
>  1 file changed, 2 insertions(+)
>
> diff --git a/btf_encoder.c b/btf_encoder.c
> index da776f4..24f4c65 100644
> --- a/btf_encoder.c
> +++ b/btf_encoder.c
> @@ -1748,6 +1748,8 @@ int btf_encoder__encode_cu(struct btf_encoder *encoder, struct cu *cu, struct co
>         encoder->type_id_off = btf__type_cnt(encoder->btf) - 1;
>         if (encoder->cu->unspecified_type.tag)
>                 encoder->unspecified_type = encoder->cu->unspecified_type.type;
> +       else
> +               encoder->unspecified_type = 0;
>
>         if (!encoder->has_index_type) {
>                 /* cu__find_base_type_by_name() takes "type_id_t *id" */
> --
> 2.39.1