Re: R1 invalid mem access 'inv'

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




On Thu, 17 Jun 2021, Yonghong Song wrote:

> 
> 
> On 6/17/21 7:19 AM, Vincent Li wrote:
> > 
> > Hi Song,
> > 
> > Thank you for your response!
> > 
> > 
> > On Wed, 16 Jun 2021, Yonghong Song wrote:
> > 
> > > 
> > > 
> > > On 6/16/21 5:05 PM, Vincent Li wrote:
> > > > Hi BPF Experts,
> > > > 
> > > > I had a problem that verifier report "R1 invalid mem access 'inv'" when
> > > > I attempted to rewrite packet destination ethernet MAC address in Cilium
> > > > tunnel mode, I opened an issue
> > > > with detail here https://github.com/cilium/cilium/issues/16571:
> > > > 
> > > > I have couple of questions in general to try to understand the compiler,
> > > > BPF byte code, and the verifier.
> > > > 
> > > > 1 Why the BPF byte code changes so much with my simple C code change
> > > > 
> > > > a: BPF byte code  before C code change:
> > > > 
> > > > 0000000000006068 <LBB12_410>:
> > > >       3085:       bf a2 00 00 00 00 00 00 r2 = r10
> > > > ;       tunnel = map_lookup_elem(&TUNNEL_MAP, key);
> > > >       3086:       07 02 00 00 78 ff ff ff r2 += -136
> > > >       3087:       18 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r1 = 0
> > > > ll
> > > >       3089:       85 00 00 00 01 00 00 00 call 1
> > > > ;       if (!tunnel)
> > > >       3090:       15 00 06 01 00 00 00 00 if r0 == 0 goto +262
> > > > <LBB12_441>
> > > > ;       key.tunnel_id = seclabel;
> > > >       3091:       18 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r2 = 0
> > > > ll
> > > >       3093:       67 02 00 00 20 00 00 00 r2 <<= 32
> > > >       3094:       77 02 00 00 20 00 00 00 r2 >>= 32
> > > >       3095:       b7 01 00 00 06 00 00 00 r1 = 6
> > > >       3096:       15 02 02 00 01 00 00 00 if r2 == 1 goto +2 <LBB12_413>
> > > >       3097:       18 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r1 = 0
> > > > ll
> > > > 
> > > > 00000000000060d8 <LBB12_413>:
> > > > ;       return __encap_and_redirect_with_nodeid(ctx, tunnel->ip4,
> > > > seclabel, monitor);
> > > > 
> > > > 
> > > > b: BPF byte code  after C code change:
> > > > 
> > > > the C code diff change:
> > > > 
> > > > diff --git a/bpf/lib/encap.h b/bpf/lib/encap.h
> > > > index dfd87bd82..19199429d 100644
> > > > --- a/bpf/lib/encap.h
> > > > +++ b/bpf/lib/encap.h
> > > > @@ -187,6 +187,8 @@ encap_and_redirect_lxc(struct __ctx_buff *ctx, __u32
> > > > tunnel_endpoint,
> > > >                          struct endpoint_key *key, __u32 seclabel, __u32
> > > > monitor)
> > > >    {
> > > >           struct endpoint_key *tunnel;
> > > > +#define VTEP_MAC  { .addr = { 0xce, 0x72, 0xa7, 0x03, 0x88, 0x58 } }
> > > > +       union macaddr vtep_mac = VTEP_MAC;
> > > >             if (tunnel_endpoint) {
> > > >    #ifdef ENABLE_IPSEC
> > > > @@ -221,6 +223,8 @@ encap_and_redirect_lxc(struct __ctx_buff *ctx, __u32
> > > > tunnel_endpoint,
> > > >                                                   seclabel);
> > > >           }
> > > >    #endif
> > > > +       if (eth_store_daddr(ctx, (__u8 *) &vtep_mac.addr, 0) < 0)
> > > > +               return DROP_WRITE_ERROR;
> > > >           return __encap_and_redirect_with_nodeid(ctx, tunnel->ip4,
> > > > seclabel, monitor);
> > > >    }
> > > > 
> > > > the result BPF byte code
> > > > 
> > > > 0000000000004468 <LBB3_274>:
> > > >       2189:       bf a2 00 00 00 00 00 00 r2 = r10
> > > > ;       tunnel = map_lookup_elem(&TUNNEL_MAP, key);
> > > >       2190:       07 02 00 00 50 ff ff ff r2 += -176
> > > >       2191:       18 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r1 = 0
> > > > ll
> > > >       2193:       85 00 00 00 01 00 00 00 call 1
> > > >       2194:       bf 07 00 00 00 00 00 00 r7 = r0
> > > >       2195:       79 a6 48 ff 00 00 00 00 r6 = *(u64 *)(r10 - 184)
> > > > ;       if (!tunnel)
> > > >       2196:       55 07 94 00 00 00 00 00 if r7 != 0 goto +148
> > > > <LBB3_289>
> > > > 
> > > > 00000000000044a8 <LBB3_275>:
> > > > ;       __u8 new_ttl, ttl = ip4->ttl;
> > > >       2197:       79 a1 38 ff 00 00 00 00 r1 = *(u64 *)(r10 - 200)
> > > >       2198:       71 13 16 00 00 00 00 00 r3 = *(u8 *)(r1 + 22)
> > > > ;       if (ttl <= 1)
> > > >       2199:       25 03 01 00 01 00 00 00 if r3 > 1 goto +1 <LBB3_277>
> > > >       2200:       05 00 20 ff 00 00 00 00 goto -224 <LBB3_253>
> > > > 
> > > > 
> > > > You can see that:
> > > > 
> > > > before change:  <LBB12_410>
> > > > after change    <LBB3_274>
> > > > 
> > > > is different that <LBB12_410> has instructions 3091, 3092... but
> > > > <LBB3_274> end with instruction 2196
> > > > 
> > > > before change: <LBB12_413> follows <LBB12_410>
> > > > after change: <LBB3_275> follows <LBB3_274>
> > > > 
> > > > <LBB12_413> and <LBB3_275> is very much different
> > > > 
> > > > and  <LBB3_275> instruction 2198 is the one with "R1 invalid mem access
> > > > 'inv'"
> > > > 
> > > > Why <LBB3_275> follows <LBB3_274> ? from C code, <LBB3_275> is not close
> > > > to <LBB3_274>.
> > > 
> > > The cilium code has a lot of functions inlined and after inlining, clang
> > > may
> > > do reordering based on its internal heuristics. It is totally possible
> > > slight
> > > code change may cause generated codes quite different.
> > > 
> > > Regarding to
> > > > and  <LBB3_275> instruction 2198 is the one with "R1 invalid mem access
> > > > 'inv'"
> > > 
> > > 
> > > > 00000000000044a8 <LBB3_275>:
> > > > ;       __u8 new_ttl, ttl = ip4->ttl;
> > > >       2197:       79 a1 38 ff 00 00 00 00 r1 = *(u64 *)(r10 - 200)
> > > >       2198:       71 13 16 00 00 00 00 00 r3 = *(u8 *)(r1 + 22)
> > > > ;       if (ttl <= 1)
> > > >       2199:       25 03 01 00 01 00 00 00 if r3 > 1 goto +1 <LBB3_277>
> > > >       2200:       05 00 20 ff 00 00 00 00 goto -224 <LBB3_253>
> > > 
> > > Looks like "ip4" is spilled on the stack. and maybe the stack save/restore
> > > for
> > > "ip4" does not preserve its original type.
> > > This mostly happens to old kernels, I think.
> > > 
> > 
> > the kernel 4.18 on Centos8, I also custom build most recent mainline git
> > kernel 5.13 on Centos8, I recall I got same invaid memory access
> > 
> > > If you have verifier log, it may help identify issues easily.
> > 
> > Here is the complete verifer log, I skipped the BTF part
> > 
> > level=warning msg="Prog section '2/7' rejected: Permission denied (13)!"
> > subsys=datapath-loader
> > level=warning msg=" - Type:         3" subsys=datapath-loader
> > level=warning msg=" - Attach Type:  0" subsys=datapath-loader
> > level=warning msg=" - Instructions: 2488 (0 over limit)"
> > subsys=datapath-loader
> > level=warning msg=" - License:      GPL" subsys=datapath-loader
> > level=warning subsys=datapath-loader
> > level=warning msg="Verifier analysis:" subsys=datapath-loader
> > level=warning subsys=datapath-loader
> > level=warning msg="Skipped 158566 bytes, use 'verb' option for the full
> > verbose log." subsys=datapath-loader
> > level=warning msg="[...]" subsys=datapath-loader
> > level=warning msg="-136=????00mm fp-144=00000000 fp-152=0000mmmm
> > fp-160=????mmmm fp-168=mmmmmmmm fp-176=mmmmmmmm fp-184=ctx fp-192=mmmmmmmm
> > fp-200=inv fp-208=mmmmmmmm fp-216=inv3 fp-224=mmmmmmmm fp-232=mmmmmmmm
> > fp-240=inv128" subsys=datapath-loader
> > level=warning msg="2437: (0f) r1 += r8" subsys=datapath-loader
> > level=warning msg="2438: (7b) *(u64 *)(r0 +8) = r1" subsys=datapath-loader
> > level=warning msg=" R0_w=map_value(id=0,off=0,ks=8,vs=16,imm=0)
> > R1_w=inv(id=0) R6=ctx(id=0,off=0,imm=0)
> > R7=inv(id=0,umax_value=128,var_off=(0x0; 0xff))
> > R8=inv(id=0,umax_value=128,var_off=(0x0; 0xff)) R9=invP0 R10=fp0
> > fp-8=mmmmmmmm fp-16=????mmmm fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmmmmmm
> > fp-48=mmmmmmmm fp-88=mmmmmmmm fp-96=00000000 fp-104=00000000
> > fp-112=??mmmmmm fp-120=mmmmmmmm fp-128=??mmmmmm fp-136=????00mm
> > fp-144=00000000 fp-152=0000mmmm fp-160=????mmmm fp-168=mmmmmmmm
> > fp-176=mmmmmmmm fp-184=ctx fp-192=mmmmmmmm fp-200=inv fp-208=mmmmmmmm
> > fp-216=inv3 fp-224=mmmmmmmm fp-232=mmmmmmmm fp-240=inv128"
> > subsys=datapath-loader
> > level=warning msg="2439: (05) goto pc+41" subsys=datapath-loader
> > level=warning msg="2481: (18) r2 = 0x5c7" subsys=datapath-loader
> > level=warning msg="2483: (67) r2 <<= 32" subsys=datapath-loader
> > level=warning msg="2484: (77) r2 >>= 32" subsys=datapath-loader
> > level=warning msg="2485: (b7) r1 = 6" subsys=datapath-loader
> > level=warning msg="2486: (15) if r2 == 0x1 goto pc-341"
> > subsys=datapath-loader
> > level=warning msg="last_idx 2486 first_idx 2481" subsys=datapath-loader
> > level=warning msg="regs=4 stack=0 before 2485: (b7) r1 = 6"
> > subsys=datapath-loader
> > level=warning msg="regs=4 stack=0 before 2484: (77) r2 >>= 32"
> > subsys=datapath-loader
> > level=warning msg="regs=4 stack=0 before 2483: (67) r2 <<= 32"
> > subsys=datapath-loader
> > level=warning msg="regs=4 stack=0 before 2481: (18) r2 = 0x5c7"
> > subsys=datapath-loader
> > level=warning msg="2487: (05) goto pc-344" subsys=datapath-loader
> > level=warning msg="2144: (18) r1 = 0x5c7" subsys=datapath-loader
> > level=warning msg="2146: (61) r2 = *(u32 *)(r6 +68)"
> > subsys=datapath-loader
> > level=warning msg="2147: (b7) r3 = 39" subsys=datapath-loader
> > level=warning msg="2148: (63) *(u32 *)(r10 -76) = r3"
> > subsys=datapath-loader
> > level=warning msg="2149: (b7) r3 = 1" subsys=datapath-loader
> > level=warning msg="2150: (6b) *(u16 *)(r10 -90) = r3"
> > subsys=datapath-loader
> > level=warning msg="2151: (63) *(u32 *)(r10 -96) = r8"
> > subsys=datapath-loader
> > level=warning msg="2152: (63) *(u32 *)(r10 -100) = r2"
> > subsys=datapath-loader
> > level=warning msg="2153: (18) r2 = 0x1d3" subsys=datapath-loader
> > level=warning msg="2155: (6b) *(u16 *)(r10 -102) = r2"
> > subsys=datapath-loader
> > level=warning msg="2156: (b7) r2 = 1028" subsys=datapath-loader
> > level=warning msg="2157: (6b) *(u16 *)(r10 -104) = r2"
> > subsys=datapath-loader
> > level=warning msg="2158: (b7) r2 = 0" subsys=datapath-loader
> > level=warning msg="2159: (63) *(u32 *)(r10 -80) = r2"
> > subsys=datapath-loader
> > level=warning msg="last_idx 2159 first_idx 2481" subsys=datapath-loader
> > level=warning msg="regs=4 stack=0 before 2158: (b7) r2 = 0"
> > subsys=datapath-loader
> > level=warning msg="2160: (63) *(u32 *)(r10 -84) = r2"
> > subsys=datapath-loader
> > level=warning msg="2161: (7b) *(u64 *)(r10 -72) = r2"
> > subsys=datapath-loader
> > level=warning msg="2162: (7b) *(u64 *)(r10 -64) = r2"
> > subsys=datapath-loader
> > level=warning msg="2163: (63) *(u32 *)(r10 -88) = r1"
> > subsys=datapath-loader
> > level=warning msg="2164: (6b) *(u16 *)(r10 -92) = r7"
> > subsys=datapath-loader
> > level=warning msg="2165: (67) r7 <<= 32" subsys=datapath-loader
> > level=warning msg="2166: (18) r1 = 0xffffffff" subsys=datapath-loader
> > level=warning msg="2168: (4f) r7 |= r1" subsys=datapath-loader
> > level=warning msg="2169: (bf) r4 = r10" subsys=datapath-loader
> > level=warning msg="2170: (07) r4 += -104" subsys=datapath-loader
> > level=warning msg="2171: (bf) r1 = r6" subsys=datapath-loader
> > level=warning msg="2172: (18) r2 = 0xffffa0c68cae1600"
> > subsys=datapath-loader
> > level=warning msg="2174: (bf) r3 = r7" subsys=datapath-loader
> > level=warning msg="2175: (b7) r5 = 48" subsys=datapath-loader
> > level=warning msg="2176: (85) call bpf_perf_event_output#25"
> > subsys=datapath-loader
> > level=warning msg="last_idx 2176 first_idx 2481" subsys=datapath-loader
> > level=warning msg="regs=20 stack=0 before 2175: (b7) r5 = 48"
> > subsys=datapath-loader
> > level=warning msg="2177: (b7) r1 = 39" subsys=datapath-loader
> > level=warning msg="2178: (b7) r2 = 0" subsys=datapath-loader
> > level=warning msg="2179: (85) call bpf_redirect#23" subsys=datapath-loader
> > level=warning msg="2180: (bf) r9 = r0" subsys=datapath-loader
> > level=warning msg="2181: (bf) r1 = r9" subsys=datapath-loader
> > level=warning msg="2182: (67) r1 <<= 32" subsys=datapath-loader
> > level=warning msg="2183: (77) r1 >>= 32" subsys=datapath-loader
> > level=warning msg="2184: (15) if r1 == 0x0 goto pc+57"
> > subsys=datapath-loader
> > level=warning msg=" R0_w=inv(id=0)
> > R1_w=inv(id=0,umax_value=2147483647,var_off=(0x0; 0x7fffffff))
> > R6=ctx(id=0,off=0,imm=0)
> > R7=inv(id=0,umin_value=4294967295,umax_value=1099511627775,var_off=(0xffffffff;
> > 0xff00000000),s32_min_value=-1,s32_max_value=0,u32_max_value=0)
> > R8=inv(id=0,umax_value=128,var_off=(0x0; 0xff)) R9_w=inv(id=0) R10=fp0
> > fp-8=mmmmmmmm fp-16=????mmmm fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmmmmmm
> > fp-48=mmmmmmmm fp-64=mmmmmmmm fp-72=mmmmmmmm fp-80=mmmmmmmm fp-88=mmmmmmmm
> > fp-96=mmmmmmmm fp-104=mmmmmmmm fp-112=??mmmmmm fp-120=mmmmmmmm
> > fp-128=??mmmmmm fp-136=????00mm fp-144=00000000 fp-152=0000mmmm
> > fp-160=????mmmm fp-168=mmmmmmmm fp-176=mmmmmmmm fp-184=ctx fp-192=mmmmmmmm
> > fp-200=inv fp-208=mmmmmmmm fp-216=inv3 fp-224=mmmmmmmm fp-232=mmmmmmmm
> > fp-240=inv128" subsys=datapath-loader
> > level=warning msg="2185: (18) r2 = 0xffffff60" subsys=datapath-loader
> > level=warning msg="2187: (1d) if r1 == r2 goto pc+9"
> > subsys=datapath-loader
> > level=warning subsys=datapath-loader
> > level=warning msg="from 2187 to 2197: R0=inv(id=0) R1=inv4294967136
> > R2=inv4294967136 R6=ctx(id=0,off=0,imm=0)
> > R7=inv(id=0,umin_value=4294967295,umax_value=1099511627775,var_off=(0xffffffff;
> > 0xff00000000),s32_min_value=-1,s32_max_value=0,u32_max_value=0)
> > R8=inv(id=0,umax_value=128,var_off=(0x0; 0xff)) R9=inv(id=0) R10=fp0
> > fp-8=mmmmmmmm fp-16=????mmmm fp-24=mmmmmmmm fp-32=mmmmmmmm fp-40=mmmmmmmm
> > fp-48=mmmmmmmm fp-64=mmmmmmmm fp-72=mmmmmmmm fp-80=mmmmmmmm fp-88=mmmmmmmm
> > fp-96=mmmmmmmm fp-104=mmmmmmmm fp-112=??mmmmmm fp-120=mmmmmmmm
> > fp-128=??mmmmmm fp-136=????00mm fp-144=00000000 fp-152=0000mmmm
> > fp-160=????mmmm fp-168=mmmmmmmm fp-176=mmmmmmmm fp-184=ctx fp-192=mmmmmmmm
> > fp-200=inv fp-208=mmmmmmmm fp-216=inv3 fp-224=mmmmmmmm fp-232=mmmmmmmm
> 
> This is the problem. Here, we have "fp-200=inv" and
> later on we have
>    r1 = *(u64 *)(r10 -200)  // r1 is a unknown scalar
> 
> We cannot do the following operation
>    r3 = *(u8 *)(r1 +22)
> since r1 is a unknown scalar and the verifier rightfully rejected
> the program.
> 
> You need to examine complete log to find out why fp-200 stores
> an "inv" (a unknown scalar).

I guess you mean the complete log starting from the prog section 2/7 from 
verifier, if so, it seems fp-200 started with "inv"

level=warning msg="Prog section '2/7' rejected: Permission denied (13)!" 
subsys=datapath-loader

level=warning msg="-136=????00mm fp-144=00000000 fp-152=0000mmmm 
fp-160=????mmmm fp-168=mmmmmmmm fp-176=mmmmmmmm fp-184=ctx fp-192=mmmmmmmm 
fp-200=inv fp-208=mmmmmmmm fp-216=inv3 fp-224=mmmmmmmm fp-232=mmmmmmmm 
fp-240=inv128" subsys=datapath-loader

and I don't see fp-200 ever changed to something else after, maybe I am 
reading it wrong

> 
> > fp-240=inv128" subsys=datapath-loader
> > level=warning msg="2197: (79) r1 = *(u64 *)(r10 -200)"
> > subsys=datapath-loader
> > level=warning msg="2198: (71) r3 = *(u8 *)(r1 +22)" subsys=datapath-loader
> > level=warning msg="R1 invalid mem access 'inv'" subsys=datapath-loader
> > level=warning msg="processed 1802 insns (limit 1000000)
> > max_states_per_insn 4 total_states 103 peak_states 103 mark_read 49"
> > subsys=datapath-loader
> > level=warning subsys=datapath-loader
> > level=warning msg="Error filling program arrays!" subsys=datapath-loader
> > level=warning msg="Unable to load program" subsys=datapath-loader
> >   
> > 
> > 
> > > > 
> > > > 
> > > > 2, Can I assume the verifier is to simulate the order of BPF byte
> > > > code execution in run time, like if without any jump or goto in
> > > > <LBB3_274>, <LBB3_275> will be executed after <LBB3_274>?
> > > 
> > > The verifier will try to verify both paths, jumping to LBB3_289
> > > or fall back to LBB3_275.
> > > 
> > > > 
> > > > 
> > > > 
> > > > Enterprise Network Engineer
> > > > F5 Networks Inc
> > > > https://www.youtube.com/c/VincentLi
> > > > 
> > > 
> 



[Index of Archives]     [Linux Samsung SoC]     [Linux Rockchip SoC]     [Linux Actions SoC]     [Linux for Synopsys ARC Processors]     [Linux NFS]     [Linux NILFS]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]


  Powered by Linux