Re: perf test LLVM & clang 6 failing

From: Arnaldo Carvalho de Melo
Date: Mon Nov 27 2017 - 14:34:35 EST


Em Mon, Nov 27, 2017 at 11:11:56AM -0800, Yonghong Song escreveu:
> On 11/27/17 9:04 AM, Arnaldo Carvalho de Melo wrote:
> > Em Fri, Nov 24, 2017 at 04:16:52PM +0100, Daniel Borkmann escreveu:
> > > [ +Yonghong ]
> >
> > + Josh
> > > On 11/24/2017 03:47 PM, Arnaldo Carvalho de Melo wrote:
> > > > FYI, just noticed, recently updated clang to version 6, from its
> > > > upstream git repo.
> > >
> > > Do you recall what was your LLVM version prior to this where it was
> > > working fine? (Wild guess from below would be the BPF inline asm
> > > support that was added recently to LLVM (2865ab6996) vs asm() used
> > > in headers included in the stdin header causing trouble due to arch
> > > mixup?)
> >
> > So, if I go to the cset just before:
> >
> > commit f5caf621ee357279e759c0911daf6d55c7d36f03
> > Author: Josh Poimboeuf <jpoimboe@xxxxxxxxxx>
> > Date: Wed Sep 20 16:24:33 2017 -0500
> >
> > x86/asm: Fix inline asm call constraints for Clang
> > ---
> >
> > 'perf test LLVM' works again:
> >
> > [root@jouet ~]# perf test LLVM
> > 37: LLVM search and compile :
> > 37.1: Basic BPF llvm compile : Ok
> > 37.2: kbuild searching : Ok
> > 37.3: Compile source for BPF prologue generation : Ok
> > 37.4: Compile source for BPF relocation : Ok
> > [root@jouet ~]#
> >
> > I.e. 'perf test LLVM' built from what is in my acme/perf/urgent branch,
> > targetted to v4.15, uses kernel headers and if I go to just before
> > f5caf621ee, it works again, both with clang from fedora26 (4.0.1) and
> > with 6.0, built from sources.
>
> This patch introduced a module level inline assembly.
>
> ...
> --- a/arch/x86/include/asm/asm.h
> +++ b/arch/x86/include/asm/asm.h
> @@ -132,4 +132,15 @@
> /* For C file, we already have NOKPROBE_SYMBOL macro */
> #endif
>
> +#ifndef __ASSEMBLY__
> +/*
> + * This output constraint should be used for any inline asm which has a
> "call"
> + * instruction. Otherwise the asm may be inserted before the frame pointer
> + * gets set up by the containing function. If you forget to do this,
> objtool
> + * may print a "call without frame pointer save/setup" warning.
> + */
> +register unsigned int __asm_call_sp asm("esp");
> +#define ASM_CALL_CONSTRAINT "+r" (__asm_call_sp)
> +#endif
> ...
>
> This will cause "clang ... -target bpf ..." failure since 4.0 does not have
> bpf inline asm support and 6.0 does not recognize the register 'esp'.

Ok, explains the problem then, Josh, ideas on how to proceed here?

> > 'perf test BPF' breaks for another reason, needs another investigation,
> > maybe you guys can spot something changed recently in that area:
> >
> > libbpf: failed to create map (name: 'flip_table'): Invalid argument
> > libbpf: failed to load object '[basic_bpf_test]'


So, I noticed that any maps are failing, I'll go dig, but may be some
new security tightening, even running as root, this was working
recently, was even part of our discussion on the bpf_probe_read_str()
trouble with clang's optimizer:

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

SEC("prog=do_sys_open filename")
int prog(void *ctx, int err, char *filename_ptr)
{
char filename[128];
int len = bpf_probe_read_str(filename, sizeof(filename), filename_ptr);
if (len > 0) {
if (len == 1)
perf_event_output(ctx, &__bpf_stdout__, BPF_F_CURRENT_CPU, filename, len);
else if (len < 128)
perf_event_output(ctx, &__bpf_stdout__, BPF_F_CURRENT_CPU, filename, len);
}
return 1;
}
[root@jouet bpf]#
<SNIP>
Found 1 probe_trace_events.
Opening /sys/kernel/debug/tracing//kprobe_events write=1
Writing event: p:perf_bpf_probe/prog _text+2493856 filename=%si:x64
In map_prologue, ntevs=1
mapping[0]=0
libbpf: failed to create map (name: '__bpf_stdout__'): Invalid argument
libbpf: failed to load object 'open.c'
bpf: load objects failed
event syntax error: 'open.c'
\___ Operation not permitted
<SNIP>

Using 'perf ftrace' to trace just 'perf trace':

[root@jouet bpf]# perf ftrace -G SyS_bpf perf trace -v -e open.c,open cat /tmp/somefile 2> /dev/null
0) | SyS_bpf() {
0) | capable() {
0) | ns_capable_common() {
0) | security_capable() {
0) 0.045 us | cap_capable();
0) | selinux_capable() {
0) 0.274 us | cred_has_capability();
0) 0.518 us | }
0) 1.464 us | }
0) 1.783 us | }
0) 2.130 us | }
0) 0.458 us | check_uarg_tail_zero();
0) | __check_object_size() {
0) 0.046 us | __virt_addr_valid();
0) 0.040 us | check_stack_object();
0) 0.510 us | }
0) 4.161 us | }
[root@jouet bpf]#

/me goes to look at SyS_bpf() in this kernel... (4.14.0+).

- Arnaldo


> Not sure whether this is the root cause or not, but the below section name
> SEC("func=SyS_epoll_wait")
> is not a good one.
> If it is used to represent the program name in the kernel, the kernel will
> reject it with invalid argument since it contains "=".

I forgot the details about this one, but this has been working like that
for quite a while, I'll check if something new happened here...

> >
> > Complete logs up to this error are below, I'll go read Yonghong message
> > to see if I can get the 'perf test LLVM' case fixed.
> >
> > - Arnaldo
> >
> > [root@jouet ~]# perf test BPF
> > 39: BPF filter :
> > 39.1: Basic BPF filtering : FAILED!
> > 39.2: BPF pinning : Skip
> > 39.3: BPF prologue generation : Skip
> > 39.4: BPF relocation checker : Skip
> > [root@jouet ~]# perf test -v BPF
> > 39: BPF filter :
> > 39.1: Basic BPF filtering :
> > --- start ---
> > test child forked, pid 3541
> > 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/lib64/ccache/clang
> > set env: CLANG_OPTIONS=-xc
> > 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=-
> > llvm compiling command template: echo '/*
> > * bpf-script-example.c
> > * Test basic LLVM building
> > */
> > #ifndef LINUX_VERSION_CODE
> > # error Need LINUX_VERSION_CODE
> > # error Example: for 4.2 kernel, put 'clang-opt="-DLINUX_VERSION_CODE=0x40200" into llvm section of ~/.perfconfig'
> > #endif
> > #define BPF_ANY 0
> > #define BPF_MAP_TYPE_ARRAY 2
> > #define BPF_FUNC_map_lookup_elem 1
> > #define BPF_FUNC_map_update_elem 2
> >
> > static void *(*bpf_map_lookup_elem)(void *map, void *key) =
> > (void *) BPF_FUNC_map_lookup_elem;
> > static void *(*bpf_map_update_elem)(void *map, void *key, void *value, int flags) =
> > (void *) BPF_FUNC_map_update_elem;
> >
> > struct bpf_map_def {
> > unsigned int type;
> > unsigned int key_size;
> > unsigned int value_size;
> > unsigned int max_entries;
> > };
> >
> > #define SEC(NAME) __attribute__((section(NAME), used))
> > struct bpf_map_def SEC("maps") flip_table = {
> > .type = BPF_MAP_TYPE_ARRAY,
> > .key_size = sizeof(int),
> > .value_size = sizeof(int),
> > .max_entries = 1,
> > };
> >
> > SEC("func=SyS_epoll_wait")
> > int bpf_func__SyS_epoll_wait(void *ctx)
> > {
> > int ind =0;
> > int *flag = bpf_map_lookup_elem(&flip_table, &ind);
> > int new_flag;
> > if (!flag)
> > return 0;
> > /* flip flag and store back */
> > new_flag = !*flag;
> > bpf_map_update_elem(&flip_table, &ind, &new_flag, BPF_ANY);
> > return new_flag;
> > }
> > char _license[] SEC("license") = "GPL";
> > int _version SEC("version") = LINUX_VERSION_CODE;
> > ' | $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 '[basic_bpf_test]' from buffer
> > libbpf: section .strtab, size 120, link 0, flags 0, type=3
> > libbpf: section .text, size 0, link 0, flags 6, type=1
> > libbpf: section func=SyS_epoll_wait, size 200, link 0, flags 6, type=1
> > libbpf: found program func=SyS_epoll_wait
> > libbpf: section .relfunc=SyS_epoll_wait, size 32, 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 [basic_bpf_test] is GPL
> > libbpf: section version, size 4, link 0, flags 3, type=1
> > libbpf: kernel version of [basic_bpf_test] is 40e00
> > libbpf: section .symtab, size 168, link 1, flags 0, type=2
> > libbpf: maps in [basic_bpf_test]: 1 maps in 16 bytes
> > libbpf: map 0 is "flip_table"
> > libbpf: collecting relocating info for: 'func=SyS_epoll_wait'
> > libbpf: relocation: insn_idx=4
> > libbpf: relocation: find map 0 (flip_table) for insn 4
> > libbpf: relocation: insn_idx=18
> > libbpf: relocation: find map 0 (flip_table) for insn 18
> > bpf: config program 'func=SyS_epoll_wait'
> > symbol:SyS_epoll_wait file:(null) line:0 offset:0 return:0 lazy:(null)
> > bpf: config 'func=SyS_epoll_wait' is ok
> > 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: SyS_epoll_wait [2e5a9be]
> > found inline addr: 0xffffffff812af256
> > Probe point found: compat_SyS_epoll_pwait+150
> > found inline addr: 0xffffffff812af037
> > Probe point found: SyS_epoll_pwait+135
> > found inline addr: 0xffffffff812aeed0
> > Probe point found: SyS_epoll_wait+0
> > Found 3 probe_trace_events.
> > Opening /sys/kernel/debug/tracing//kprobe_events write=1
> > Writing event: p:perf_bpf_probe/func _text+2814550
> > Writing event: p:perf_bpf_probe/func_1 _text+2814007
> > Writing event: p:perf_bpf_probe/func_2 _text+2813648
> > libbpf: failed to create map (name: 'flip_table'): Invalid argument
> > libbpf: failed to load object '[basic_bpf_test]'
> > bpf: load objects failed
> > Failed to add events selected by BPF
> >