All of lore.kernel.org
 help / color / mirror / Atom feed
* Verifier rejects previously accepted program
@ 2021-11-03 11:55 Lorenz Bauer
  2021-11-04 16:50 ` Alexei Starovoitov
  2021-11-16  9:26 ` Lorenz Bauer
  0 siblings, 2 replies; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-03 11:55 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: kernel-team, bpf, regressions, Andrii Nakryiko, Daniel Borkmann

Hi Alexei,

I started testing our load balancer on 5.15 today, unfortunately BPF
which is happy on 5.10 gets rejected on the latest kernel.

    BPF program is too large. Processed 1000001 insn
    processed 1000001 insns (limit 1000000) max_states_per_insn 28
total_states 40641 peak_states 1104 mark_read 53

It looks like the verifier has to spend more instructions on verifying
a gnarly loop we have (start and end are u8*):

#pragma clang loop unroll(full)
    for (int b = 1 << 10; b >= 4; b >>= 1) {
        if (start + b > end) {
            continue;
        }

        // If we do 8 byte reads, we have to handle overflows which is
slower than 4 byte reads.
        for (int i = 0; i < b; i += 4) {
            csum += *(uint32_t *)(start + i);
        }

        start += b;
    }
    if (start + 2 <= end) {
        csum += *(uint16_t *)(start);
        start += 2;
    }
    if (start + 1 <= end) {
        csum += *(start);
    }

clang compiles this to:

;               if (start + b > end) {
    1906:       bf 75 00 00 00 00 00 00 r5 = r7
    1907:       07 05 00 00 4a 04 00 00 r5 += 1098
    1908:       2d 15 0d 00 00 00 00 00 if r5 > r1 goto +13 <LBB0_374>
    1909:       b7 03 00 00 00 00 00 00 r3 = 0
    1910:       b7 00 00 00 4a 00 00 00 r0 = 74
;               for (int i = 0; i < b; i += 4) {
    1911:       b7 08 00 00 4a 00 00 00 r8 = 74

0000000000003bc0 <LBB0_373>:
;                       csum += *(uint32_t *)(start + i);
    1912:       bf 74 00 00 00 00 00 00 r4 = r7
    1913:       0f 04 00 00 00 00 00 00 r4 += r0
    1914:       61 44 00 00 00 00 00 00 r4 = *(u32 *)(r4 + 0)
    1915:       0f 43 00 00 00 00 00 00 r3 += r4
;               for (int i = 0; i < b; i += 4) {
    1916:       07 08 00 00 04 00 00 00 r8 += 4
    1917:       bf 09 00 00 00 00 00 00 r9 = r0
    1918:       07 09 00 00 b6 ff ff ff r9 += -74
    1919:       bf 80 00 00 00 00 00 00 r0 = r8
    1920:       bf 54 00 00 00 00 00 00 r4 = r5
    1921:       a5 09 f6 ff fc 03 00 00 if r9 < 1020 goto -10 <LBB0_373>

0000000000003c10 <LBB0_374>:
;               if (start + b > end) {
    1922:       bf 40 00 00 00 00 00 00 r0 = r4
    1923:       07 00 00 00 00 02 00 00 r0 += 512
    1924:       bf 45 00 00 00 00 00 00 r5 = r4
    1925:       2d 10 09 00 00 00 00 00 if r0 > r1 goto +9 <LBB0_377>
    1926:       b7 08 00 00 00 00 00 00 r8 = 0

0000000000003c38 <LBB0_376>:
    1927:       bf 89 00 00 00 00 00 00 r9 = r8
;                       csum += *(uint32_t *)(start + i);
    1928:       bf 45 00 00 00 00 00 00 r5 = r4
    1929:       0f 95 00 00 00 00 00 00 r5 += r9
    1930:       61 55 00 00 00 00 00 00 r5 = *(u32 *)(r5 + 0)
    1931:       0f 53 00 00 00 00 00 00 r3 += r5
;               for (int i = 0; i < b; i += 4) {
    1932:       07 08 00 00 04 00 00 00 r8 += 4
    1933:       bf 05 00 00 00 00 00 00 r5 = r0
;               for (int i = 0; i < b; i += 4) {
    1934:       a5 09 f8 ff fc 01 00 00 if r9 < 508 goto -8 <LBB0_376>

0000000000003c78 <LBB0_377>:
;               if (start + b > end) {
    1935:       bf 50 00 00 00 00 00 00 r0 = r5
    1936:       07 00 00 00 00 01 00 00 r0 += 256
    1937:       bf 54 00 00 00 00 00 00 r4 = r5
    1938:       2d 10 09 00 00 00 00 00 if r0 > r1 goto +9 <LBB0_380>
    1939:       b7 08 00 00 00 00 00 00 r8 = 0

0000000000003ca0 <LBB0_379>:
    1940:       bf 89 00 00 00 00 00 00 r9 = r8
;                       csum += *(uint32_t *)(start + i);
    1941:       bf 54 00 00 00 00 00 00 r4 = r5
    1942:       0f 94 00 00 00 00 00 00 r4 += r9
    1943:       61 44 00 00 00 00 00 00 r4 = *(u32 *)(r4 + 0)
    1944:       0f 43 00 00 00 00 00 00 r3 += r4
;               for (int i = 0; i < b; i += 4) {
    1945:       07 08 00 00 04 00 00 00 r8 += 4
    1946:       bf 04 00 00 00 00 00 00 r4 = r0
;               for (int i = 0; i < b; i += 4) {
    1947:       a5 09 f8 ff fc 00 00 00 if r9 < 252 goto -8 <LBB0_379>

If b is <= 128 clang simply unrolls the loop. With log_level = 2 the
verifier output is full of tracing of those loops. A "short" excerpt:

    ; for (int i = 0; i < b; i += 4) {
    1911: (b7) r8 = 74
    1912: R0_w=inv74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0) R3_w=inv0
R4=pkt(id=0,off=74,r=1098,imm=0) R5_w=pkt(id=0,off=1098,r=1098,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv74
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    ; csum += *(uint32_t *)(start + i);
    1912: (bf) r4 = r7
    1913: R0_w=inv74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0) R3_w=inv0
R4_w=pkt(id=0,off=0,r=1098,imm=0) R5_w=pkt(id=0,off=1098,r=1098,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv74
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1913: (0f) r4 += r0
    last_idx 1913 first_idx 1901
    regs=1 stack=0 before 1912: (bf) r4 = r7
    regs=1 stack=0 before 1911: (b7) r8 = 74
    regs=1 stack=0 before 1910: (b7) r0 = 74
    1914: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0) R3_w=inv0
R4_w=pkt(id=0,off=74,r=1098,imm=0)
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv74
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1914: (61) r4 = *(u32 *)(r4 +0)
    1915: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0) R3_w=inv0
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv74
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    ; csum += *(uint32_t *)(start + i);
    1915: (0f) r3 += r4
    1916: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv74
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    ; for (int i = 0; i < b; i += 4) {
    1916: (07) r8 += 4
    1917: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv78
R9=inv(id=0,umax_value=65535,var_off=(0x0; 0xffff)) R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1917: (bf) r9 = r0
    1918: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv78 R9_w=invP74 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1918: (07) r9 += -74
    1919: R0_w=invP74 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv78 R9_w=invP0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1919: (bf) r0 = r8
    1920: R0_w=inv78 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv78 R9_w=invP0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    1920: (bf) r4 = r5
    1921: R0_w=inv78 R1=pkt_end(id=0,off=0,imm=0)
R2_w=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4_w=pkt(id=0,off=1098,r=1098,imm=0)
R5_w=pkt(id=0,off=1098,r=1098,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=pkt(id=0,off=0,r=1098,imm=0) R8_w=inv78 R9_w=invP0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
fp-128=map_value
    ; for (int i = 0; i < b; i += 4) {
    1921: (a5) if r9 < 0x3fc goto pc-10
    1912: R0=inv78 R1=pkt_end(id=0,off=0,imm=0)
R2=map_value(id=0,off=0,ks=4,vs=368,imm=0)
R3=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff))
R4=pkt(id=0,off=1098,r=1098,imm=0) R5=pkt(id=0,off=1098,r=1098,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=pkt(id=0,off=0,r=1098,imm=0) R8=inv78
R9=invP0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=mmmmmmmm fp-104=map_value
fp-112=inv fp-120=fp fp-128=map_value

I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
pointer mismatch in bpf_timer_init.") The commit seems unrelated to
loop processing though (it does touch the verifier however). Either I
got the bisection wrong or there is something subtle going on.

Lorenz

#regzb introduced: 3e8ce29850f1 ("bpf: Prevent pointer mismatch in
bpf_timer_init.")

--
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-03 11:55 Verifier rejects previously accepted program Lorenz Bauer
@ 2021-11-04 16:50 ` Alexei Starovoitov
  2021-11-04 23:30   ` sdf
  2021-11-05 10:41   ` Lorenz Bauer
  2021-11-16  9:26 ` Lorenz Bauer
  1 sibling, 2 replies; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-04 16:50 UTC (permalink / raw)
  To: Lorenz Bauer
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Wed, Nov 3, 2021 at 4:55 AM Lorenz Bauer <lmb@cloudflare.com> wrote:

> #pragma clang loop unroll(full)
>     for (int b = 1 << 10; b >= 4; b >>= 1) {
>         if (start + b > end) {
>             continue;
>         }
>
>         // If we do 8 byte reads, we have to handle overflows which is
> slower than 4 byte reads.
>         for (int i = 0; i < b; i += 4) {
>             csum += *(uint32_t *)(start + i);
>         }
>
>         start += b;
>     }
>     if (start + 2 <= end) {
>         csum += *(uint16_t *)(start);
>         start += 2;
>     }
>     if (start + 1 <= end) {
>         csum += *(start);
>     }

Thanks for flagging!
Could you craft a test case that we can use a repro and future
test case?

> fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
...
> I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
> pointer mismatch in bpf_timer_init.") The commit seems unrelated to
> loop processing though (it does touch the verifier however). Either I
> got the bisection wrong or there is something subtle going on.

I stared at that commit and the example asm.
I suspect the bisect went wrong.

Could you try reverting a single
commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill")
?
The above fp-112=inv means that the verifier is tracking scalar spill.
That could be the reason for bounded loop logic seeing different
stack state on every iteration.
But the asm snippet doesn't have the store to stack at [fp-112]
location, so it could be a red herring.

Are you using the same llvm during bisect?
The commit 354e8f1970f8 should be harmless
(when commit f30d4968e9ae ("bpf: Do not reject when the stack read
size is different from the tracked scalar size"))
is also applied. That fix is in bpf tree only, so far.
The tracking of 8-byte spill is the most useful with the latest llvm
that was taught to use 8-byte aligned stack for such spills.

Without being able to repro it's hard to investigate much further.

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-04 16:50 ` Alexei Starovoitov
@ 2021-11-04 23:30   ` sdf
  2021-11-05  1:20     ` Alexei Starovoitov
  2021-11-05 10:41   ` Lorenz Bauer
  1 sibling, 1 reply; 19+ messages in thread
From: sdf @ 2021-11-04 23:30 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Lorenz Bauer, Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann, Martin KaFai Lau

On 11/04, Alexei Starovoitov wrote:
> On Wed, Nov 3, 2021 at 4:55 AM Lorenz Bauer <lmb@cloudflare.com> wrote:

> > #pragma clang loop unroll(full)
> >     for (int b = 1 << 10; b >= 4; b >>= 1) {
> >         if (start + b > end) {
> >             continue;
> >         }
> >
> >         // If we do 8 byte reads, we have to handle overflows which is
> > slower than 4 byte reads.
> >         for (int i = 0; i < b; i += 4) {
> >             csum += *(uint32_t *)(start + i);
> >         }
> >
> >         start += b;
> >     }
> >     if (start + 2 <= end) {
> >         csum += *(uint16_t *)(start);
> >         start += 2;
> >     }
> >     if (start + 1 <= end) {
> >         csum += *(start);
> >     }

> Thanks for flagging!
> Could you craft a test case that we can use a repro and future
> test case?

> > fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
> ...
> > I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
> > pointer mismatch in bpf_timer_init.") The commit seems unrelated to
> > loop processing though (it does touch the verifier however). Either I
> > got the bisection wrong or there is something subtle going on.

> I stared at that commit and the example asm.
> I suspect the bisect went wrong.

> Could you try reverting a single
> commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill")
> ?
> The above fp-112=inv means that the verifier is tracking scalar spill.
> That could be the reason for bounded loop logic seeing different
> stack state on every iteration.
> But the asm snippet doesn't have the store to stack at [fp-112]
> location, so it could be a red herring.

> Are you using the same llvm during bisect?
> The commit 354e8f1970f8 should be harmless
> (when commit f30d4968e9ae ("bpf: Do not reject when the stack read
> size is different from the tracked scalar size"))
> is also applied. That fix is in bpf tree only, so far.
> The tracking of 8-byte spill is the most useful with the latest llvm
> that was taught to use 8-byte aligned stack for such spills.

> Without being able to repro it's hard to investigate much further.

Not to derail the conversation, but we do actually see a problem
with commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and
refill"). Program that passed without it now gets:

  R0=inv(id=0) R1_w=invP0 R2_w=invP0 R5_w=inv0 R6=ctx(id=0,off=0,imm=0)  
R7=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R8=inv(id=0)  
R9_w=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R10=fp0 fp-8=mmmm????  
fp-16=mmmmmmmm fp-24=00000000 fp-32=inv fp-40=00000000 fp-48=inv  
fp-56=mmmmmmmm fp-64=mmmmmmmm
479: (79) r1 = *(u64 *)(r10 -32)
corrupted spill memory
processed 970 insns (limit 1000000) max_states_per_insn 2 total_states 73  
peak_states 73 mark_read 24

Here is where R10 flips from 'fp0' to 'fp-8=mmmm????':

137: (5d) if r3 != r4 goto pc-102
  R0=inv(id=0) R1=invP0 R2=inv0 R3_w=inv4294901760 R4_w=inv4294901760  
R6=ctx(id=0,off=0,imm=0) R7=inv8 R10=fp0 fp-16=00000000 fp-24=00000000  
fp-32=00000000 fp-40=00000000 fp-48=00000000 fp-56=mmmmmmmm
138: (61) r7 = *(u32 *)(r6 +28)
139: (61) r2 = *(u32 *)(r6 +24)
140: (63) *(u32 *)(r10 -48) = r2
141: (63) *(u32 *)(r10 -32) = r7
142: (63) *(u32 *)(r10 -4) = r1
143: (bf) r2 = r10
144: (07) r2 += -4
145: (18) r1 = 0xffff8803fe837e00
147: (85) call bpf_map_lookup_elem#1
148: (55) if r0 != 0x0 goto pc+5
  R0=inv0 R6=ctx(id=0,off=0,imm=0)  
R7=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0  
fp-8=mmmm???? fp-16=00000000 fp-24=00000000 fp-32=inv fp-40=00000000  
fp-48=inv fp-56=mmmmmmmm

We are not using latest clang (don't have https://reviews.llvm.org/D109073).

Added Martin to CC in case he can get any clues from the verifier log.

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-04 23:30   ` sdf
@ 2021-11-05  1:20     ` Alexei Starovoitov
  2021-11-05  4:13       ` Stanislav Fomichev
  0 siblings, 1 reply; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-05  1:20 UTC (permalink / raw)
  To: Stanislav Fomichev
  Cc: Lorenz Bauer, Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann, Martin KaFai Lau

On Thu, Nov 4, 2021 at 4:30 PM <sdf@google.com> wrote:
>
> On 11/04, Alexei Starovoitov wrote:
> > On Wed, Nov 3, 2021 at 4:55 AM Lorenz Bauer <lmb@cloudflare.com> wrote:
>
> > > #pragma clang loop unroll(full)
> > >     for (int b = 1 << 10; b >= 4; b >>= 1) {
> > >         if (start + b > end) {
> > >             continue;
> > >         }
> > >
> > >         // If we do 8 byte reads, we have to handle overflows which is
> > > slower than 4 byte reads.
> > >         for (int i = 0; i < b; i += 4) {
> > >             csum += *(uint32_t *)(start + i);
> > >         }
> > >
> > >         start += b;
> > >     }
> > >     if (start + 2 <= end) {
> > >         csum += *(uint16_t *)(start);
> > >         start += 2;
> > >     }
> > >     if (start + 1 <= end) {
> > >         csum += *(start);
> > >     }
>
> > Thanks for flagging!
> > Could you craft a test case that we can use a repro and future
> > test case?
>
> > > fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
> > ...
> > > I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
> > > pointer mismatch in bpf_timer_init.") The commit seems unrelated to
> > > loop processing though (it does touch the verifier however). Either I
> > > got the bisection wrong or there is something subtle going on.
>
> > I stared at that commit and the example asm.
> > I suspect the bisect went wrong.
>
> > Could you try reverting a single
> > commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill")
> > ?
> > The above fp-112=inv means that the verifier is tracking scalar spill.
> > That could be the reason for bounded loop logic seeing different
> > stack state on every iteration.
> > But the asm snippet doesn't have the store to stack at [fp-112]
> > location, so it could be a red herring.
>
> > Are you using the same llvm during bisect?
> > The commit 354e8f1970f8 should be harmless
> > (when commit f30d4968e9ae ("bpf: Do not reject when the stack read
> > size is different from the tracked scalar size"))
> > is also applied. That fix is in bpf tree only, so far.
> > The tracking of 8-byte spill is the most useful with the latest llvm
> > that was taught to use 8-byte aligned stack for such spills.
>
> > Without being able to repro it's hard to investigate much further.
>
> Not to derail the conversation, but we do actually see a problem
> with commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and
> refill"). Program that passed without it now gets:
>
>   R0=inv(id=0) R1_w=invP0 R2_w=invP0 R5_w=inv0 R6=ctx(id=0,off=0,imm=0)
> R7=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R8=inv(id=0)
> R9_w=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R10=fp0 fp-8=mmmm????
> fp-16=mmmmmmmm fp-24=00000000 fp-32=inv fp-40=00000000 fp-48=inv
> fp-56=mmmmmmmm fp-64=mmmmmmmm
> 479: (79) r1 = *(u64 *)(r10 -32)
> corrupted spill memory
> processed 970 insns (limit 1000000) max_states_per_insn 2 total_states 73
> peak_states 73 mark_read 24

Stan,
please read the 2nd part of my sentence above and try again with that patch.

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-05  1:20     ` Alexei Starovoitov
@ 2021-11-05  4:13       ` Stanislav Fomichev
  0 siblings, 0 replies; 19+ messages in thread
From: Stanislav Fomichev @ 2021-11-05  4:13 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Lorenz Bauer, Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann, Martin KaFai Lau

On Thu, Nov 4, 2021 at 6:20 PM Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Thu, Nov 4, 2021 at 4:30 PM <sdf@google.com> wrote:
> >
> > On 11/04, Alexei Starovoitov wrote:
> > > On Wed, Nov 3, 2021 at 4:55 AM Lorenz Bauer <lmb@cloudflare.com> wrote:
> >
> > > > #pragma clang loop unroll(full)
> > > >     for (int b = 1 << 10; b >= 4; b >>= 1) {
> > > >         if (start + b > end) {
> > > >             continue;
> > > >         }
> > > >
> > > >         // If we do 8 byte reads, we have to handle overflows which is
> > > > slower than 4 byte reads.
> > > >         for (int i = 0; i < b; i += 4) {
> > > >             csum += *(uint32_t *)(start + i);
> > > >         }
> > > >
> > > >         start += b;
> > > >     }
> > > >     if (start + 2 <= end) {
> > > >         csum += *(uint16_t *)(start);
> > > >         start += 2;
> > > >     }
> > > >     if (start + 1 <= end) {
> > > >         csum += *(start);
> > > >     }
> >
> > > Thanks for flagging!
> > > Could you craft a test case that we can use a repro and future
> > > test case?
> >
> > > > fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
> > > ...
> > > > I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
> > > > pointer mismatch in bpf_timer_init.") The commit seems unrelated to
> > > > loop processing though (it does touch the verifier however). Either I
> > > > got the bisection wrong or there is something subtle going on.
> >
> > > I stared at that commit and the example asm.
> > > I suspect the bisect went wrong.
> >
> > > Could you try reverting a single
> > > commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill")
> > > ?
> > > The above fp-112=inv means that the verifier is tracking scalar spill.
> > > That could be the reason for bounded loop logic seeing different
> > > stack state on every iteration.
> > > But the asm snippet doesn't have the store to stack at [fp-112]
> > > location, so it could be a red herring.
> >
> > > Are you using the same llvm during bisect?
> > > The commit 354e8f1970f8 should be harmless
> > > (when commit f30d4968e9ae ("bpf: Do not reject when the stack read
> > > size is different from the tracked scalar size"))
> > > is also applied. That fix is in bpf tree only, so far.
> > > The tracking of 8-byte spill is the most useful with the latest llvm
> > > that was taught to use 8-byte aligned stack for such spills.
> >
> > > Without being able to repro it's hard to investigate much further.
> >
> > Not to derail the conversation, but we do actually see a problem
> > with commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and
> > refill"). Program that passed without it now gets:
> >
> >   R0=inv(id=0) R1_w=invP0 R2_w=invP0 R5_w=inv0 R6=ctx(id=0,off=0,imm=0)
> > R7=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R8=inv(id=0)
> > R9_w=map_value(id=0,off=0,ks=4,vs=9616,imm=0) R10=fp0 fp-8=mmmm????
> > fp-16=mmmmmmmm fp-24=00000000 fp-32=inv fp-40=00000000 fp-48=inv
> > fp-56=mmmmmmmm fp-64=mmmmmmmm
> > 479: (79) r1 = *(u64 *)(r10 -32)
> > corrupted spill memory
> > processed 970 insns (limit 1000000) max_states_per_insn 2 total_states 73
> > peak_states 73 mark_read 24
>
> Stan,
> please read the 2nd part of my sentence above and try again with that patch.

Ah, sorry, I've missed that part. It does indeed fix it for me, thank you!

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-04 16:50 ` Alexei Starovoitov
  2021-11-04 23:30   ` sdf
@ 2021-11-05 10:41   ` Lorenz Bauer
  2021-11-05 19:49     ` Alexei Starovoitov
  1 sibling, 1 reply; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-05 10:41 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Thu, 4 Nov 2021 at 16:51, Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> Thanks for flagging!
> Could you craft a test case that we can use a repro and future
> test case?

Yes, I'll give it a shot.

> > fp-88=map_value fp-96=mmmmmmmm fp-104=map_value fp-112=inv fp-120=fp
> ...
> > I've bisected the problem to commit 3e8ce29850f1 ("bpf: Prevent
> > pointer mismatch in bpf_timer_init.") The commit seems unrelated to
> > loop processing though (it does touch the verifier however). Either I
> > got the bisection wrong or there is something subtle going on.
>
> I stared at that commit and the example asm.
> I suspect the bisect went wrong.

I tried the parent of the offending commit, and it worked fine. Weird.
Could the problem be that there are multiple regressions? See below,
we also get hit with the corrupted stack spill.

> Could you try reverting a single
> commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill")
> ?
> The above fp-112=inv means that the verifier is tracking scalar spill.
> That could be the reason for bounded loop logic seeing different
> stack state on every iteration.
> But the asm snippet doesn't have the store to stack at [fp-112]
> location, so it could be a red herring.
>
> Are you using the same llvm during bisect?

I'm compiling the test case once and then invoke it via git bisect
run, so the BPF should be identical. clang-11.

> The commit 354e8f1970f8 should be harmless
> (when commit f30d4968e9ae ("bpf: Do not reject when the stack read
> size is different from the tracked scalar size"))
> is also applied. That fix is in bpf tree only, so far.

I did some more tests. TL;DR: commit 3e8ce29850f1 ("bpf: Prevent
pointer mismatch in bpf_timer_init.") is the first one that fails with
"BPF program too large", it's ancestor loads OK. commit 354e8f1970f8
("bpf: Support <8-byte scalar spill and refill") makes verification
fail earlier with "corrupted spill memory". The following solves both
issues:

    git checkout 354e8f1970f8 # "bpf: Support <8-byte scalar spill and refill"
    git cherry-pick f30d4968e9ae # "bpf: Do not reject when the stack
read size is different from the tracked scalar size"

I think you're on the money wrt scalar spill tracking. Maybe I
misattributed the problem to the wrong bit of code, instead of having
found the wrong commit?

Details:

bpf-next: commit be2f2d1680df ("libbpf: Deprecate bpf_program__load() API"):

    ; v = *pos++;
    1099: (79) r1 = *(u64 *)(r10 -72)
    corrupted spill memory
    processed 48649 insns (limit 1000000) max_states_per_insn 4
total_states 1305 peak_states 290 mark_read 53

bpf-next with f30d4968e9ae on top:

    works!

bpf-next with commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill
and refill") reverted:

    2225: (05) goto pc+13
    BPF program is too large. Processed 1000001 insn
    processed 1000001 insns (limit 1000000) max_states_per_insn 28
total_states 40641 peak_states 1104 mark_read 53

commit 3e8ce29850f1 ("bpf: Prevent pointer mismatch in
bpf_timer_init.") (found via bisection):

    BPF program is too large. Processed 1000001 insn

commit 3e8ce29850f1^ ("bpf: Add map side support for bpf timers."):

   works!

commit 3e8ce29850f1 with commit 354e8f1970f8 ("bpf: Support <8-byte
scalar spill and refill") reverted:

   doesn't revert cleanly

commit 354e8f1970f8 ("bpf: Support <8-byte scalar spill and refill"):

    corrupted spill memory

commit 354e8f1970f8^ ("bpf: Check the other end of slot_type for STACK_SPILL"):

    2225: (05) goto pc+13
    BPF program is too large. Processed 1000001 insn
    processed 1000001 insns (limit 1000000) max_states_per_insn 28
total_states 40641 peak_states 1104 mark_read 53

commit 354e8f1970f8~2 ("selftests/bpf: Fix btf_dump __int128 test
failure with clang build kernel"):

    same as above

-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-05 10:41   ` Lorenz Bauer
@ 2021-11-05 19:49     ` Alexei Starovoitov
  2021-11-08 13:21       ` Lorenz Bauer
  0 siblings, 1 reply; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-05 19:49 UTC (permalink / raw)
  To: Lorenz Bauer
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Fri, Nov 05, 2021 at 10:41:40AM +0000, Lorenz Bauer wrote:
> 
> bpf-next with f30d4968e9ae on top:
> 
>     works!

Awesome.

> commit 3e8ce29850f1 ("bpf: Prevent pointer mismatch in
> bpf_timer_init.") (found via bisection):
> 
>     BPF program is too large. Processed 1000001 insn
> 
> commit 3e8ce29850f1^ ("bpf: Add map side support for bpf timers."):
> 
>    works!

So with just 3e8ce29850f1 it's "too large" and with parent commit it works ?
I've analyzed offending commit again and don't see how it can be causing
state pruning to be more conservative for your asm.
reg->map_uid should only be non-zero for lookups from inner maps,
but your asm doesn't have lookups at all in that loop.
Maybe in some case map_uid doesn't get cleared, but I couldn't find
such code path with manual code analysis.
I think it's worth investigating further.
Please craft a reproducer.

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-05 19:49     ` Alexei Starovoitov
@ 2021-11-08 13:21       ` Lorenz Bauer
  2021-11-10  4:25         ` Alexei Starovoitov
  0 siblings, 1 reply; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-08 13:21 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Fri, 5 Nov 2021 at 19:49, Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Fri, Nov 05, 2021 at 10:41:40AM +0000, Lorenz Bauer wrote:
> >
> > bpf-next with f30d4968e9ae on top:
> >
> >     works!
>
> Awesome.
>
> > commit 3e8ce29850f1 ("bpf: Prevent pointer mismatch in
> > bpf_timer_init.") (found via bisection):
> >
> >     BPF program is too large. Processed 1000001 insn
> >
> > commit 3e8ce29850f1^ ("bpf: Add map side support for bpf timers."):
> >
> >    works!
>
> So with just 3e8ce29850f1 it's "too large" and with parent commit it works ?
> I've analyzed offending commit again and don't see how it can be causing
> state pruning to be more conservative for your asm.
> reg->map_uid should only be non-zero for lookups from inner maps,
> but your asm doesn't have lookups at all in that loop.

I misattributed the problem to the loop, since it was really prominent
in the verifier output. We use nested maps extensively, most likely
those are what's causing the problem.

> Maybe in some case map_uid doesn't get cleared, but I couldn't find
> such code path with manual code analysis.
> I think it's worth investigating further.
> Please craft a reproducer.

I've started with some verifier log analysis to narrow the problem down.

* Same test case as before
* Dump verifier output with log_level=2 for both 3e8ce29850f1 and 3e8ce29850f1^
* Use diff to find the first non-matching line

3e8ce29850f1 makes the verifier do a lot more work on our code. Some
later commit then drops the complexity below what the verifier will
accept, probably the more precise scalar spill tracking.

3e8ce29850f1^:                  295498 insns
3e8ce29850f1:                > 1000000 insns
be2f2d1680df + bd479d103883:    450161 insns

Trace from 3e8ce29850f1^ (working):

1033: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
fp-128=map_value
1033: (16) if w1 == 0x0 goto pc+43
1077: safe
1178: R0=inv0 R1=map_ptr(id=0,off=0,ks=4,vs=4,imm=0) R2_w=inv0
R3=inv2388976653695081527 R4=inv-8645972361240307355 R5=inv(id=6898)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1178: (63) *(u32 *)(r10 -32) = r7
<...>
processed 295498 insns (limit 1000000) max_states_per_insn 29
total_states 14527 peak_states 1322 mark_read 53

Trace from 3e8ce29850f1 (broken):

1033: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
fp-128=map_value
1033: (16) if w1 == 0x0 goto pc+43
1077: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
fp-128=map_value
1077: (79) r2 = *(u64 *)(r10 -128)
1078: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
R2_w=map_value(id=0,off=0,ks=4,vs=32,imm=0)
R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
fp-128=map_value
1078: (79) r1 = *(u64 *)(r2 +0)
<...>
(truncated)

Trace from be2f2d1680df ("libbpf: Deprecate bpf_program__load() API")
with bd479d103883 ("bpf: Do not reject when the stack read size is
different from the tracked scalar size") cherry picked:

processed 450161 insns (limit 1000000) max_states_per_insn 19
total_states 19452 peak_states 1319 mark_read 53

r2 is the result of a lookup from a per-CPU array, ts_metrics in the
snippet below:

struct bpf_map_def traffic_set_metrics_map __section("maps") = {
    .type        = BPF_MAP_TYPE_PERCPU_ARRAY,
    .key_size    = sizeof(traffic_set_id_t),
    .value_size  = sizeof(traffic_set_metrics_t),
    .max_entries = SET_BY_USERSPACE,
};

    traffic_set_metrics_t *ts_metrics =
bpf_map_lookup_elem(&traffic_set_metrics_map, &meta->ts_id);
    if (ts_metrics == NULL) {
        return XDP_ABORTED;
    }

   <...>

   if (meta->from_plurimog) {
        ts_metrics->packets_total_plurimog_ingress++;
    } else {
        ts_metrics->packets_total_main++; // insn 1078
    }

Lorenz

-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-08 13:21       ` Lorenz Bauer
@ 2021-11-10  4:25         ` Alexei Starovoitov
  2021-11-10 11:41           ` Lorenz Bauer
  0 siblings, 1 reply; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-10  4:25 UTC (permalink / raw)
  To: Lorenz Bauer
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Mon, Nov 08, 2021 at 01:21:12PM +0000, Lorenz Bauer wrote:
> On Fri, 5 Nov 2021 at 19:49, Alexei Starovoitov
> <alexei.starovoitov@gmail.com> wrote:
> >
> > On Fri, Nov 05, 2021 at 10:41:40AM +0000, Lorenz Bauer wrote:
> > >
> > > bpf-next with f30d4968e9ae on top:
> > >
> > >     works!
> >
> > Awesome.
> >
> > > commit 3e8ce29850f1 ("bpf: Prevent pointer mismatch in
> > > bpf_timer_init.") (found via bisection):
> > >
> > >     BPF program is too large. Processed 1000001 insn
> > >
> > > commit 3e8ce29850f1^ ("bpf: Add map side support for bpf timers."):
> > >
> > >    works!
> >
> > So with just 3e8ce29850f1 it's "too large" and with parent commit it works ?
> > I've analyzed offending commit again and don't see how it can be causing
> > state pruning to be more conservative for your asm.
> > reg->map_uid should only be non-zero for lookups from inner maps,
> > but your asm doesn't have lookups at all in that loop.
> 
> I misattributed the problem to the loop, since it was really prominent
> in the verifier output. We use nested maps extensively, most likely
> those are what's causing the problem.
> 
> > Maybe in some case map_uid doesn't get cleared, but I couldn't find
> > such code path with manual code analysis.
> > I think it's worth investigating further.
> > Please craft a reproducer.
> 
> I've started with some verifier log analysis to narrow the problem down.
> 
> * Same test case as before
> * Dump verifier output with log_level=2 for both 3e8ce29850f1 and 3e8ce29850f1^
> * Use diff to find the first non-matching line
> 
> 3e8ce29850f1 makes the verifier do a lot more work on our code. Some
> later commit then drops the complexity below what the verifier will
> accept, probably the more precise scalar spill tracking.
> 
> 3e8ce29850f1^:                  295498 insns
> 3e8ce29850f1:                > 1000000 insns
> be2f2d1680df + bd479d103883:    450161 insns
> 
> Trace from 3e8ce29850f1^ (working):
> 
> 1033: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
> R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
> R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
> fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
> fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
> fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
> fp-128=map_value
> 1033: (16) if w1 == 0x0 goto pc+43
> 1077: safe
> 1178: R0=inv0 R1=map_ptr(id=0,off=0,ks=4,vs=4,imm=0) R2_w=inv0
> R3=inv2388976653695081527 R4=inv-8645972361240307355 R5=inv(id=6898)
> R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
> R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
> fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
> fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
> fp-112=pkt fp-120=fp fp-128=map_value
> 1178: (63) *(u32 *)(r10 -32) = r7
> <...>
> processed 295498 insns (limit 1000000) max_states_per_insn 29
> total_states 14527 peak_states 1322 mark_read 53
> 
> Trace from 3e8ce29850f1 (broken):
> 
> 1033: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
> R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
> R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
> fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
> fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
> fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
> fp-128=map_value
> 1033: (16) if w1 == 0x0 goto pc+43
> 1077: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
> R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
> R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
> fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
> fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
> fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
> fp-128=map_value
> 1077: (79) r2 = *(u64 *)(r10 -128)

R2 loads a spilled map_value.

> 1078: R0=map_value(id=0,off=0,ks=4,vs=36,imm=0) R1_w=invP0
> R2_w=map_value(id=0,off=0,ks=4,vs=32,imm=0)
> R3_w=map_value(id=0,off=0,ks=4,vs=36,imm=0) R6=ctx(id=0,off=0,imm=0)
> R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0
> fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000
> fp-56=00000000 fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm
> fp-88=map_value fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp
> fp-128=map_value
> 1078: (79) r1 = *(u64 *)(r2 +0)
> <...>
> (truncated)
> 
> Trace from be2f2d1680df ("libbpf: Deprecate bpf_program__load() API")
> with bd479d103883 ("bpf: Do not reject when the stack read size is
> different from the tracked scalar size") cherry picked:
> 
> processed 450161 insns (limit 1000000) max_states_per_insn 19
> total_states 19452 peak_states 1319 mark_read 53
> 
> r2 is the result of a lookup from a per-CPU array, ts_metrics in the
> snippet below:
> 
> struct bpf_map_def traffic_set_metrics_map __section("maps") = {
>     .type        = BPF_MAP_TYPE_PERCPU_ARRAY,
>     .key_size    = sizeof(traffic_set_id_t),
>     .value_size  = sizeof(traffic_set_metrics_t),
>     .max_entries = SET_BY_USERSPACE,
> };
> 
>     traffic_set_metrics_t *ts_metrics =
> bpf_map_lookup_elem(&traffic_set_metrics_map, &meta->ts_id);
>     if (ts_metrics == NULL) {
>         return XDP_ABORTED;
>     }
> 
>    <...>
> 
>    if (meta->from_plurimog) {
>         ts_metrics->packets_total_plurimog_ingress++;
>     } else {
>         ts_metrics->packets_total_main++; // insn 1078
>     }

but it goes into R2 from non-inner map which ruins all my theories.

I've tried to craft a test case based on a theory and so far couldn't do so.
Could you please try the following hack:
diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index 1aafb43f61d1..89b8f79b7236 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -665,9 +665,10 @@ static void print_verifier_state(struct bpf_verifier_env *env,
                                 t == PTR_TO_MAP_KEY ||
                                 t == PTR_TO_MAP_VALUE ||
                                 t == PTR_TO_MAP_VALUE_OR_NULL)
-                               verbose(env, ",ks=%d,vs=%d",
+                               verbose(env, ",ks=%d,vs=%d,uid=%d",
                                        reg->map_ptr->key_size,
-                                       reg->map_ptr->value_size);
+                                       reg->map_ptr->value_size,
+                                       reg->map_uid);
                        if (tnum_is_const(reg->var_off)) {
                                /* Typically an immediate SCALAR_VALUE, but
                                 * could be a pointer whose offset is too big
@@ -10509,8 +10510,11 @@ static bool regsafe(struct bpf_verifier_env *env, struct bpf_reg_state *rold,
                 */
                if (rcur->type != PTR_TO_MAP_VALUE_OR_NULL)
                        return false;
-               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, id)))
+               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, map_uid)))
                        return false;
+               if (rcur->map_uid)
+                       if (!check_ids(rold->map_uid, rcur->map_uid, idmap))
+                               return false;
                /* Check our ids match any regs they're supposed to */
                return check_ids(rold->id, rcur->id, idmap);
        case PTR_TO_PACKET_META:


The verbose() part will help to confirm that R2 in the above should be uid=0.

After that please try only with:
-               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, id)))
+               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, map_uid)))

It should resolve the regression, but will break timer safety check and makes
the map_uid logic not quite right (though no existing test will show it).
Hence the check_ids() part in the hunk above that should make map_uid correct again
and hopefully not repeat the infinite loop you're seeing.

Without a reproducer it's all wild guesses.

If offsetof(map_uid) doesn't help another guess would be:
@@ -10496,7 +10497,7 @@ static bool regsafe(struct bpf_verifier_env *env, struct bpf_reg_state *rold,
                 * it's valid for all map elements regardless of the key
                 * used in bpf_map_lookup()
                 */
-               return memcmp(rold, rcur, offsetof(struct bpf_reg_state, id)) == 0 &&
+               return memcmp(rold, rcur, offsetof(struct bpf_reg_state, map_uid)) == 0 &&
                       range_within(rold, rcur) &&
                       tnum_in(rold->var_off, rcur->var_off);
that's for PTR_TO_MAP_VALUE and that would be a different theory which makes even less sense.

If neither help the reproducer would be must have to make further progress.

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10  4:25         ` Alexei Starovoitov
@ 2021-11-10 11:41           ` Lorenz Bauer
  2021-11-10 16:50             ` Alexei Starovoitov
  0 siblings, 1 reply; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-10 11:41 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Wed, 10 Nov 2021 at 04:25, Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> but it goes into R2 from non-inner map which ruins all my theories.

The trace does contain modifications from inner maps, but they aren't
at the start of the block at 1077. Your suggested hack makes this
clear:

1033: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1033: (16) if w1 == 0x0 goto pc+43
1077: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1077: (79) r2 = *(u64 *)(r10 -128)
1078: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0) R1_w=invP0
R2_w=map_value(id=0,off=0,ks=4,vs=32,uid=0,imm=0)
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value

r2 is the per-CPU array. r0, r3 are from an inner map. There are
accesses to r3 a couple instructions later:

1081: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R1_w=inv(id=0) R2_w=map_value(id=0,off=0,ks=4,vs=32,uid=0,imm=0)
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1081: (71) r1 = *(u8 *)(r3 +32)
 R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0) R1_w=inv(id=0)
R2_w=map_value(id=0,off=0,ks=4,vs=32,uid=0,imm=0)
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value

> The verbose() part will help to confirm that R2 in the above should be uid=0.

Yes, uid=0, see above.

> After that please try only with:
> -               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, id)))
> +               if (memcmp(rold, rcur, offsetof(struct bpf_reg_state, map_uid)))
>
> It should resolve the regression, but will break timer safety check and makes
> the map_uid logic not quite right (though no existing test will show it).

This doesn't help.

>
> If offsetof(map_uid) doesn't help another guess would be:
> @@ -10496,7 +10497,7 @@ static bool regsafe(struct bpf_verifier_env *env, struct bpf_reg_state *rold,
>                  * it's valid for all map elements regardless of the key
>                  * used in bpf_map_lookup()
>                  */
> -               return memcmp(rold, rcur, offsetof(struct bpf_reg_state, id)) == 0 &&
> +               return memcmp(rold, rcur, offsetof(struct bpf_reg_state, map_uid)) == 0 &&
>                        range_within(rold, rcur) &&
>                        tnum_in(rold->var_off, rcur->var_off);
> that's for PTR_TO_MAP_VALUE and that would be a different theory which makes even less sense.

This change resolves the regression. The first five occurrences of
insn 1077 in the trace, with your logging applied:

1077: R0=map_value(id=0,off=0,ks=4,vs=36,uid=13,imm=0) R1=invP0
R3=map_value(id=0,off=0,ks=4,vs=36,uid=13,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=00000000 fp-32=0000mmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1077: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6875,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6875,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=00000000 fp-32=0000mmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1077: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6900,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1077: R0=map_value(id=0,off=0,ks=4,vs=36,uid=6908,imm=0) R1_w=invP0
R3_w=map_value(id=0,off=0,ks=4,vs=36,uid=6908,imm=0)
R6=ctx(id=0,off=0,imm=0) R7=inv(id=0) R8=pkt(id=0,off=18,r=38,imm=0)
R9=inv0 R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmm00m0
fp-48=mmmm0000 fp-56=00000000 fp-64=00000000 fp-72=0000mmmm
fp-80=mmmmmmmm fp-88=map_value fp-96=pkt_end fp-104=map_value
fp-112=pkt fp-120=fp fp-128=map_value
1077: R0=map_value(id=0,off=0,ks=16,vs=36,uid=0,imm=0) R1=invP0
R2=map_value(id=0,off=0,ks=4,vs=368,uid=0,imm=0)
R3=map_value(id=0,off=0,ks=16,vs=36,uid=0,imm=0)
R6=ctx(id=0,off=0,imm=0)
R7=map_value(id=0,off=0,ks=4,vs=368,uid=0,imm=0)
R8=pkt(id=0,off=18,r=38,imm=0) R9=inv0 R10=fp0 fp-24=mmmmmmmm
fp-32=mmmmmmmm fp-40=mmmm00m0 fp-48=mmmm0000 fp-56=00000000
fp-64=00000000 fp-72=0000mmmm fp-80=mmmmmmmm fp-88=map_value
fp-96=pkt_end fp-104=map_value fp-112=pkt fp-120=fp fp-128=map_value

uid changes on every invocation, and therefore regsafe() returns false?

-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 11:41           ` Lorenz Bauer
@ 2021-11-10 16:50             ` Alexei Starovoitov
  2021-11-10 17:05               ` Lorenz Bauer
  2021-11-10 18:01               ` Thorsten Leemhuis
  0 siblings, 2 replies; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-10 16:50 UTC (permalink / raw)
  To: Lorenz Bauer
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Wed, Nov 10, 2021 at 11:41:09AM +0000, Lorenz Bauer wrote:
> 
> uid changes on every invocation, and therefore regsafe() returns false?

That's correct.
Could you please try the following fix.
I think it's less risky and more accurate than what I've tried before.

From be7736582945b56e88d385ddd4a05e13e4bc6784 Mon Sep 17 00:00:00 2001
From: Alexei Starovoitov <ast@kernel.org>
Date: Wed, 10 Nov 2021 08:47:52 -0800
Subject: [PATCH] bpf: Fix inner map state pruning regression.

Fixes: 3e8ce29850f1 ("bpf: Prevent pointer mismatch in bpf_timer_init.")
Signed-off-by: Alexei Starovoitov <ast@kernel.org>
---
 kernel/bpf/verifier.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/kernel/bpf/verifier.c b/kernel/bpf/verifier.c
index 1aafb43f61d1..3eddcd8ebae2 100644
--- a/kernel/bpf/verifier.c
+++ b/kernel/bpf/verifier.c
@@ -1157,7 +1157,8 @@ static void mark_ptr_not_null_reg(struct bpf_reg_state *reg)
                        /* transfer reg's id which is unique for every map_lookup_elem
                         * as UID of the inner map.
                         */
-                       reg->map_uid = reg->id;
+                       if (map_value_has_timer(map->inner_map_meta))
+                               reg->map_uid = reg->id;
                } else if (map->map_type == BPF_MAP_TYPE_XSKMAP) {
                        reg->type = PTR_TO_XDP_SOCK;
                } else if (map->map_type == BPF_MAP_TYPE_SOCKMAP ||
--
2.30.2


^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 16:50             ` Alexei Starovoitov
@ 2021-11-10 17:05               ` Lorenz Bauer
  2021-11-10 18:01               ` Thorsten Leemhuis
  1 sibling, 0 replies; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-10 17:05 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Wed, 10 Nov 2021 at 16:50, Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> On Wed, Nov 10, 2021 at 11:41:09AM +0000, Lorenz Bauer wrote:
> >
> > uid changes on every invocation, and therefore regsafe() returns false?
>
> That's correct.
> Could you please try the following fix.
> I think it's less risky and more accurate than what I've tried before.

It works!

processed 295498 insns (limit 1000000) max_states_per_insn 29
total_states 14527 peak_states 1322 mark_read 53

Thanks for looking into this without a reproducer!

Lorenz


-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 16:50             ` Alexei Starovoitov
  2021-11-10 17:05               ` Lorenz Bauer
@ 2021-11-10 18:01               ` Thorsten Leemhuis
  2021-11-10 19:16                 ` Alexei Starovoitov
  1 sibling, 1 reply; 19+ messages in thread
From: Thorsten Leemhuis @ 2021-11-10 18:01 UTC (permalink / raw)
  To: Alexei Starovoitov, Lorenz Bauer
  Cc: Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann



On 10.11.21 17:50, Alexei Starovoitov wrote:
> On Wed, Nov 10, 2021 at 11:41:09AM +0000, Lorenz Bauer wrote:
>>
>> uid changes on every invocation, and therefore regsafe() returns false?
> 
> That's correct.
> Could you please try the following fix.
> I think it's less risky and more accurate than what I've tried before.
> 
>>From be7736582945b56e88d385ddd4a05e13e4bc6784 Mon Sep 17 00:00:00 2001
> From: Alexei Starovoitov <ast@kernel.org>
> Date: Wed, 10 Nov 2021 08:47:52 -0800
> Subject: [PATCH] bpf: Fix inner map state pruning regression.
> 
> Fixes: 3e8ce29850f1 ("bpf: Prevent pointer mismatch in bpf_timer_init.")
> Signed-off-by: Alexei Starovoitov <ast@kernel.org>

Thanks for working on a fix for this regression. There is one small
detail that afaics could be improved (maybe you left that for later, if
that's the case please simply stop reading and ignore this mail):

The commit message would benefit from a link to the regression report.
This is explained in Documentation/process/submitting-patches.rst, which
recently was changed slightly to make this aspect clearer:
https://git.kernel.org/linus/1f57bd42b77c

E.g. add something like this

Link:
https://linux-regtracking.leemhuis.info/regzbot/regression/CACAyw99hVEJFoiBH_ZGyy=%2BoO-jyydoz6v1DeKPKs2HVsUH28w@mail.gmail.com/

Thanks in advance.

FWIW, in case anyone wonders why I'm asking for this: yes, that link is
not really crucial; but it's good to have if someone needs to look into
the backstory of this change sometime in the future. But I care for a
different reason. I'm tracking this regression (and others) with
regzbot, my relative new Linux kernel regression tracking bot. The entry
for this regression can be found at:
https://linux-regtracking.leemhuis.info/regzbot/regression/CACAyw99hVEJFoiBH_ZGyy=%2BoO-jyydoz6v1DeKPKs2HVsUH28w@mail.gmail.com/

This bot will notice if a patch with a Link: tag to a tracked regression
gets posted. It will record that and show a link in the web-interface,
which allows anyone looking into a regression to quickly gasp the
current status. The bot will also notice if a commit with a Link: tag to
a regression report is applied by Linus and then automatically mark the
regression as resolved then.

IOW: this tag makes my life easier, as I otherwise have to tell regzbot
manually about each and every fix for a regression manually. ;-)

Ciao, your Linux kernel regression tracker (Thorsten)

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 18:01               ` Thorsten Leemhuis
@ 2021-11-10 19:16                 ` Alexei Starovoitov
  2021-11-10 19:49                   ` Thorsten Leemhuis
  0 siblings, 1 reply; 19+ messages in thread
From: Alexei Starovoitov @ 2021-11-10 19:16 UTC (permalink / raw)
  To: Thorsten Leemhuis
  Cc: Lorenz Bauer, Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On Wed, Nov 10, 2021 at 10:01 AM Thorsten Leemhuis
<regressions@leemhuis.info> wrote:
>
>
>
> On 10.11.21 17:50, Alexei Starovoitov wrote:
> > On Wed, Nov 10, 2021 at 11:41:09AM +0000, Lorenz Bauer wrote:
> >>
> >> uid changes on every invocation, and therefore regsafe() returns false?
> >
> > That's correct.
> > Could you please try the following fix.
> > I think it's less risky and more accurate than what I've tried before.
> >
> >>From be7736582945b56e88d385ddd4a05e13e4bc6784 Mon Sep 17 00:00:00 2001
> > From: Alexei Starovoitov <ast@kernel.org>
> > Date: Wed, 10 Nov 2021 08:47:52 -0800
> > Subject: [PATCH] bpf: Fix inner map state pruning regression.
> >
> > Fixes: 3e8ce29850f1 ("bpf: Prevent pointer mismatch in bpf_timer_init.")
> > Signed-off-by: Alexei Starovoitov <ast@kernel.org>
>
> Thanks for working on a fix for this regression. There is one small
> detail that afaics could be improved (maybe you left that for later, if
> that's the case please simply stop reading and ignore this mail):
>
> The commit message would benefit from a link to the regression report.
> This is explained in Documentation/process/submitting-patches.rst, which
> recently was changed slightly to make this aspect clearer:
> https://git.kernel.org/linus/1f57bd42b77c

I don't think you're familiar with bpf process of applying patches.
Please take a look at bpf tree.
The 'Link:' exists for every commit.

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 19:16                 ` Alexei Starovoitov
@ 2021-11-10 19:49                   ` Thorsten Leemhuis
  2021-11-11 17:10                     ` Lorenz Bauer
  0 siblings, 1 reply; 19+ messages in thread
From: Thorsten Leemhuis @ 2021-11-10 19:49 UTC (permalink / raw)
  To: Alexei Starovoitov
  Cc: Lorenz Bauer, Alexei Starovoitov, kernel-team, bpf, regressions,
	Andrii Nakryiko, Daniel Borkmann

On 10.11.21 20:16, Alexei Starovoitov wrote:
> On Wed, Nov 10, 2021 at 10:01 AM Thorsten Leemhuis
> <regressions@leemhuis.info> wrote:
>> On 10.11.21 17:50, Alexei Starovoitov wrote:
>>> On Wed, Nov 10, 2021 at 11:41:09AM +0000, Lorenz Bauer wrote:
>>>>
>>>> uid changes on every invocation, and therefore regsafe() returns false?
>>>
>>> That's correct.
>>> Could you please try the following fix.
>>> I think it's less risky and more accurate than what I've tried before.
>>>
>>> >From be7736582945b56e88d385ddd4a05e13e4bc6784 Mon Sep 17 00:00:00 2001
>>> From: Alexei Starovoitov <ast@kernel.org>
>>> Date: Wed, 10 Nov 2021 08:47:52 -0800
>>> Subject: [PATCH] bpf: Fix inner map state pruning regression.
>>>
>>> Fixes: 3e8ce29850f1 ("bpf: Prevent pointer mismatch in bpf_timer_init.")
>>> Signed-off-by: Alexei Starovoitov <ast@kernel.org>
>>
>> Thanks for working on a fix for this regression. There is one small
>> detail that afaics could be improved (maybe you left that for later, if
>> that's the case please simply stop reading and ignore this mail):
>>
>> The commit message would benefit from a link to the regression report.
>> This is explained in Documentation/process/submitting-patches.rst, which
>> recently was changed slightly to make this aspect clearer:
>> https://git.kernel.org/linus/1f57bd42b77c
> 
> I don't think you're familiar with bpf process of applying patches.

That's totally correct, but why should someone working as a regression
tracker for all of the Linux kernel has to know the exact inner workings
of all the various subsystems?

> Please take a look at bpf tree. The 'Link:' exists for every commit.

One of us is missing something. I might be wrong, but you afaics mean
that every commit has a 'Link:' to the latest review posting added when
a patch is committed. Many thx for that, I really like that, as it made
my life easier a few times in the past already.

But that was not what I was asking got. I was asking for a 'Link:' to
the *regression report*. To quote myself again from above:

>> The commit message would benefit from a link to the regression report.
>> [...] https://git.kernel.org/linus/1f57bd42b77c

To quote from there:
```
In case your patch fixes a bug, for example, add a tag with a URL
referencing the report in the mailing list archives or a bug tracker
````

Or what am I missing? Ciao, Thorsten

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-10 19:49                   ` Thorsten Leemhuis
@ 2021-11-11 17:10                     ` Lorenz Bauer
  2021-11-11 17:33                       ` Thorsten Leemhuis
  0 siblings, 1 reply; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-11 17:10 UTC (permalink / raw)
  To: Thorsten Leemhuis; +Cc: Alexei Starovoitov, bpf

Hi Thorsten,

On Wed, 10 Nov 2021 at 19:50, Thorsten Leemhuis
<regressions@leemhuis.info> wrote:
>
> >
> > I don't think you're familiar with bpf process of applying patches.
>
> That's totally correct, but why should someone working as a regression
> tracker for all of the Linux kernel has to know the exact inner workings
> of all the various subsystems?

I think I'm responsible for a misunderstanding between you and Alexei,
sorry. I saw your regression tracker mentioned, and wanted to give it
a try. Alexei wasn't aware of this and therefore lacked context when
you replied.

For the purpose of this report I'll send an email to regzbot when the
commit has made its way into the bpf tree. I hope this works for you
and Alexei.

Thanks,
Lorenz

-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-11 17:10                     ` Lorenz Bauer
@ 2021-11-11 17:33                       ` Thorsten Leemhuis
  0 siblings, 0 replies; 19+ messages in thread
From: Thorsten Leemhuis @ 2021-11-11 17:33 UTC (permalink / raw)
  To: Lorenz Bauer; +Cc: Alexei Starovoitov, bpf

On 11.11.21 18:10, Lorenz Bauer wrote:
> On Wed, 10 Nov 2021 at 19:50, Thorsten Leemhuis
> <regressions@leemhuis.info> wrote:
>>
>>>
>>> I don't think you're familiar with bpf process of applying patches.
>>
>> That's totally correct, but why should someone working as a regression
>> tracker for all of the Linux kernel has to know the exact inner workings
>> of all the various subsystems?
> 
> I think I'm responsible for a misunderstanding between you and Alexei,
> sorry. I saw your regression tracker mentioned, and wanted to give it
> a try.

Many thx for that. You were the first person besides me to give it a try
since it ran for real (and everything worked as it was supposed to),
that's why I on twitter already promised to get you a beer or other
beverage of choice should we ever meet on a conference. :-)

> Alexei wasn't aware of this and therefore lacked context when
> you replied.

Well, I think the mail explained it, but I guess it was a bit too long,
complicated, or something like that. Whatever, no worries. :-D

> For the purpose of this report I'll send an email to regzbot when the
> commit has made its way into the bpf tree. I hope this works for you
> and Alexei.

Sure it does, many thx!

Ciao, Thorsten

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-03 11:55 Verifier rejects previously accepted program Lorenz Bauer
  2021-11-04 16:50 ` Alexei Starovoitov
@ 2021-11-16  9:26 ` Lorenz Bauer
  2021-11-16 10:59   ` Thorsten Leemhuis
  1 sibling, 1 reply; 19+ messages in thread
From: Lorenz Bauer @ 2021-11-16  9:26 UTC (permalink / raw)
  To: regressions

On Wed, 3 Nov 2021 at 11:55, Lorenz Bauer <lmb@cloudflare.com> wrote:
>
> Hi Alexei,
>
> I started testing our load balancer on 5.15 today, unfortunately BPF
> which is happy on 5.10 gets rejected on the latest kernel.
>
>     BPF program is too large. Processed 1000001 insn
>     processed 1000001 insns (limit 1000000) max_states_per_insn 28
> total_states 40641 peak_states 1104 mark_read 53

#regzbot fixed-by: 34d11a440c6167133201b7374065b59f259730d7

-- 
Lorenz Bauer  |  Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK

www.cloudflare.com

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: Verifier rejects previously accepted program
  2021-11-16  9:26 ` Lorenz Bauer
@ 2021-11-16 10:59   ` Thorsten Leemhuis
  0 siblings, 0 replies; 19+ messages in thread
From: Thorsten Leemhuis @ 2021-11-16 10:59 UTC (permalink / raw)
  To: Lorenz Bauer, regressions

On 16.11.21 10:26, Lorenz Bauer wrote:
> On Wed, 3 Nov 2021 at 11:55, Lorenz Bauer <lmb@cloudflare.com> wrote:
>>
>> I started testing our load balancer on 5.15 today, unfortunately BPF
>> which is happy on 5.10 gets rejected on the latest kernel.
>>
>>     BPF program is too large. Processed 1000001 insn
>>     processed 1000001 insns (limit 1000000) max_states_per_insn 28
>> total_states 40641 peak_states 1104 mark_read 53
> 
> #regzbot fixed-by: 34d11a440c6167133201b7374065b59f259730d7

Many thx for this, regzbot picked this up and reacted (mostly(¹)) as
expected. But FWIW and for everybody information, turns out it wasn't
actually needed (but didn't do any harm), as Alexei added the link to
the regression report in above commit. Regzbot thus had noticed the
commit already when it turned up in next and marked the regression as
"to be fixed" – and will mark it as fixed, once the commit lands in
mainline.

Thx again, good to see that developer give regzbot a try!

Ciao, Thorsten

(¹) it didn't look up the commit summary in next to get a proper
description for it; not a big deal, but would have been nice to have, so
I will look into that later

^ permalink raw reply	[flat|nested] 19+ messages in thread

end of thread, other threads:[~2021-11-16 10:59 UTC | newest]

Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-11-03 11:55 Verifier rejects previously accepted program Lorenz Bauer
2021-11-04 16:50 ` Alexei Starovoitov
2021-11-04 23:30   ` sdf
2021-11-05  1:20     ` Alexei Starovoitov
2021-11-05  4:13       ` Stanislav Fomichev
2021-11-05 10:41   ` Lorenz Bauer
2021-11-05 19:49     ` Alexei Starovoitov
2021-11-08 13:21       ` Lorenz Bauer
2021-11-10  4:25         ` Alexei Starovoitov
2021-11-10 11:41           ` Lorenz Bauer
2021-11-10 16:50             ` Alexei Starovoitov
2021-11-10 17:05               ` Lorenz Bauer
2021-11-10 18:01               ` Thorsten Leemhuis
2021-11-10 19:16                 ` Alexei Starovoitov
2021-11-10 19:49                   ` Thorsten Leemhuis
2021-11-11 17:10                     ` Lorenz Bauer
2021-11-11 17:33                       ` Thorsten Leemhuis
2021-11-16  9:26 ` Lorenz Bauer
2021-11-16 10:59   ` Thorsten Leemhuis

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.