Subject: Re: len = bpf_probe_read_str(); bpf_perf_event_output(... len) == FAIL

From: Arnaldo Carvalho de Melo <[email-masked]>
Date: Tue, 14 Nov 2017 09:58:48 -0300

Em Tue, Nov 14, 2017 at 01:09:39AM +0100, Daniel Borkmann escreveu:
> On 11/13/2017 04:08 PM, Arnaldo Carvalho de Melo wrote:
> > libbpf: -- BEGIN DUMP LOG ---
> > libbpf: 
> > 0: (79) r3 = *(u64 *)(r1 +104)
> > 1: (b7) r2 = 0
> > 2: (bf) r6 = r1
> > 3: (bf) r1 = r10
> > 4: (07) r1 += -128
> > 5: (b7) r2 = 128
> > 6: (85) call bpf_probe_read_str#45
> > 7: (bf) r1 = r0
> > 8: (07) r1 += -1
> > 9: (67) r1 <<= 32
> > 10: (77) r1 >>= 32
> > 11: (25) if r1 > 0x7f goto pc+11
> 
> Right, so the compiler is optimizing the two tests into a single one above,
> which means lower bound cannot properly be derived again by the verifier due
> to this and thus you'll get the error. Similar issue was seen recently [1].
> 
> Does the below hack work for you?
> 
> int prog([...])
> {
>         char filename[128];
>         int ret = bpf_probe_read_str(filename, sizeof(filename), filename_ptr);
>         if (ret > 0)
>                 bpf_perf_event_output(ctx, &__bpf_stdout__, BPF_F_CURRENT_CPU, filename,
>                                       ret & (sizeof(filename) - 1));
>         return 1;
> }
> 
> r0 should keep on tracking bounds here at least:
> 
> prog:
>        0:	bf 16 00 00 00 00 00 00 	r6 = r1
>        1:	bf a1 00 00 00 00 00 00 	r1 = r10
>        2:	07 01 00 00 80 ff ff ff 	r1 += -128
>        3:	b7 02 00 00 80 00 00 00 	r2 = 128
>        4:	85 00 00 00 2d 00 00 00 	call 45
>        5:	67 00 00 00 20 00 00 00 	r0 <<= 32
>        6:	c7 00 00 00 20 00 00 00 	r0 s>>= 32
>        7:	b7 01 00 00 01 00 00 00 	r1 = 1
>        8:	6d 01 0a 00 00 00 00 00 	if r1 s> r0 goto 10
>        9:	57 00 00 00 7f 00 00 00 	r0 &= 127
>       10:	bf a4 00 00 00 00 00 00 	r4 = r10
>       11:	07 04 00 00 80 ff ff ff 	r4 += -128
>       12:	bf 61 00 00 00 00 00 00 	r1 = r6
>       13:	18 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 	r2 = 0ll
>       15:	18 03 00 00 ff ff ff ff 00 00 00 00 00 00 00 00 	r3 = 4294967295ll
>       17:	bf 05 00 00 00 00 00 00 	r5 = r0
>       18:	85 00 00 00 19 00 00 00 	call 25
> 
>   [1] http://patchwork.ozlabs.org/project/netdev/list/?series=13211

Not yet:

6: (85) call bpf_probe_read_str#45
7: (bf) r1 = r0
8: (67) r1 <<= 32
9: (77) r1 >>= 32
10: (15) if r1 == 0x0 goto pc+10
 R0=inv(id=0) R1=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff)) R6=ctx(id=0,off=0,imm=0) R10=fp0
11: (57) r0 &= 127
12: (bf) r4 = r10
13: (07) r4 += -128
14: (bf) r1 = r6
15: (18) r2 = 0xffff92bfc2aba840
17: (18) r3 = 0xffffffff
19: (bf) r5 = r0
20: (85) call bpf_perf_event_output#25
invalid stack type R4 off=-128 access_size=0

I'll try updating clang/llvm...

Full details:

[root@jouet bpf]# cat open.c 
#include "bpf.h"

SEC("prog=do_sys_open filename")
int prog(void *ctx, int err, const char __user *filename_ptr)
{
	char filename[128];
	const unsigned len = bpf_probe_read_str(filename, sizeof(filename), filename_ptr);
	if (len > 0)
       		perf_event_output(ctx, &__bpf_stdout__, BPF_F_CURRENT_CPU, filename,
				  len & (sizeof(filename) - 1));
	return 1;
}
[root@jouet bpf]# perf trace -v -e *open,open.c  usleep 2
bpf: builtin compilation failed: -95, try external compiler
Kernel build dir is set to /lib/modules/4.14.0+/build
set env: KBUILD_DIR=/lib/modules/4.14.0+/build
unset env: KBUILD_OPTS
include option is set to  -nostdinc -isystem /usr/lib/gcc/x86_64-redhat-linux/7/include -I/home/acme/git/linux/arch/x86/include -I./arch/x86/include/generated  -I/home/acme/git/linux/include -I./include -I/home/acme/git/linux/arch/x86/include/uapi -I./arch/x86/include/generated/uapi -I/home/acme/git/linux/include/uapi -I./include/generated/uapi -include /home/acme/git/linux/include/linux/kconfig.h 
set env: NR_CPUS=4
set env: LINUX_VERSION_CODE=0x40e00
set env: CLANG_EXEC=/usr/local/bin/clang
unset env: CLANG_OPTIONS
set env: KERNEL_INC_OPTIONS= -nostdinc -isystem /usr/lib/gcc/x86_64-redhat-linux/7/include -I/home/acme/git/linux/arch/x86/include -I./arch/x86/include/generated  -I/home/acme/git/linux/include -I./include -I/home/acme/git/linux/arch/x86/include/uapi -I./arch/x86/include/generated/uapi -I/home/acme/git/linux/include/uapi -I./include/generated/uapi -include /home/acme/git/linux/include/linux/kconfig.h 
set env: WORKING_DIR=/lib/modules/4.14.0+/build
set env: CLANG_SOURCE=/home/acme/bpf/open.c
llvm compiling command template: $CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c "$CLANG_SOURCE" -target bpf -O2 -o -
libbpf: loading object 'open.c' from buffer
libbpf: section .strtab, size 103, link 0, flags 0, type=3
libbpf: section .text, size 0, link 0, flags 6, type=1
libbpf: section prog=do_sys_open filename, size 168, link 0, flags 6, type=1
libbpf: found program prog=do_sys_open filename
libbpf: section .relprog=do_sys_open filename, size 16, link 8, flags 0, type=9
libbpf: section maps, size 16, link 0, flags 3, type=1
libbpf: section license, size 4, link 0, flags 3, type=1
libbpf: license of open.c is GPL
libbpf: section version, size 4, link 0, flags 3, type=1
libbpf: kernel version of open.c is 40e00
libbpf: section .symtab, size 144, link 1, flags 0, type=2
libbpf: maps in open.c: 1 maps in 16 bytes
libbpf: map 0 is "__bpf_stdout__"
libbpf: collecting relocating info for: 'prog=do_sys_open filename'
libbpf: relocation: insn_idx=13
libbpf: relocation: find map 0 (__bpf_stdout__) for insn 13
bpf: config program 'prog=do_sys_open filename'
symbol:do_sys_open file:(null) line:0 offset:0 return:0 lazy:(null)
parsing arg: filename into filename
bpf: config 'prog=do_sys_open filename' is ok
Failed to open cache(-1): /root/.debug/[kernel.kallsyms]/b5e25bb34abb3ddefa85250978beb530cc2eebd5/probes
Cache open error: -1
Looking at the vmlinux_path (8 entries long)
Using /lib/modules/4.14.0+/build/vmlinux for symbols
Open Debuginfo file: /lib/modules/4.14.0+/build/vmlinux
Try to find probe point from debuginfo.
Matched function: do_sys_open [2a2e5db]
Probe point found: do_sys_open+0
Searching 'filename' variable in context.
Converting variable filename into trace event.
filename type is (null).
Opening /sys/kernel/debug/tracing//README write=0
Found 1 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:perf_bpf_probe/prog _text+2493840 filename=%si:x64
In map_prologue, ntevs=1
mapping[0]=0
libbpf: create map __bpf_stdout__: fd=3
prologue: pass validation
prologue: fast path
libbpf: load bpf program failed: Permission denied
libbpf: -- BEGIN DUMP LOG ---
libbpf: 
0: (79) r3 = *(u64 *)(r1 +104)
1: (b7) r2 = 0
2: (bf) r6 = r1
3: (bf) r1 = r10
4: (07) r1 += -128
5: (b7) r2 = 128
6: (85) call bpf_probe_read_str#45
7: (bf) r1 = r0
8: (67) r1 <<= 32
9: (77) r1 >>= 32
10: (15) if r1 == 0x0 goto pc+10
 R0=inv(id=0) R1=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff)) R6=ctx(id=0,off=0,imm=0) R10=fp0
11: (57) r0 &= 127
12: (bf) r4 = r10
13: (07) r4 += -128
14: (bf) r1 = r6
15: (18) r2 = 0xffff92bfc2aba840
17: (18) r3 = 0xffffffff
19: (bf) r5 = r0
20: (85) call bpf_perf_event_output#25
invalid stack type R4 off=-128 access_size=0

libbpf: -- END LOG --
libbpf: Loading the 0th instance of program 'prog=do_sys_open filename' failed
libbpf: failed to load program 'prog=do_sys_open filename'
libbpf: failed to load object 'open.c'
bpf: load objects failed
event syntax error: 'open.c'
                     \___ Kernel verifier blocks program loading

(add -v to see detail)
Run 'perf list' for a list of valid events

 Usage: perf trace [<options>] [<command>]
    or: perf trace [<options>] -- <command> [<options>]
    or: perf trace record [<options>] [<command>]
    or: perf trace record [<options>] -- <command> [<options>]

    -e, --event <event>   event/syscall selector. use 'perf list' to list available events
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Opening /sys/kernel/debug/tracing//uprobe_events write=1
Parsing probe_events: p:perf_bpf_probe/prog _text+2493840 filename=%si:x64
Group:perf_bpf_probe Event:prog probe:p
Writing event: -:perf_bpf_probe/prog
[root@jouet bpf]#