Skip to contentSkip to conversation

Hitting verifier backtracking bug on 6.5.5 kernel

DISCUSSION Toke Høiland-Jørgensen 6 participants 16 messages Oct 12, 2023 – Oct 30, 2023

Subsystems (2)
BPF BPF core
lore
Share & tools
lore

Toke Høiland-Jørgensen

author
#0 lore raw

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

	1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
	; switch (protocol) {
	1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
	; if ((void *)udp + sizeof(*udp) <= data_end) {
	1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
	1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
	; if ((void *)udp + sizeof(*udp) <= data_end) {
	1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
	; id->src_port = bpf_ntohs(udp->source);
	1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
	1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
	1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
	; id->src_port = bpf_ntohs(udp->source);
	1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
	; id->src_port = bpf_ntohs(udp->source);
	1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
	; id->src_port = bpf_ntohs(udp->source);
	1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
	1893: (73) *(u8 *)(r1 +48) = r2
	BUG regs 1
	processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
	(truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Thanks!

-Toke

#1 lore raw
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Quoted 4 lines

Thanks!

-Toke

author
#2 lore raw
Quoted 72 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Quoted 7 lines

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

-Toke

#3 lore raw
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8

*)(r1 +47) = r3

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Quoted 3 lines

-Toke

author
#4 lore raw
Quoted 92 lines · Andrii Nakryiko
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8
Quoted 7 lines

*)(r1 +47) = r3

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

-Toke

#5 lore raw

Any idea why the same verification errors are not seen when the program is attached with bpftool ?

Thanks!
Mohamed

Quoted 108 lines · Toke Høiland-Jørgensen
Quoted 92 lines · Andrii Nakryiko
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8
Quoted 7 lines

*)(r1 +47) = r3

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

-Toke

#6 lore raw
Quoted 2 lines · Mohamed Mahmoud

Any idea why the same verification errors are not seen when the program is attached with bpftool ?

Not sure why, but I've captured the verifier log during the successful tc load here (using a slightly modified tc) on v6.5.4:
https://gist.github.com/shunghsiyu/b3bd6e4f4e1510e98a80491d50f3908b

    1890: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
    ; id->src_port = bpf_ntohs(udp->source);
    1891: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
    1892: (73) *(u8 *)(r1 +48) = r2
    mark_precise: frame2: last_idx 1892 first_idx 1883 subseq_idx -1 
    mark_precise: frame2: regs=r2 stack= before 1891: (77) r2 >>= 56
    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8 *)(r1 +47) = r3
    mark_precise: frame2: regs=r0,r2 stack= before 1888: (dc) r3 = be16 r3
    mark_precise: frame2: regs=r0,r2 stack= before 1887: (bf) r3 = r2
    mark_precise: frame2: regs=r0,r2 stack= before 1886: (69) r2 = *(u16 *)(r7 +0)
    mark_precise: frame2: regs=r0 stack= before 1885: (2d) if r3 > r2 goto pc+23
    mark_precise: frame2: regs=r0 stack= before 1884: (07) r3 += 8
    mark_precise: frame2: regs=r0 stack= before 1883: (bf) r3 = r7
    mark_precise: frame2: parent state regs= stack=:  frame2: R1_r=fp-160 R2_r=pkt_end(off=0,imm=0) R3=17 R4=fp-96 R6=fp-96 R7_r=pkt(off=54,r=54,imm=0) R10=fp0
    mark_precise: frame1: parent state regs= stack=:  frame1: R6=ctx(off=0,imm=0) R7=1 R8=pkt_end(off=0,imm=0) R10=fp0 fp-56= fp-64=00000000 fp-72=00000000 fp-80=00000000 fp-88=mmmmmmmm fp-96=fp fp-104=??????00 fp-112=0000m000 fp-120= fp-128=mmmmmmmm fp-136=mmmmmmmm fp-144= fp-152=mmmmmmmm fp-160=mmmmm0mm
    mark_precise: frame0: parent state regs= stack=:  R10=fp0
    ; id->dst_port = bpf_ntohs(udp->dest);
    1893: (69) r2 = *(u16 *)(r7 +2)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7=pkt(off=54,r=62,imm=0)

Looks like r0 is also being incorrectly added the to the precise regs set here; but I'm not sure why backtracking didn't go all the way back to "call pc+1617" (which trigger the warning).

Quoted 110 lines · Toke Høiland-Jørgensen
Quoted 108 lines
Quoted 92 lines · Andrii Nakryiko
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8
Quoted 7 lines

*)(r1 +47) = r3

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

-Toke

#7 lore raw
In reply to Toke Høiland-Jørgensen
Quoted 96 lines · Toke Høiland-Jørgensen
Quoted 94 lines · Andrii Nakryiko
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8

*)(r1 +47) = r3

Quoted 8 lines
Quoted 5 lines

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

---
 kernel/bpf/verifier.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)
kernel/bpf/verifier.c +3 -1
index 9cdba4ce23d2..7e396288aaf0 100644
@@ -3418,7 +3418,9 @@ static int backtrack_insn(struct bpf_verifier_env *env, int idx, int subseq_idx,
 	if (class == BPF_ALU || class == BPF_ALU64) {
 		if (!bt_is_reg_set(bt, dreg))
 			return 0;
-		if (opcode == BPF_MOV) {
+		if (opcode == BPF_END || opcode == BPF_NEG) {
+			return 0;
+		} else if (opcode == BPF_MOV) {
 			if (BPF_SRC(insn->code) == BPF_X) {
 				/* dreg = sreg
 				 * dreg needs precision after this insn
Signature · 1 line
2.42.0
#8 lore raw
Quoted 20 lines · Shung-Hsi Yu
Quoted 4 lines

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

---
 kernel/bpf/verifier.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)
kernel/bpf/verifier.c +0 -0
index 9cdba4ce23d2..7e396288aaf0 100644

kernel/bpf/verifier.c static int backtrack_insn(struct bpf_verifier_env *env, int idx, int subseq_idx, · line 3423

Quoted 7 lines
kernel/bpf/verifier.c +3 -1
@@ -3418,7 +3418,9 @@ static int backtrack_insn(struct bpf_verifier_env *env, int idx, int subseq_idx,
        if (class == BPF_ALU || class == BPF_ALU64) {
                if (!bt_is_reg_set(bt, dreg))
                        return 0;
-               if (opcode == BPF_MOV) {
+               if (opcode == BPF_END || opcode == BPF_NEG) {
+                       return 0;
+               } else if (opcode == BPF_MOV) {

lgtm. Pls send an official patch with a selftest.

author Tested-by
#9 lore raw
In reply to Shung-Hsi Yu
Quoted 103 lines · Shung-Hsi Yu
Quoted 102 lines · Toke Høiland-Jørgensen
Quoted 99 lines · Andrii Nakryiko
Quoted 79 lines · Toke Høiland-Jørgensen
Quoted 76 lines · Andrii Nakryiko
Quoted 62 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

Quoted 8 lines

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Yes, I tried. Unfortunately I can't build netobserv-ebpf-agent on my dev machine and can't run it. I tried to load bpf_bpfel.o through veristat, but unfortunately it is not libbpf-compatible.

Quoted 6 lines
Quoted 3 lines

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8

*)(r1 +47) = r3

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Quoted 8 lines
Quoted 2 lines

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

Alright, manually applied this to bpf-next and indeed this enables the netobserv-bpf-agent to load successfully. Care to submit a formal patch? In that case please add my:

Tested-by Toke Høiland-Jørgensen <[email protected]>

Thanks!

-Toke

author
#10 lore raw
Quoted 8 lines · Toke Høiland-Jørgensen
Quoted 5 lines · Shung-Hsi Yu

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

Quoted 7 lines

Alright, manually applied this to bpf-next and indeed this enables the netobserv-bpf-agent to load successfully. Care to submit a formal patch? In that case please add my:

Tested-by Toke Høiland-Jørgensen <[email protected]>

Thanks!

Friendly ping - are you planning to submit an official patch for this? :)

-Toke

#11 lore raw
Quoted 13 lines · Toke Høiland-Jørgensen
Quoted 12 lines · Toke Høiland-Jørgensen
Quoted 5 lines · Shung-Hsi Yu

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

Alright, manually applied this to bpf-next and indeed this enables the netobserv-bpf-agent to load successfully. Care to submit a formal patch? In that case please add my:

Quoted 5 lines
Quoted 3 lines
Tested-by Toke Høiland-Jørgensen <[email protected]>

Thanks!

Friendly ping - are you planning to submit an official patch for this? :)

Yes, I do plan to send an offical one along with selftest as Alexei has suggested. Once I've got my irrational fear of writing selftests overcame ;)

Should have it out before the end of this week.

Shung-Hsi

Quoted 1 line

-Toke

author
#12 lore raw
Quoted 16 lines · Shung-Hsi Yu
Quoted 15 lines · Toke Høiland-Jørgensen
Quoted 14 lines · Toke Høiland-Jørgensen
Quoted 5 lines · Shung-Hsi Yu

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

Alright, manually applied this to bpf-next and indeed this enables the netobserv-bpf-agent to load successfully. Care to submit a formal patch? In that case please add my:

Tested-by Toke Høiland-Jørgensen <[email protected]>
Quoted 8 lines
Quoted 3 lines
Quoted 1 line

Thanks!

Friendly ping - are you planning to submit an official patch for this? :)

Yes, I do plan to send an offical one along with selftest as Alexei has suggested. Once I've got my irrational fear of writing selftests overcame ;)

Should have it out before the end of this week.

Alright great! Didn't mean to rush you, just wanted to double check that you were planning to submit this :)

Thanks!

-Toke

#13 lore raw
In reply to Toke Høiland-Jørgensen
Quoted 64 lines · Toke Høiland-Jørgensen
Quoted 63 lines · Shung-Hsi Yu
Quoted 62 lines · Toke Høiland-Jørgensen
Quoted 61 lines · Andrii Nakryiko
Quoted 44 lines · Toke Høiland-Jørgensen
Quoted 43 lines · Andrii Nakryiko
Quoted 42 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090
Quoted 8 lines
Quoted 5 lines
Quoted 1 line

...

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8

*)(r1 +47) = r3

Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
Quoted 5 lines

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Turns out the only case r0 is wrongly added to the regs set is with BPF_ALU | BPF_TO_BE | BPF_END like the one seen here (only realize this while working on selftests). All other cases are already handled correctly because they happens to fall into the BPF_SRC(insn->code) == BPF_K == 0 case.

        } else {
                if (BPF_SRC(insn->code) == BPF_X) {
                        bt_set_reg(bt, sreg);
                }
                /* BPF_NEG, BPF_ALU | BPF_TO_LE | BPF_END, and
                 * BPF_ALU64 | BPF_END goes here in backtrack_insn()
                 */
        }

That said, having a "if (opcode == BPF_END || opcode == BPF_NEG)" check still makes more sense, so I'm sticking with that.

RFC can be found at
https://lore.kernel.org/bpf/[email protected]/

Quoted 18 lines
Quoted 8 lines
Quoted 2 lines

Sounds good, thank you for looking into it! Let me know if you need me to test a patch :)

Patch based on Andrii's analysis.

Given that both BPF_END and BPF_NEG always operates on dst_reg itself and that bt_is_reg_set(bt, dreg) was already checked I believe we can just return with no futher action.

Alright, manually applied this to bpf-next and indeed this enables the netobserv-bpf-agent to load successfully. Care to submit a formal patch? In that case please add my:

Tested-by Toke Høiland-Jørgensen <[email protected]>

Thanks!

-Toke

author
#14 lore raw
Quoted 85 lines · Shung-Hsi Yu
Quoted 64 lines · Toke Høiland-Jørgensen
Quoted 63 lines · Shung-Hsi Yu
Quoted 62 lines · Toke Høiland-Jørgensen
Quoted 61 lines · Andrii Nakryiko
Quoted 44 lines · Toke Høiland-Jørgensen
Quoted 43 lines · Andrii Nakryiko
Quoted 42 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090
Quoted 8 lines
Quoted 5 lines
Quoted 1 line

...

Is there some way to get a full verifier log for the failure above? with log_level 2, if possible? If you can share it through Github Gist or something like that, I'd really appreciate it. Thanks!

Sure, here you go:
https://gist.github.com/tohojo/31173d2bb07262a21393f76d9a45132d

Thanks, this is very useful. And it's pretty clear what happens from last few lines:

    mark_precise: frame2: regs=r2 stack= before 1890: (dc) r2 = be64 r2
    mark_precise: frame2: regs=r0,r2 stack= before 1889: (73) *(u8

*)(r1 +47) = r3

Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
Quoted 5 lines

See how we add r0 to the regs set, while there is no r0 involved in r2 = be64 r2? I think it's just a missing case of handling BPF_END (and perhaps BPF_NEG as well) instructions in backtrack_insn(). Should be a trivial fix, though ideally we should also add some test for this as well.

Turns out the only case r0 is wrongly added to the regs set is with BPF_ALU | BPF_TO_BE | BPF_END like the one seen here (only realize this while working on selftests). All other cases are already handled correctly because they happens to fall into the BPF_SRC(insn->code) == BPF_K == 0 case.

        } else {
                if (BPF_SRC(insn->code) == BPF_X) {
                        bt_set_reg(bt, sreg);
                }
                /* BPF_NEG, BPF_ALU | BPF_TO_LE | BPF_END, and
                 * BPF_ALU64 | BPF_END goes here in backtrack_insn()
                 */
        }
Quoted 5 lines

That said, having a "if (opcode == BPF_END || opcode == BPF_NEG)" check still makes more sense, so I'm sticking with that.

RFC can be found at
https://lore.kernel.org/bpf/[email protected]/

Great, thanks for taking care of this! :)

-Toke

#15 lore raw
In reply to Toke Høiland-Jørgensen
Quoted 58 lines · Toke Høiland-Jørgensen

Hi Andrii

Mohamed ran into what appears to be a verifier bug related to your commit:

fde2a3882bd0 ("bpf: support precision propagation in the presence of subprogs")

So I figured you'd be the person to ask about this :)

The issue appears on a vanilla 6.5 kernel (on both 6.5.6 on Fedora 38, and 6.5.5 on my Arch machine):

INFO[0000] Verifier error: load program: bad address:

        1861: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=scalar(umin=17,umax=255,var_off=(0x0; 0xff)) R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; switch (protocol) {
        1861: (15) if r3 == 0x11 goto pc+22 1884: frame2: R1_w=fp-160 R2_w=pkt_end(off=0,imm=0) R3=17 R4_w=fp-96 R6_w=fp-96 R7_w=pkt(off=34,r=34,imm=0) R10=fp0
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1884: (bf) r3 = r7                    ; frame2: R3_w=pkt(off=34,r=34,imm=0) R7_w=pkt(off=34,r=34,imm=0)
        1885: (07) r3 += 8                    ; frame2: R3_w=pkt(off=42,r=34,imm=0)
        ; if ((void *)udp + sizeof(*udp) <= data_end) {
        1886: (2d) if r3 > r2 goto pc+23      ; frame2: R2_w=pkt_end(off=0,imm=0) R3_w=pkt(off=42,r=42,imm=0)
        ; id->src_port = bpf_ntohs(udp->source);
        1887: (69) r2 = *(u16 *)(r7 +0)       ; frame2: R2_w=scalar(umax=65535,var_off=(0x0; 0xffff)) R7_w=pkt(off=34,r=42,imm=0)
        1888: (bf) r3 = r2                    ; frame2: R2_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff)) R3_w=scalar(id=103,umax=65535,var_off=(0x0; 0xffff))
        1889: (dc) r3 = be16 r3               ; frame2: R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1890: (73) *(u8 *)(r1 +47) = r3       ; frame2: R1_w=fp-160 R3_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1891: (dc) r2 = be64 r2               ; frame2: R2_w=scalar()
        ; id->src_port = bpf_ntohs(udp->source);
        1892: (77) r2 >>= 56                  ; frame2: R2_w=scalar(umax=255,var_off=(0x0; 0xff))
        1893: (73) *(u8 *)(r1 +48) = r2
        BUG regs 1
        processed 5121 insns (limit 1000000) max_states_per_insn 4 total_states 92 peak_states 90 mark_read 20
        (truncated)  component=ebpf.FlowFetcher

Dmesg says:

[252431.093126] verifier backtracking bug
[252431.093129] WARNING: CPU: 3 PID: 302245 at kernel/bpf/verifier.c:3533 __mark_chain_precision+0xe83/0x1090

The splat appears when trying to run the netobserv-ebpf-agent. Steps to reproduce:

git clone https://github.com/netobserv/netobserv-ebpf-agent
cd netobserv-ebpf-agent && make compile
sudo FLOWS_TARGET_HOST=127.0.0.1 FLOWS_TARGET_PORT=9999 ./bin/netobserv-ebpf-agent

(It needs a 'make generate' before the compile to recompile the BPF program itself, but that requires the Cilium bpf2go program to be installed and there's a binary version checked into the tree so that is not strictly necessary to reproduce the splat).

That project uses the Cilium Go eBPF loader. Interestingly, loading the same program using tc (with libbpf 1.2.2) works just fine:

Quoted 9 lines

ip link add type veth
tc qdisc add dev veth0 clsact
tc filter add dev veth0 egress bpf direct-action obj pkg/ebpf/bpf_bpfel.o sec tc_egress

So maybe there is some massaging of the object file that libbpf is doing but the Go library isn't, that prevents this bug from triggering? I'm only guessing here, I don't really know exactly what the Go library is doing under the hood.

Interesting, have you tried https://github.com/cilium/ebpf/pull/1159 ?

Quoted 8 lines

Anyway, I guess this is a kernel bug in any case since that WARN() is there; could you please take a look?

Thanks!

-Toke