Help with the BPF verifier
Subsystems (2)
tl;dr: I seem to be trying to get past clang optimizations that get the
verifier to accept my proggie.
Hi,
So I'm moving to use raw_syscalls:sys_exit to collect pointer
contents, using maps to tell the bpf program what to copy, how many bytes, filters, etc.
I'm at the start of it at this point I need to use an index to
get to the right syscall arg that is a filename, starting just with "open" and "openat", that have the filename in different args, so to get this first part working I'm doing it directly in the bpf restricted C program, later this will be to maps, etc, so if I set the index as a constant, just for testing, it works, look at the "open" and "openat" calls below, later we'll see why openat is failing to augment its "filename" arg while "open" works:
[root@seventh perf]# trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
? ( ): sleep/10152 ... [continued]: execve()) = 0
0.045 ( 0.004 ms): sleep/10152 brk() = 0x55ccff356000
0.074 ( 0.007 ms): sleep/10152 access(filename: , mode: R) = -1 ENOENT No such file or directory
0.089 ( 0.006 ms): sleep/10152 openat(dfd: CWD, filename: , flags: CLOEXEC) = 3
0.097 ( 0.003 ms): sleep/10152 fstat(fd: 3, statbuf: 0x7ffecdd283f0) = 0
0.103 ( 0.006 ms): sleep/10152 mmap(len: 103334, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8ffee9c000
0.111 ( 0.002 ms): sleep/10152 close(fd: 3) = 0
0.135 ( 0.007 ms): sleep/10152 openat(dfd: CWD, filename: , flags: CLOEXEC) = 3
0.144 ( 0.003 ms): sleep/10152 read(fd: 3, buf: 0x7ffecdd285b8, count: 832) = 832
0.150 ( 0.002 ms): sleep/10152 fstat(fd: 3, statbuf: 0x7ffecdd28450) = 0
0.155 ( 0.005 ms): sleep/10152 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) = 0x7f8ffee9a000
0.166 ( 0.007 ms): sleep/10152 mmap(len: 3889792, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3) = 0x7f8ffe8dc000
0.175 ( 0.010 ms): sleep/10152 mprotect(start: 0x7f8ffea89000, len: 2093056) = 0
0.188 ( 0.010 ms): sleep/10152 mmap(addr: 0x7f8ffec88000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 1753088) = 0x7f8ffec88000
0.204 ( 0.005 ms): sleep/10152 mmap(addr: 0x7f8ffec8e000, len: 14976, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7f8ffec8e000
0.218 ( 0.002 ms): sleep/10152 close(fd: 3) = 0
0.239 ( 0.002 ms): sleep/10152 arch_prctl(option: 4098, arg2: 140256433779968) = 0
0.312 ( 0.009 ms): sleep/10152 mprotect(start: 0x7f8ffec88000, len: 16384, prot: READ) = 0
0.343 ( 0.005 ms): sleep/10152 mprotect(start: 0x55ccff1c6000, len: 4096, prot: READ) = 0
0.354 ( 0.006 ms): sleep/10152 mprotect(start: 0x7f8ffeeb6000, len: 4096, prot: READ) = 0
0.362 ( 0.019 ms): sleep/10152 munmap(addr: 0x7f8ffee9c000, len: 103334) = 0
0.476 ( 0.002 ms): sleep/10152 brk() = 0x55ccff356000
0.480 ( 0.004 ms): sleep/10152 brk(brk: 0x55ccff377000) = 0x55ccff377000
0.487 ( 0.002 ms): sleep/10152 brk() = 0x55ccff377000
0.497 ( 0.008 ms): sleep/10152 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3
0.507 ( 0.002 ms): sleep/10152 fstat(fd: 3, statbuf: 0x7f8ffec8daa0) = 0
0.511 ( 0.006 ms): sleep/10152 mmap(len: 113045344, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8ff7d0d000
0.524 ( 0.002 ms): sleep/10152 close(fd: 3) = 0
0.574 (1000.140 ms): sleep/10152 nanosleep(rqtp: 0x7ffecdd29130) = 0 1000.753 ( 0.007 ms): sleep/10152 close(fd: 1) = 0 1000.767 ( 0.004 ms): sleep/10152 close(fd: 2) = 0
1000.781 ( ): sleep/10152 exit_group()
[root@seventh perf]#
1 // SPDX-License-Identifier: GPL-2.0
2 /*
3 * Augment the raw_syscalls tracepoints with the contents of the pointer arguments.
4 *
5 * Test it with:
6 *
7 * perf trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c cat /etc/passwd > /dev/null
8 *
9 * This exactly matches what is marshalled into the raw_syscall:sys_enter
10 * payload expected by the 'perf trace' beautifiers.
11 *
12 * For now it just uses the existing tracepoint augmentation code in 'perf
13 * trace', in the next csets we'll hook up these with the sys_enter/sys_exit
14 * code that will combine entry/exit in a strace like way.
15 */
16 #include <stdio.h>
17 #include <linux/socket.h>
18 /* bpf-output associated map */
19 struct bpf_map SEC("maps") __augmented_syscalls__ = {
20 .type = BPF_MAP_TYPE_PERF_EVENT_ARRAY,
21 .key_size = sizeof(int),
22 .value_size = sizeof(u32),
23 .max_entries = __NR_CPUS__,
24 };
25 struct syscall_enter_args {
26 unsigned long long common_tp_fields;
27 long syscall_nr;
28 unsigned long args[6];
29 };
30 struct syscall_exit_args {
31 unsigned long long common_tp_fields;
32 long syscall_nr;
33 long ret;
34 };
35 struct augmented_filename {
36 unsigned int size;
37 int reserved;
38 char value[256];
39 };
40 #define SYS_OPEN 2
41 #define SYS_OPENAT 257
42 SEC("raw_syscalls:sys_enter")
43 int sys_enter(struct syscall_enter_args *args)
44 {
45 struct {
46 struct syscall_enter_args args;
47 struct augmented_filename filename;
48 } augmented_args;
49 unsigned int len = sizeof(augmented_args);
50 unsigned int filename_arg = 6;
51 probe_read(&augmented_args.args, sizeof(augmented_args.args), args);
52 switch (augmented_args.args.syscall_nr) {
53 case SYS_OPEN: filename_arg = 0; break;
54 case SYS_OPENAT: filename_arg = 1; break;
55 }
56 if (filename_arg <= 5) {
57 augmented_args.filename.reserved = 0;
58 augmented_args.filename.size = probe_read_str(&augmented_args.filename.value,
59 sizeof(augmented_args.filename.value),
60 (const void *)args->args[0]);
61 if (augmented_args.filename.size < sizeof(augmented_args.filename.value)) {
62 len -= sizeof(augmented_args.filename.value) - augmented_args.filename.size;
63 len &= sizeof(augmented_args.filename.value) - 1;
64 }
65 } else {
66 len = sizeof(augmented_args.args);
67 }
68 perf_event_output(args, &__augmented_syscalls__, BPF_F_CURRENT_CPU, &augmented_args, len);
69 return 0;
70 }
71 SEC("raw_syscalls:sys_exit")
72 int sys_exit(struct syscall_exit_args *args)
73 {
74 return 1; /* 0 as soon as we start copying data returned by the kernel, e.g. 'read' */
75 }
76 license(GPL);In line #60 if I change that to 1, then "openat" works and "open" doesn't, so what I wanted was to use filename_arg there as the index, now it comes from that switch, but really it'll come from userspace, that knows the syscall tables for each arch, etc.
But if I do that, i.e. apply this patch to that program:
wb/augmented_raw_syscalls.c renamed from wb/augmented_raw_syscalls.c.old +1 -1
@@ -67,7 +67,7 @@ augmented_args.filename.reserved =0 ; augmented_args.filename.size =probe_read_str (&augmented_args.filename.value,sizeof (augmented_args.filename.value), - (const void *)args->args[0 ]); + (const void *)args->args[filename_arg]);if (augmented_args.filename.size <sizeof (augmented_args.filename.value)) { len -=sizeof (augmented_args.filename.value) - augmented_args.filename.size; len &=sizeof (augmented_args.filename.value) -1 ;
Then I end up with the verifier complying, I tried various ways to get around the compiler about filename_arg being safe to use as an index, but I couldn't find the right trick, ideas?
This is what I end up with when I apply that patch:
[root@seventh perf]# trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1 event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.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
[root@seventh perf]#
Using -v, as suggested, I get:
[root@seventh perf]# trace -v -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
bpf: builtin compilation failed: -95, try external compiler
Kernel build dir is set to /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build
set env: KBUILD_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/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=0x41300
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: PERF_BPF_INC_OPTIONS=-I/home/acme/lib/perf/include/bpf
set env: WORKING_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/build
set env: CLANG_SOURCE=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c
llvm compiling command template: $CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $PERF_BPF_INC_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c "$CLANG_SOURCE" -target bpf $CLANG_EMIT_LLVM -O2 -o - $LLVM_OPTIONS_PIPE
llvm compiling command : /usr/local/bin/clang -D__KERNEL__ -D__NR_CPUS__=4 -DLINUX_VERSION_CODE=0x41300 -I/home/acme/lib/perf/include/bpf -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 -Wno-unused-value -Wno-pointer-sign -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -target bpf -O2 -o -
libbpf: loading object 'tools/perf/examples/bpf/augmented_raw_syscalls.c' from buffer
libbpf: section(1) .strtab, size 168, link 0, flags 0, type=3
libbpf: skip section(1) .strtab
libbpf: section(2) .text, size 0, link 0, flags 6, type=1
libbpf: skip section(2) .text
libbpf: section(3) raw_syscalls:sys_enter, size 376, link 0, flags 6, type=1
libbpf: found program raw_syscalls:sys_enter
libbpf: section(4) .relraw_syscalls:sys_enter, size 16, link 10, flags 0, type=9
libbpf: section(5) raw_syscalls:sys_exit, size 16, link 0, flags 6, type=1
libbpf: found program raw_syscalls:sys_exit
libbpf: section(6) maps, size 56, link 0, flags 3, type=1
libbpf: section(7) license, size 4, link 0, flags 3, type=1
libbpf: license of tools/perf/examples/bpf/augmented_raw_syscalls.c is GPL
libbpf: section(8) version, size 4, link 0, flags 3, type=1
libbpf: kernel version of tools/perf/examples/bpf/augmented_raw_syscalls.c is 41300
libbpf: section(9) .llvm_addrsig, size 6, link 10, flags 80000000, type=1879002115
libbpf: skip section(9) .llvm_addrsig
libbpf: section(10) .symtab, size 240, link 1, flags 0, type=2
libbpf: maps in tools/perf/examples/bpf/augmented_raw_syscalls.c: 2 maps in 56 bytes
libbpf: map 0 is "__augmented_syscalls__"
libbpf: map 1 is "__bpf_stdout__"
libbpf: collecting relocating info for: 'raw_syscalls:sys_enter'
libbpf: relo for 4 value 28 name 124
libbpf: relocation: insn_idx=39
libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 39
bpf: config program 'raw_syscalls:sys_enter'
bpf: config program 'raw_syscalls:sys_exit'
libbpf: create map __bpf_stdout__: fd=3
libbpf: create map __augmented_syscalls__: fd=4
libbpf: load bpf program failed: Permission denied
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (b7) r2 = 1
8: (79) r3 = *(u64 *)(r10 -320)
9: (15) if r3 == 0x101 goto pc+1
R0=inv(id=0) R2=inv1 R3=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (b7) r2 = 6
11: (b7) r1 = 0
12: (15) if r3 == 0x2 goto pc+1
R0=inv(id=0) R1=inv0 R2=inv6 R3=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
13: (bf) r1 = r2
14: (25) if r1 > 0x5 goto pc+21
R0=inv(id=0) R1=inv6 R2=inv6 R3=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
15: (b7) r2 = 0
16: (63) *(u32 *)(r10 -260) = r2
17: (67) r1 <<= 32
18: (77) r1 >>= 32
19: (67) r1 <<= 3
20: (bf) r2 = r6
21: (0f) r2 += r1
22: (79) r3 = *(u64 *)(r2 +16)
R2 invalid mem access 'inv'
libbpf: -- END LOG --
libbpf: failed to load program 'raw_syscalls:sys_enter'
libbpf: failed to load object 'tools/perf/examples/bpf/augmented_raw_syscalls.c'
bpf: load objects failed: err=-4007: (Kernel verifier blocks program loading) event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.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
[root@seventh perf]#
David Miller
maintainerFrom: Arnaldo Carvalho de Melo <[email protected]>
Date: Thu, 1 Nov 2018 15:52:17 -0300
Quoted 1 line
50 unsigned int filename_arg = 6;
...
wb/augmented_raw_syscalls.c line 70
Quoted 8 lines
wb/augmented_raw_syscalls.c renamed from wb/augmented_raw_syscalls.c.old +1
-1@@ -67,7 +67,7 @@ augmented_args.filename.reserved =0 ; augmented_args.filename.size =probe_read_str (&augmented_args.filename.value,sizeof (augmented_args.filename.value), - (const void *)args->args[0 ]); + (const void *)args->args[filename_arg]);
args[] is sized to '6', therefore the last valid index is '5', yet you're using '6' here which is one entry past the end of the declared array.
Em Thu, Nov 01, 2018 at 12:10:39PM -0700, David Miller escreveu:
Quoted 5 lines
From: Arnaldo Carvalho de Melo <[email protected]>
Date: Thu, 1 Nov 2018 15:52:17 -0300Quoted 1 line
50 unsigned int filename_arg = 6;...
Quoted 11 lines
wb/augmented_raw_syscalls.c line 70
Quoted 8 lines
wb/augmented_raw_syscalls.c renamed from wb/augmented_raw_syscalls.c.old +1
-1@@ -67,7 +67,7 @@ augmented_args.filename.reserved =0 ; augmented_args.filename.size =probe_read_str (&augmented_args.filename.value,sizeof (augmented_args.filename.value), - (const void *)args->args[0 ]); + (const void *)args->args[filename_arg]);args[] is sized to '6', therefore the last valid index is '5', yet you're using '6' here which is one entry past the end of the declared array.
Nope... this is inside an if:
if (filename_arg <= 5) {
augmented_args.filename.reserved = 0;
augmented_args.filename.size = probe_read_str(&augmented_args.filename.value,
sizeof(augmented_args.filename.value),
(const void *)args->args[filename_arg]);
if (augmented_args.filename.size < sizeof(augmented_args.filename.value)) {
len -= sizeof(augmented_args.filename.value) - augmented_args.filename.size;
len &= sizeof(augmented_args.filename.value) - 1;
}
} else {I use 6 to mean "hey, this syscall doesn't have any string argument, don't bother with it".
- Arnaldo
David Miller
maintainerFrom: Arnaldo Carvalho de Melo <[email protected]>
Date: Thu, 1 Nov 2018 16:13:10 -0300
Quoted 13 lines
Nope... this is inside an if:
if (filename_arg <= 5) { augmented_args.filename.reserved = 0; augmented_args.filename.size = probe_read_str(&augmented_args.filename.value, sizeof(augmented_args.filename.value), (const void *)args->args[filename_arg]); if (augmented_args.filename.size < sizeof(augmented_args.filename.value)) { len -= sizeof(augmented_args.filename.value) - augmented_args.filename.size; len &= sizeof(augmented_args.filename.value) - 1; } } else {
Quoted 2 lines
I use 6 to mean "hey, this syscall doesn't have any string argument, don't bother with it".
Really weird. And it's unsigned so I can't imagine it wants you to check that it's >= 0...
Maybe Deniel or someone else can figure it out.
Quoted 10 lines · Arnaldo Carvalho de Melo
R0=inv(id=0) R1=inv6 R2=inv6 R3=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
15: (b7) r2 = 0
16: (63) *(u32 *)(r10 -260) = r2
17: (67) r1 <<= 32
18: (77) r1 >>= 32
19: (67) r1 <<= 3
20: (bf) r2 = r6
21: (0f) r2 += r1
22: (79) r3 = *(u64 *)(r2 +16)
R2 invalid mem access 'inv'
I wonder if you could run this with verifier log level 2? (I'm not sure how you would go about plumbing that through the perf tooling.) It seems very odd that it ends up with R2=inv, and I'm wondering whether R1 becomes unknown during the shifts or whether the addition in insn 21 somehow produces the unknown-ness. (I know we used to have a thing[1] where doing ptr += K and then also having an offset in the LDX produced an error about ptr+const+const, but that seems to have been fixed at some point.)
Note however that even if we get past this, R1 at this point holds 6, so it looks like the verifier is walking the impossible path where we're inside the 'if' even though filename_arg = 6. This is a (slightly annoying) verifier limitation, that it walks paths with impossible combinations of constraints (we've previously had cases where assertions in the verifier would blow up because of this, e.g. registers with max_val less than min_val). So if the check_ctx_access() is going to worry about whether you're off the end of the array (I'm not sure what your program type is and thus which is_valid_access callback is involved), then it'll complain about this.
If filename_arg came from some external source you'd have a different problem, because then it would have a totally unknown value, that on entering the 'if' becomes "unknown but < 6", which is still too variable to have as the offset of a ctx access. Those have to be at a known constant offset, so that we can determine the type of the returned value.
As a way to fix this, how about [UNTESTED!]:
const void *filename_arg = NULL;
/* ... */
switch (augmented_args.args.syscall_nr) {
case SYS_OPEN: filename_arg = args->args[0]; break;
case SYS_OPENAT: filename_arg = args->args[1]; break;
}
/* ... */
if (filename_arg) {
/* stuff */
blah = probe_read_str(/* ... */, filename_arg);
} else {
/* the other stuff */
}
That way, you're only ever dealing in constant pointers (although judging by an old thread I found[1] about ptr+const+const, the compiler might decide to make some optimisations that end up looking like your existing code).
As for what you want to do with the index coming from userspace, the verifier will not like that at all, as mentioned above, so I think you'll need to do something like:
switch (filename_arg_from_userspace) {
case 0: filename_arg = args->args[0]; break;
case 1: filename_arg = args->args[1]; break;
/* etc */
default: filename_arg = NULL;
}
thus ensuring that you only ever have ctx pointers with constant offsets.
-Ed
[1]: https://lists.iovisor.org/g/iovisor-dev/topic/21386327#1302
Em Thu, Nov 01, 2018 at 08:05:07PM +0000, Edward Cree escreveu:
Quoted 43 lines · Arnaldo Carvalho de Melo
Quoted 10 lines
R0=inv(id=0) R1=inv6 R2=inv6 R3=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
15: (b7) r2 = 0
16: (63) *(u32 *)(r10 -260) = r2
17: (67) r1 <<= 32
18: (77) r1 >>= 32
19: (67) r1 <<= 3
20: (bf) r2 = r6
21: (0f) r2 += r1
22: (79) r3 = *(u64 *)(r2 +16)
R2 invalid mem access 'inv'I wonder if you could run this with verifier log level 2? (I'm not sure how you would go about plumbing that through the perf tooling.) It seems very odd that it ends up with R2=inv, and I'm wondering whether R1 becomes unknown during the shifts or whether the addition in insn 21 somehow produces the unknown-ness. (I know we used to have a thing[1] where doing ptr += K and then also having an offset in the LDX produced an error about ptr+const+const, but that seems to have been fixed at some point.)
Note however that even if we get past this, R1 at this point holds 6, so it looks like the verifier is walking the impossible path where we're inside the 'if' even though
filename_arg= 6. This is a (slightly annoying) verifier limitation, that it walks paths with impossible combinations of constraints (we've previously had cases where assertions in the verifier would blow up because of this, e.g. registers withmax_valless than min_val). So if thecheck_ctx_access()is going to worry about whether you're off the end of the array (I'm not sure what your program type is and thus whichis_valid_accesscallback is involved), then it'll complain about this.
Iffilename_argcame from some external source you'd have a different problem, because then it would have a totally unknown value, that on entering the 'if' becomes "unknown but < 6", which is still too variable to have as the offset of a ctx access. Those have to be at a known constant offset, so that we can determine the type of the returned value.As a way to fix this, how about [UNTESTED!]:
const void*filename_arg= NULL;
/* ... */
switch (augmented_args.args.syscall_nr) {
caseSYS_OPEN:filename_arg= args->args[0]; break; caseSYS_OPENAT:filename_arg= args->args[1]; break; }
/* ... */
if (filename_arg) {
Quoted 8 lines
/* stuff */
blah = probe_read_str(/* ... */,filename_arg);
} else {
/* the other stuff */
}
That way, you're only ever dealing in constant pointers (although judging by an old thread I found[1] about ptr+const+const, the compiler might decide to make some optimisations that end up looking like your existing code).
Yeah, didn't work as well:
SEC("raw_syscalls:sys_enter")
int sys_enter(struct syscall_enter_args *args)
{
struct {
struct syscall_enter_args args;
struct augmented_filename filename;
} augmented_args;
unsigned int len = sizeof(augmented_args);
const void *filename_arg = NULL;
probe_read(&augmented_args.args, sizeof(augmented_args.args), args);
switch (augmented_args.args.syscall_nr) {
case SYS_OPEN: filename_arg = (const void *)args->args[0]; break;
case SYS_OPENAT: filename_arg = (const void *)args->args[1]; break;
}
if (filename_arg != NULL) {
augmented_args.filename.reserved = 0;
augmented_args.filename.size = probe_read_str(&augmented_args.filename.value,
sizeof(augmented_args.filename.value),
filename_arg);
if (augmented_args.filename.size < sizeof(augmented_args.filename.value)) {
len -= sizeof(augmented_args.filename.value) - augmented_args.filename.size;
len &= sizeof(augmented_args.filename.value) - 1;
}
} else {
len = sizeof(augmented_args.args);
}
perf_event_output(args, &__augmented_syscalls__, BPF_F_CURRENT_CPU, &augmented_args, len);
return 0;
}And the -vv in 'perf trace' didn't seem to map to further details in the output of the verifier debug:
# trace -vv -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1 bpf: builtin compilation failed: -95, try external compiler Kernel build dir is set to /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build set env: KBUILD_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/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=0x41300 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: PERF_BPF_INC_OPTIONS=-I/home/acme/lib/perf/include/bpf set env: WORKING_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/build set env: CLANG_SOURCE=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c llvm compiling command template: $CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $PERF_BPF_INC_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c "$CLANG_SOURCE" -target bpf $CLANG_EMIT_LLVM -O2 -o - $LLVM_OPTIONS_PIPE llvm compiling command : /usr/local/bin/clang -D__KERNEL__ -D__NR_CPUS__=4 -DLINUX_VERSION_CODE=0x41300 -I/home/acme/lib/perf/include/bpf -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 -Wno-unused-value -Wno-pointer-sign -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -target bpf -O2 -o - libbpf: loading object 'tools/perf/examples/bpf/augmented_raw_syscalls.c' from buffer libbpf: section(1) .strtab, size 168, link 0, flags 0, type=3 libbpf: skip section(1) .strtab libbpf: section(2) .text, size 0, link 0, flags 6, type=1 libbpf: skip section(2) .text libbpf: section(3) raw_syscalls:sys_enter, size 344, link 0, flags 6, type=1 libbpf: found program raw_syscalls:sys_enter libbpf: section(4) .relraw_syscalls:sys_enter, size 16, link 10, flags 0, type=9 libbpf: section(5) raw_syscalls:sys_exit, size 16, link 0, flags 6, type=1 libbpf: found program raw_syscalls:sys_exit libbpf: section(6) maps, size 56, link 0, flags 3, type=1 libbpf: section(7) license, size 4, link 0, flags 3, type=1 libbpf: license of tools/perf/examples/bpf/augmented_raw_syscalls.c is GPL libbpf: section(8) version, size 4, link 0, flags 3, type=1 libbpf: kernel version of tools/perf/examples/bpf/augmented_raw_syscalls.c is 41300 libbpf: section(9) .llvm_addrsig, size 6, link 10, flags 80000000, type=1879002115 libbpf: skip section(9) .llvm_addrsig libbpf: section(10) .symtab, size 240, link 1, flags 0, type=2 libbpf: maps in tools/perf/examples/bpf/augmented_raw_syscalls.c: 2 maps in 56 bytes libbpf: map 0 is "__augmented_syscalls__" libbpf: map 1 is "__bpf_stdout__" libbpf: collecting relocating info for: 'raw_syscalls:sys_enter' libbpf: relo for 4 value 28 name 124 libbpf: relocation: insn_idx=35 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 35 Added extra kernel map __entry_SYSCALL_64_trampoline fffffe0000006000-fffffe0000007000 Added extra kernel map __entry_SYSCALL_64_trampoline fffffe0000032000-fffffe0000033000 Added extra kernel map __entry_SYSCALL_64_trampoline fffffe000005e000-fffffe000005f000 Added extra kernel map __entry_SYSCALL_64_trampoline fffffe000008a000-fffffe000008b000 bpf: config program 'raw_syscalls:sys_enter' bpf: config program 'raw_syscalls:sys_exit' libbpf: create map __bpf_stdout__: fd=3 libbpf: create map __augmented_syscalls__: fd=4 libbpf: load bpf program failed: Permission denied libbpf: -- BEGIN DUMP LOG --- libbpf: 0: (bf) r6 = r1 1: (bf) r1 = r10 2: (07) r1 += -328 3: (b7) r7 = 64 4: (b7) r2 = 64 5: (bf) r3 = r6 6: (85) call bpf_probe_read#4 7: (79) r1 = *(u64 *)(r10 -320) 8: (15) if r1 == 0x101 goto pc+4 R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1 9: (55) if r1 != 0x2 goto pc+22 R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1 10: (bf) r1 = r6 11: (07) r1 += 16 12: (05) goto pc+2 15: (79) r3 = *(u64 *)(r1 +0) dereference of modified ctx ptr R1 off=16 disallowed
libbpf: -- END LOG --
libbpf: failed to load program 'raw_syscalls:sys_enter'
libbpf: failed to load object 'tools/perf/examples/bpf/augmented_raw_syscalls.c'
bpf: load objects failed: err=-4007: (Kernel verifier blocks program loading) event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.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
[root@seventh perf]#
I'll check how to plumb that, but its a holiday down here in Brazil, kids at home...
Quoted 14 lines
As for what you want to do with the index coming from userspace, the verifier will not like that at all, as mentioned above, so I think you'll need to do something like:
switch (filename_arg_from_userspace) {
case 0:filename_arg= args->args[0]; break;
case 1:filename_arg= args->args[1]; break;
/* etc */
default:filename_arg= NULL;
}
thus ensuring that you only ever have ctx pointers with constant offsets.-Ed
[1]: https://lists.iovisor.org/g/iovisor-dev/topic/21386327#1302
Quoted 4 lines · Arnaldo Carvalho de Melo
Yeah, didn't work as well:
And the -vv in 'perf trace' didn't seem to map to further details in the output of the verifier debug:
Yeah for log_level 2 you probably need to make source-level changes to either perf or libbpf (I think the latter). It's annoying that essentially no tools plumb through an option for that, someone should fix them ;-)
Quoted 11 lines
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (79) r1 = *(u64 *)(r10 -320)
8: (15) if r1 ==0x101goto pc+4
Quoted 8 lines
R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
9: (55) if r1 !=0x2goto pc+22
R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (bf) r1 = r6
11: (07) r1 += 16
12: (05) goto pc+2
15: (79) r3 = *(u64 *)(r1 +0)
dereference of modified ctx ptr R1 off=16 disallowed
Aha, we at least got a different error message this time.
And indeed llvm has done that optimisation, rather than the more obvious 11: r3 = *(u64 *)(r1 +16)
because it wants to have lots of reads share a single insn. You may be able to defeat that optimisation by adding compiler barriers, idk. Maybe someone with llvm knowledge can figure out how to stop it (ideally, llvm would know when it's generating for bpf backend and not do that). -O0? ¯\_(ツ)_/¯ Alternatively, your prog looks short enough that maybe you could kick the C habit and write it directly in eBPF asm, that way no-one is optimising things behind your back. (I realise this option won't appeal to everyone ;-) The reason the verifier disallows this, iirc, is because it needs to be able to rewrite the offsets on ctx accesses (see convert_ctx_accesses()) in case underlying kernel struct doesn't match the layout of the ctx ABI. To do this it needs the ctx offset to live entirely in the insn doing the access, otherwise different paths could lead to the same insn accessing different ctx offsets with different fixups needed — can't be done.
-Ed
Quoted 28 lines · Edward Cree
Quoted 4 lines · Arnaldo Carvalho de Melo
Yeah, didn't work as well:
And the -vv in 'perf trace' didn't seem to map to further details in the output of the verifier debug:
Yeah for
log_level2 you probably need to make source-level changes to either
perf or libbpf (I think the latter). It's annoying that essentially no tools plumb through an option for that, someone should fix them ;-)Quoted 11 lines
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (79) r1 = *(u64 *)(r10 -320)
8: (15) if r1 ==0x101goto pc+4Quoted 8 lines
R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
9: (55) if r1 !=0x2goto pc+22
R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (bf) r1 = r6
11: (07) r1 += 16
12: (05) goto pc+2
15: (79) r3 = *(u64 *)(r1 +0)
dereference of modified ctx ptr R1 off=16 disallowed
Quoted 7 lines
Aha, we at least got a different error message this time.
And indeed llvm has done that optimisation, rather than the more obvious 11: r3 = *(u64 *)(r1 +16)
because it wants to have lots of reads share a single insn. You may be able to defeat that optimisation by adding compiler barriers, idk. Maybe someone with llvm knowledge can figure out how to stop it (ideally, llvm would know when it's generating for bpf backend and not do that). -O0? ¯\_(ツ)_/¯
The optimization mostly likes below:
br1:
...
r1 += 16
goto merge
br2:
...
r1 += 20
goto merge
merge:
*(u64 *)(r1 + 0)The compiler tries to merge common loads. There is no easy way to stop this compiler optimization without turning off a lot of other optimizations. The easiest way is to add barriers
__asm__ __volatile__("": : :"memory")after the ctx memory access to prevent their down stream merging.
Quoted 3 lines
Alternatively, your prog looks short enough that maybe you could kick the C
habit and write it directly in eBPF asm, that way no-one is optimising things behind your back. (I realise this option won't appeal to everyone ;-)
The LLVM supports BPF inline assembly as well. Some examples here
https://github.com/llvm-mirror/llvm/blob/master/test/CodeGen/BPF/inline_asm.ll
You may try it for selective ctx access to work around some compiler optimizations. I personally have not used it yet and actually not sure whether it actually works or not :-)
Quoted 2 lines
The reason the verifier disallows this, iirc, is because it needs to be able
to rewrite the offsets on ctx accesses (seeconvert_ctx_accesses()) in case > underlying kernel struct doesn't match the layout of the ctx ABI.
To do this
Quoted 6 lines
it needs the ctx offset to live entirely in the insn doing the access, otherwise different paths could lead to the same insn accessing different ctx offsets with different fixups needed — can't be done.
-Ed
Em Fri, Nov 02, 2018 at 09:27:52PM +0000, Yonghong Song escreveu:
Quoted 51 lines · Edward Cree
Quoted 28 lines · Arnaldo Carvalho de Melo
Quoted 4 lines
Yeah, didn't work as well:
And the -vv in 'perf trace' didn't seem to map to further details in the output of the verifier debug:
Yeah for
log_level2 you probably need to make source-level changes to either
perf or libbpf (I think the latter). It's annoying that essentially no tools plumb through an option for that, someone should fix them ;-)Quoted 11 lines
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (79) r1 = *(u64 *)(r10 -320)
8: (15) if r1 ==0x101goto pc+4Quoted 8 lines
R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
9: (55) if r1 !=0x2goto pc+22
R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (bf) r1 = r6
11: (07) r1 += 16
12: (05) goto pc+2
15: (79) r3 = *(u64 *)(r1 +0)
dereference of modified ctx ptr R1 off=16 disallowedQuoted 7 lines
Aha, we at least got a different error message this time.
And indeed llvm has done that optimisation, rather than the more obvious 11: r3 = *(u64 *)(r1 +16)
because it wants to have lots of reads share a single insn. You may be able to defeat that optimisation by adding compiler barriers, idk. Maybe someone with llvm knowledge can figure out how to stop it (ideally, llvm would know when it's generating for bpf backend and not do that). -O0? ¯\_(ツ)_/¯The optimization mostly likes below:
br1: ... r1 += 16 goto merge br2: ... r1 += 20 goto merge merge: *(u64 *)(r1 + 0)
Quoted 5 lines
The compiler tries to merge common loads. There is no easy way to stop this compiler optimization without turning off a lot of other optimizations. The easiest way is to add barriers
__asm__ __volatile__("": : :"memory")after the ctx memory access to prevent their down stream merging.
Great, this made it work:
cat /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c #include <stdio.h>
#include <linux/socket.h>
/* bpf-output associated map */
struct bpf_map SEC("maps") __augmented_syscalls__ = {
.type = BPF_MAP_TYPE_PERF_EVENT_ARRAY,
.key_size = sizeof(int),
.value_size = sizeof(u32),
.max_entries = __NR_CPUS__,
};struct syscall_enter_args {
unsigned long long common_tp_fields;
long syscall_nr;
unsigned long args[6];
};struct syscall_exit_args {
unsigned long long common_tp_fields;
long syscall_nr;
long ret;
};struct augmented_filename {
unsigned int size;
int reserved;
char value[256];
};#define SYS_OPEN 2
#define SYS_OPENAT 257
SEC("raw_syscalls:sys_enter")
int sys_enter(struct syscall_enter_args *args)
{
struct {
struct syscall_enter_args args;
struct augmented_filename filename;
} augmented_args;
unsigned int len = sizeof(augmented_args);
const void *filename_arg = NULL;
probe_read(&augmented_args.args, sizeof(augmented_args.args), args);
switch (augmented_args.args.syscall_nr) {
case SYS_OPEN: filename_arg = (const void *)args->args[0];
__asm__ __volatile__("": : :"memory");
break;
case SYS_OPENAT: filename_arg = (const void *)args->args[1];
break;
default:
return 0;
}
if (filename_arg != NULL) {
augmented_args.filename.reserved = 0;
augmented_args.filename.size = probe_read_str(&augmented_args.filename.value,
sizeof(augmented_args.filename.value),
filename_arg);
if (augmented_args.filename.size < sizeof(augmented_args.filename.value)) {
len -= sizeof(augmented_args.filename.value) - augmented_args.filename.size;
len &= sizeof(augmented_args.filename.value) - 1;
}
} else {
len = sizeof(augmented_args.args);
}
perf_event_output(args, &__augmented_syscalls__, BPF_F_CURRENT_CPU, &augmented_args, len);
return 0;
}SEC("raw_syscalls:sys_exit")
int sys_exit(struct syscall_exit_args *args)
{
struct syscall_exit_args augmented_args;
probe_read(&augmented_args, sizeof(augmented_args), args);
return augmented_args.syscall_nr == SYS_OPEN || augmented_args.syscall_nr == SYS_OPENAT;
}license(GPL);
Now I have both open and openat getting the right
[root@jouet perf]# trace -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
LLVM: dumping tools/perf/examples/bpf/augmented_raw_syscalls.o
0.000 ( 0.010 ms): sleep/15794 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
0.028 ( 0.005 ms): sleep/15794 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC) = 3
0.241 ( 0.005 ms): sleep/15794 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3[root@jouet perf]#
[root@jouet perf]# trace -e tools/perf/examples/bpf/augmented_raw_syscalls.o cat /etc/passwd > /dev/null
0.000 ( 0.010 ms): cat/15918 openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
0.028 ( 0.006 ms): cat/15918 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC) = 3
0.241 ( 0.007 ms): cat/15918 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3
0.289 ( 0.004 ms): cat/15918 openat(dfd: CWD, filename: /etc/passwd) = 3[root@jouet perf]#
[root@jouet perf]# readelf -SW tools/perf/examples/bpf/augmented_raw_syscalls.o There are 11 section headers, starting at offset 0x438:
Section Headers:
[Nr] Name Type Address Off Size ES Flg Lk Inf Al [ 0] NULL 0000000000000000 000000 000000 00 0 0 0 [ 1] .strtab STRTAB 0000000000000000 000376 0000bd 00 0 0 1 [ 2] .text PROGBITS 0000000000000000 000040 000000 00 AX 0 0 4 [ 3] raw_syscalls:sys_enter PROGBITS 0000000000000000 000040 000138 00 AX 0 0 8 [ 4] .relraw_syscalls:sys_enter REL 0000000000000000 000360 000010 10 10 3 8 [ 5] raw_syscalls:sys_exit PROGBITS 0000000000000000 000178 000070 00 AX 0 0 8 [ 6] maps PROGBITS 0000000000000000 0001e8 000038 00 WA 0 0 4 [ 7] license PROGBITS 0000000000000000 000220 000004 00 WA 0 0 1 [ 8] version PROGBITS 0000000000000000 000224 000004 00 WA 0 0 4 [ 9] .llvm_addrsig LOOS+0xfff4c03 0000000000000000 000370 000006 00 E 10 0 1 [10] .symtab SYMTAB 0000000000000000 000228 000138 18 1 7 8
Key to Flags:
W (write), A (alloc), X (execute), M (merge), S (strings), I (info), L (link order), O (extra OS processing required), G (group), T (TLS), C (compressed), x (unknown), o (OS specific), E (exclude), p (processor specific)
[root@jouet perf]#
Quoted 9 lines
Quoted 3 lines
Alternatively, your prog looks short enough that maybe you could kick the C
habit and write it directly in eBPF asm, that way no-one is optimising things behind your back. (I realise this option won't appeal to everyone ;-)The LLVM supports BPF inline assembly as well. Some examples here
https://github.com/llvm-mirror/llvm/blob/master/test/CodeGen/BPF/inline_asm.ll
You may try it for selective ctx access to work around some compiler optimizations. I personally have not used it yet and actually not sure whether it actually works or not :-)
I will take a look at it, but the simple barrier right after the first ctx access did the trick for me, probably I'll cook some ctx accessor macros to make this transparent.
Now to make -e open,openat to set up filters via a map, get that augmented_raw_syscalls.c to be added automatically to the evlist, etc.
- Arnaldo
Quoted 9 lines
Quoted 2 lines
The reason the verifier disallows this, iirc, is because it needs to be able
to rewrite the offsets on ctx accesses (seeconvert_ctx_accesses()) in case > underlying kernel struct doesn't match the layout of the ctx ABI.To do this
Quoted 6 lines
it needs the ctx offset to live entirely in the insn doing the access, otherwise different paths could lead to the same insn accessing different ctx offsets with different fixups needed — can't be done.
-Ed
Em Fri, Nov 02, 2018 at 03:42:49PM +0000, Edward Cree escreveu:
Quoted 28 lines · Arnaldo Carvalho de Melo
Quoted 4 lines
Yeah, didn't work as well:
And the -vv in 'perf trace' didn't seem to map to further details in the output of the verifier debug:
Yeah for
log_level2 you probably need to make source-level changes to either perf or libbpf (I think the latter). It's annoying that essentially no tools plumb through an option for that, someone should fix them ;-)Quoted 11 lines
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (79) r1 = *(u64 *)(r10 -320)
8: (15) if r1 ==0x101goto pc+4Quoted 8 lines
R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
9: (55) if r1 !=0x2goto pc+22
R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (bf) r1 = r6
11: (07) r1 += 16
12: (05) goto pc+2
15: (79) r3 = *(u64 *)(r1 +0)
dereference of modified ctx ptr R1 off=16 disallowed
Quoted 7 lines
Aha, we at least got a different error message this time.
And indeed llvm has done that optimisation, rather than the more obvious 11: r3 = *(u64 *)(r1 +16)
because it wants to have lots of reads share a single insn. You may be able to defeat that optimisation by adding compiler barriers, idk. Maybe someone with llvm knowledge can figure out how to stop it (ideally, llvm would know when it's generating for bpf backend and not do that). -O0? ¯\_(ツ)_/¯
set env: NR_CPUS=4
set env: LINUX_VERSION_CODE=0x41300
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: PERF_BPF_INC_OPTIONS=-I/home/acme/lib/perf/include/bpf
set env: WORKING_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/build
set env: CLANG_SOURCE=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c
llvm compiling command template: $CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $PERF_BPF_INC_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c "$CLANG_SOURCE" -target bpf $CLANG_EMIT_LLVM -O2 -o - $LLVM_OPTIONS_PIPE
llvm compiling command : /usr/local/bin/clang -D__KERNEL__ -D__NR_CPUS__=4 -DLINUX_VERSION_CODE=0x41300 -I/home/acme/lib/perf/include/bpf -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 -Wno-unused-value -Wno-pointer-sign -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -target bpf -O2 -o -
So it is using -O2, lets try with -O0...
So I added this to my ~/.perfconfig, i.e. the default clang command line template replacing -O2 with -O0.
[root@seventh perf]# cat ~/.perfconfig
[llvm]
clang-bpf-cmd-template = "$CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $PERF_BPF_INC_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c \"$CLANG_SOURCE\" -target bpf $CLANG_EMIT_LLVM -O0 -o - $LLVM_OPTIONS_PIPE" # dump-obj = true
[root@seventh perf]#
And got an explosion:
# trace -vv -e tools/perf/examples/bpf/augmented_raw_syscalls.c sleep 1
bpf: builtin compilation failed: -95, try external compiler
Kernel build dir is set to /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build
set env: KBUILD_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/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=0x41300
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: PERF_BPF_INC_OPTIONS=-I/home/acme/lib/perf/include/bpf
set env: WORKING_DIR=/lib/modules/4.19.0-rc8-00014-gc0cff31be705/build
set env: CLANG_SOURCE=/home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c
llvm compiling command template: $CLANG_EXEC -D__KERNEL__ -D__NR_CPUS__=$NR_CPUS -DLINUX_VERSION_CODE=$LINUX_VERSION_CODE $CLANG_OPTIONS $PERF_BPF_INC_OPTIONS $KERNEL_INC_OPTIONS -Wno-unused-value -Wno-pointer-sign -working-directory $WORKING_DIR -c "$CLANG_SOURCE" -target bpf $CLANG_EMIT_LLVM -O0 -o - $LLVM_OPTIONS_PIPE
llvm compiling command : /usr/local/bin/clang -D__KERNEL__ -D__NR_CPUS__=4 -DLINUX_VERSION_CODE=0x41300 -I/home/acme/lib/perf/include/bpf -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 -Wno-unused-value -Wno-pointer-sign -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -target bpf -O0 -o -
clang-7: /home/acme/git/llvm/lib/Target/BPF/MCTargetDesc/BPFAsmBackend.cpp:74: virtual void {anonymous}::BPFAsmBackend::applyFixup(const llvm::MCAssembler&, const llvm::MCFixup&, const llvm::MCValue&, llvm::MutableArrayRef<char>, uint64_t, bool, const llvm::MCSubtargetInfo*) const: Assertion `Value == 0' failed.
Stack dump:
0. Program arguments: /usr/local/bin/clang-7 -cc1 -triple bpf -emit-obj -mrelax-all -disable-free -main-file-name augmented_raw_syscalls.c -mrelocation-model static -mthread-model posix -mdisable-fp-elim -fmath-errno -masm-verbose -mconstructor-aliases -dwarf-column-info -debugger-tuning=gdb -coverage-notes-file /home/acme/git/perf/-.gcno -nostdsysteminc -nobuiltininc -resource-dir /usr/local/lib/clang/8.0.0 -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -isystem /usr/lib/gcc/x86_64-redhat-linux/7/include -include /home/acme/git/linux/include/linux/kconfig.h -D __KERNEL__ -D __NR_CPUS__=4 -D LINUX_VERSION_CODE=0x41300 -I /home/acme/lib/perf/include/bpf -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 -O0 -Wno-unused-value -Wno-pointer-sign -fdebug-compilation-dir /home/acme/git/perf -ferror-limit 19 -fmessage-length 203 -fobjc-runtime=gcc -fdiagnostics-show-option -fcolor-diagnostics -o - -x c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -faddrsig
1. <eof> parser at end of file
2. Code generation
#0 0x000000000408ff98 llvm::sys::PrintStackTrace(llvm::raw_ostream&) (/usr/local/bin/clang-7+0x408ff98)
#1 0x000000000409002b (/usr/local/bin/clang-7+0x409002b)
#2 0x000000000408e059 llvm::sys::RunSignalHandlers() (/usr/local/bin/clang-7+0x408e059)
#3 0x000000000408fa5b (/usr/local/bin/clang-7+0x408fa5b)
#4 0x00007fcd33ab81c0 __restore_rt (/lib64/libpthread.so.0+0x121c0)
#5 0x00007fcd32817750 __GI_raise (/lib64/libc.so.6+0x34750)
#6 0x00007fcd32818d31 __GI_abort (/lib64/libc.so.6+0x35d31)
#7 0x00007fcd3281005a __assert_fail_base (/lib64/libc.so.6+0x2d05a)
#8 0x00007fcd328100d2 (/lib64/libc.so.6+0x2d0d2)
#9 0x0000000002602d13 (/usr/local/bin/clang-7+0x2602d13)
#10 0x0000000003bf6da7 llvm::MCAssembler::layout(llvm::MCAsmLayout&) (/usr/local/bin/clang-7+0x3bf6da7)
#11 0x0000000003bf6e2c llvm::MCAssembler::Finish() (/usr/local/bin/clang-7+0x3bf6e2c)
#12 0x0000000003c524e8 llvm::MCObjectStreamer::FinishImpl() (/usr/local/bin/clang-7+0x3c524e8)
#13 0x0000000003c2db4b llvm::MCELFStreamer::FinishImpl() (/usr/local/bin/clang-7+0x3c2db4b)
#14 0x0000000003c5ba43 llvm::MCStreamer::Finish() (/usr/local/bin/clang-7+0x3c5ba43)
#15 0x0000000004c281b9 llvm::AsmPrinter::doFinalization(llvm::Module&) (/usr/local/bin/clang-7+0x4c281b9)
#16 0x00000000038d637b llvm::FPPassManager::doFinalization(llvm::Module&) (/usr/local/bin/clang-7+0x38d637b)
#17 0x00000000038d683d (/usr/local/bin/clang-7+0x38d683d)
#18 0x00000000038d6d6b llvm::legacy::PassManagerImpl::run(llvm::Module&) (/usr/local/bin/clang-7+0x38d6d6b)
#19 0x00000000038d6f9b llvm::legacy::PassManager::run(llvm::Module&) (/usr/local/bin/clang-7+0x38d6f9b)
#20 0x000000000436b091 (/usr/local/bin/clang-7+0x436b091)
#21 0x000000000436df07 clang::EmitBackendOutput(clang::DiagnosticsEngine&, clang::HeaderSearchOptions const&, clang::CodeGenOptions const&, clang::TargetOptions const&, clang::LangOptions const&, llvm::DataLayout const&, llvm::Module*, clang::BackendAction, std::unique_ptr<llvm::raw_pwrite_stream, std::default_delete<llvm::raw_pwrite_stream> >) (/usr/local/bin/clang-7+0x436df07)
#22 0x0000000004f6ee11 (/usr/local/bin/clang-7+0x4f6ee11)
#23 0x00000000062af3a3 clang::ParseAST(clang::Sema&, bool, bool) (/usr/local/bin/clang-7+0x62af3a3)
#24 0x0000000004a73873 clang::ASTFrontendAction::ExecuteAction() (/usr/local/bin/clang-7+0x4a73873)
#25 0x0000000004f6ced8 clang::CodeGenAction::ExecuteAction() (/usr/local/bin/clang-7+0x4f6ced8)
#26 0x0000000004a7329d clang::FrontendAction::Execute() (/usr/local/bin/clang-7+0x4a7329d)
#27 0x0000000004a04ccf clang::CompilerInstance::ExecuteAction(clang::FrontendAction&) (/usr/local/bin/clang-7+0x4a04ccf)
#28 0x0000000004bc512e clang::ExecuteCompilerInvocation(clang::CompilerInstance*) (/usr/local/bin/clang-7+0x4bc512e)
#29 0x0000000001d88a6c cc1_main(llvm::ArrayRef<char const*>, char const*, void*) (/usr/local/bin/clang-7+0x1d88a6c)
#30 0x0000000001d7e31e (/usr/local/bin/clang-7+0x1d7e31e)
#31 0x0000000001d7ef94 main (/usr/local/bin/clang-7+0x1d7ef94)
#32 0x00007fcd32803fea __libc_start_main (/lib64/libc.so.6+0x20fea)
#33 0x0000000001d7beea _start (/usr/local/bin/clang-7+0x1d7beea)
clang-7: error: unable to execute command: Aborted (core dumped)
clang-7: error: clang frontend command failed due to signal (use -v to see invocation)
clang version 8.0.0 (http://llvm.org/git/clang.git 8587270a739ee30c926a76d5657e65e85b560f6e) (http://llvm.org/git/llvm.git 0566eefef9c3777bd780ec4cbb9efa764633b76c)
Target: bpf
Thread model: posix
InstalledDir: /usr/local/bin
clang-7: note: diagnostic msg: PLEASE submit a bug report to https://bugs.llvm.org/ and include the crash backtrace, preprocessed source, and associated run script.
clang-7: note: diagnostic msg:
********************PLEASE ATTACH THE FOLLOWING FILES TO THE BUG REPORT:
Preprocessed source(s) and associated run script(s) are located at:
clang-7: note: diagnostic msg: /tmp/augmented_raw_syscalls-7444d9.c
clang-7: note: diagnostic msg: /tmp/augmented_raw_syscalls-7444d9.sh
clang-7: note: diagnostic msg:
********************
ERROR: unable to compile tools/perf/examples/bpf/augmented_raw_syscalls.c
Hint: Check error message shown above.
Hint: You can also pre-compile it into .o using:
clang -target bpf -O2 -c tools/perf/examples/bpf/augmented_raw_syscalls.c
with proper -I and -D options.
event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.c'
\___ Failed to load tools/perf/examples/bpf/augmented_raw_syscalls.c from source: Error when compiling BPF scriptlet
(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
[root@seventh perf]#
Trying with -O1...
Quoted 3 lines
Alternatively, your prog looks short enough that maybe you could kick the C habit and write it directly in eBPF asm, that way no-one is optimising things behind your back. (I realise this option won't appeal to everyone ;-)
Nah, if that is what it takes... Would be better with simple looking C code tho :-)
Quoted 8 lines
The reason the verifier disallows this, iirc, is because it needs to be able to rewrite the offsets on ctx accesses (see
convert_ctx_accesses()) in case underlying kernel struct doesn't match the layout of the ctx ABI. To do this it needs the ctx offset to live entirely in the insn doing the access, otherwise different paths could lead to the same insn accessing different ctx offsets with different fixups needed — can't be done.-Ed
Em Sat, Nov 03, 2018 at 08:29:34AM -0300, Arnaldo Carvalho de Melo escreveu:
Quoted 23 lines
PLEASE ATTACH THE FOLLOWING FILES TO THE BUG REPORT:
Preprocessed source(s) and associated run script(s) are located at:
clang-7: note: diagnostic msg:/tmp/augmented_raw_syscalls-7444d9.c
clang-7: note: diagnostic msg:/tmp/augmented_raw_syscalls-7444d9.sh
clang-7: note: diagnostic msg:********************
ERROR: unable to compiletools/perf/examples/bpf/augmented_raw_syscalls.c
Hint: Check error message shown above.
Hint: You can also pre-compile it into .o using:
clang -target bpf -O2 -ctools/perf/examples/bpf/augmented_raw_syscalls.c
with proper -I and -D options.
event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.c'
\___ Failed to loadtools/perf/examples/bpf/augmented_raw_syscalls.cfrom source: Error when compiling BPF scriptlet(add -v to see detail)
Run 'perf list' for a list of valid eventsUsage: perf trace [<options>] [<command>]
or: perf trace [<options>] -- <command> [<options>]
or: perf trace record [<options>] [<command>]
or: perf trace record [<options>] -- <command> [<options>]
Quoted 4 lines
-e, --event <event> event/syscall selector. use 'perf list' to list available events
[root@seventh perf]#Trying with -O1...
-O1 doesn't get clang confused, its just the verifier that doesn't like the result, i.e. we're back to that optimization, that isn't disabled with -O1
llvm compiling command : /usr/local/bin/clang -D__KERNEL__ -D__NR_CPUS__=4 -DLINUX_VERSION_CODE=0x41300 -I/home/acme/lib/perf/include/bpf -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 -Wno-unused-value -Wno-pointer-sign -working-directory /lib/modules/4.19.0-rc8-00014-gc0cff31be705/build -c /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.c -target bpf -O1 -o -
libbpf: loading object 'tools/perf/examples/bpf/augmented_raw_syscalls.c' from buffer
libbpf: section(1) .strtab, size 168, link 0, flags 0, type=3
libbpf: skip section(1) .strtab
libbpf: section(2) .text, size 0, link 0, flags 6, type=1
libbpf: skip section(2) .text
libbpf: section(3) raw_syscalls:sys_enter, size 344, link 0, flags 6, type=1
libbpf: found program raw_syscalls:sys_enter
libbpf: section(4) .relraw_syscalls:sys_enter, size 16, link 10, flags 0, type=9
libbpf: section(5) raw_syscalls:sys_exit, size 16, link 0, flags 6, type=1
libbpf: found program raw_syscalls:sys_exit
libbpf: section(6) maps, size 56, link 0, flags 3, type=1
libbpf: section(7) license, size 4, link 0, flags 3, type=1
libbpf: license of tools/perf/examples/bpf/augmented_raw_syscalls.c is GPL
libbpf: section(8) version, size 4, link 0, flags 3, type=1
libbpf: kernel version of tools/perf/examples/bpf/augmented_raw_syscalls.c is 41300
libbpf: section(9) .llvm_addrsig, size 6, link 10, flags 80000000, type=1879002115
libbpf: skip section(9) .llvm_addrsig
libbpf: section(10) .symtab, size 240, link 1, flags 0, type=2
libbpf: maps in tools/perf/examples/bpf/augmented_raw_syscalls.c: 2 maps in 56 bytes
libbpf: map 0 is "__augmented_syscalls__"
libbpf: map 1 is "__bpf_stdout__"
libbpf: collecting relocating info for: 'raw_syscalls:sys_enter'
libbpf: relo for 4 value 28 name 124
libbpf: relocation: insn_idx=35
libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 35
Added extra kernel map __entry_SYSCALL_64_trampoline fffffe0000006000-fffffe0000007000
Added extra kernel map __entry_SYSCALL_64_trampoline fffffe0000032000-fffffe0000033000
Added extra kernel map __entry_SYSCALL_64_trampoline fffffe000005e000-fffffe000005f000
Added extra kernel map __entry_SYSCALL_64_trampoline fffffe000008a000-fffffe000008b000
bpf: config program 'raw_syscalls:sys_enter'
bpf: config program 'raw_syscalls:sys_exit'
libbpf: create map __bpf_stdout__: fd=3
libbpf: create map __augmented_syscalls__: fd=4
libbpf: load bpf program failed: Permission denied
libbpf: -- BEGIN DUMP LOG ---
libbpf:
0: (bf) r6 = r1
1: (bf) r1 = r10
2: (07) r1 += -328
3: (b7) r7 = 64
4: (b7) r2 = 64
5: (bf) r3 = r6
6: (85) call bpf_probe_read#4
7: (79) r1 = *(u64 *)(r10 -320)
8: (15) if r1 == 0x101 goto pc+4
R0=inv(id=0) R1=inv(id=0) R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
9: (55) if r1 != 0x2 goto pc+22
R0=inv(id=0) R1=inv2 R6=ctx(id=0,off=0,imm=0) R7=inv64 R10=fp0,call_-1
10: (bf) r1 = r6
11: (07) r1 += 16
12: (05) goto pc+2
15: (79) r3 = *(u64 *)(r1 +0)
dereference of modified ctx ptr R1 off=16 disallowed
libbpf: -- END LOG --
libbpf: failed to load program 'raw_syscalls:sys_enter'
libbpf: failed to load object 'tools/perf/examples/bpf/augmented_raw_syscalls.c'
bpf: load objects failed: err=-4007: (Kernel verifier blocks program loading) event syntax error: 'tools/perf/examples/bpf/augmented_raw_syscalls.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
[root@seventh perf]#