On Tue, Apr 28, 2020 at 3:33 AM Mikko Ylinen
<mikko.ylinen@xxxxxxxxxxxxxxx> wrote:
>
> Hi,
>
> I'm testing BPF LSM and wanted to verify my setup by running the
> test_lsm selftests (./test_progs -vv -t test_lsm) but it fails:
>
> libbpf: loading object 'lsm' from buffer
> libbpf: section(1) .strtab, size 306, 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) lsm/file_mprotect, size 192, link 0, flags 6, type=1
> libbpf: found program lsm/file_mprotect
> libbpf: section(4) .rellsm/file_mprotect, size 32, link 25, flags 0, type=9
> libbpf: section(5) lsm/bprm_committed_creds, size 104, link 0, flags 6,
> type=1
> libbpf: found program lsm/bprm_committed_creds
> libbpf: section(6) .rellsm/bprm_committed_creds, size 32, link 25, flags
> 0, type=9
> libbpf: section(7) license, size 4, link 0, flags 3, type=1
> libbpf: license of lsm is GPL
> libbpf: section(8) .bss, size 12, link 0, flags 3, type=8
> libbpf: section(9) .debug_str, size 133448, link 0, flags 30, type=1
> libbpf: skip section(9) .debug_str
> libbpf: section(10) .debug_loc, size 428, link 0, flags 0, type=1
> libbpf: skip section(10) .debug_loc
> libbpf: section(11) .rel.debug_loc, size 112, link 25, flags 0, type=9
> libbpf: skip relo .rel.debug_loc(11) for section(10)
> libbpf: section(12) .debug_abbrev, size 901, link 0, flags 0, type=1
> libbpf: skip section(12) .debug_abbrev
> libbpf: section(13) .debug_info, size 223699, link 0, flags 0, type=1
> libbpf: skip section(13) .debug_info
> libbpf: section(14) .rel.debug_info, size 112, link 25, flags 0, type=9
> libbpf: skip relo .rel.debug_info(14) for section(13)
> libbpf: section(15) .debug_ranges, size 96, link 0, flags 0, type=1
> libbpf: skip section(15) .debug_ranges
> libbpf: section(16) .rel.debug_ranges, size 128, link 25, flags 0, type=9
> libbpf: skip relo .rel.debug_ranges(16) for section(15)
> libbpf: section(17) .BTF, size 5421, link 0, flags 0, type=1
> libbpf: section(18) .rel.BTF, size 64, link 25, flags 0, type=9
> libbpf: skip relo .rel.BTF(18) for section(17)
> libbpf: section(19) .BTF.ext, size 484, link 0, flags 0, type=1
> libbpf: section(20) .rel.BTF.ext, size 416, link 25, flags 0, type=9
> libbpf: skip relo .rel.BTF.ext(20) for section(19)
> libbpf: section(21) .debug_frame, size 64, link 0, flags 0, type=1
> libbpf: skip section(21) .debug_frame
> libbpf: section(22) .rel.debug_frame, size 32, link 25, flags 0, type=9
> libbpf: skip relo .rel.debug_frame(22) for section(21)
> libbpf: section(23) .debug_line, size 227, link 0, flags 0, type=1
> libbpf: skip section(23) .debug_line
> libbpf: section(24) .rel.debug_line, size 32, link 25, flags 0, type=9
> libbpf: skip relo .rel.debug_line(24) for section(23)
> libbpf: section(25) .symtab, size 288, link 1, flags 0, type=2
> libbpf: looking for externs among 12 symbols...
> libbpf: collected 0 externs total
> libbpf: map 'lsm.bss' (global data): at sec_idx 8, offset 0, flags 400.
> libbpf: map 0 is "lsm.bss"
> libbpf: collecting relocating info for: 'lsm/file_mprotect'
> libbpf: relo for shdr 8, symb 8, value 0, type 1, bind 1, name 232
> ('monitored_pid'), insn 12
> libbpf: found data map 0 (lsm.bss, sec 8, off 0) for insn 12
> libbpf: relo for shdr 8, symb 9, value 4, type 1, bind 1, name 34
> ('mprotect_count'), insn 17
> libbpf: found data map 0 (lsm.bss, sec 8, off 0) for insn 17
> libbpf: collecting relocating info for: 'lsm/bprm_committed_creds'
> libbpf: relo for shdr 8, symb 8, value 0, type 1, bind 1, name 232
> ('monitored_pid'), insn 1
> libbpf: found data map 0 (lsm.bss, sec 8, off 0) for insn 1
> libbpf: relo for shdr 8, symb 7, value 8, type 1, bind 1, name 49
> ('bprm_count'), insn 6
> libbpf: found data map 0 (lsm.bss, sec 8, off 0) for insn 6
> libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
> libbpf: created map lsm.bss: fd=4
> libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
> libbpf: prog 'lsm/file_mprotect': performing 4 CO-RE offset relocs
> libbpf: prog 'lsm/file_mprotect': relo #0: kind 0, spec is [6]
> vm_area_struct + 0:6 => 64.0 @ &x[0].vm_mm
> libbpf: [6] vm_area_struct: found candidate [465] vm_area_struct
> libbpf: prog 'lsm/file_mprotect': relo #0: matching candidate #0
> vm_area_struct against spec [465] vm_area_struct + 0:6 => 64.0 @
> &x[0].vm_mm: 1
> libbpf: prog 'lsm/file_mprotect': relo #0: patched insn #5 (LDX/ST/STX)
> off 64 -> 64
> libbpf: prog 'lsm/file_mprotect': relo #1: kind 0, spec is [31]
> mm_struct + 0:0:35 => 304.0 @ &x[0].start_stack
> libbpf: [31] mm_struct: found candidate [260] mm_struct
> libbpf: prog 'lsm/file_mprotect': relo #1: matching candidate #0
> mm_struct against spec [260] mm_struct + 0:0:35 => 304.0 @
> &x[0].start_stack: 1
> libbpf: prog 'lsm/file_mprotect': relo #1: patched insn #7 (LDX/ST/STX)
> off 304 -> 304
> libbpf: prog 'lsm/file_mprotect': relo #2: kind 0, spec is [6]
> vm_area_struct + 0:0 => 0.0 @ &x[0].vm_start
> libbpf: prog 'lsm/file_mprotect': relo #2: matching candidate #0
> vm_area_struct against spec [465] vm_area_struct + 0:0 => 0.0 @
> &x[0].vm_start: 1
> libbpf: prog 'lsm/file_mprotect': relo #2: patched insn #8 (LDX/ST/STX)
> off 0 -> 0
> libbpf: prog 'lsm/file_mprotect': relo #3: kind 0, spec is [6]
> vm_area_struct + 0:1 => 8.0 @ &x[0].vm_end
> libbpf: prog 'lsm/file_mprotect': relo #3: matching candidate #0
> vm_area_struct against spec [465] vm_area_struct + 0:1 => 8.0 @
> &x[0].vm_end: 1
> libbpf: prog 'lsm/file_mprotect': relo #3: patched insn #10 (LDX/ST/STX)
> off 8 -> 8
> test_test_lsm:PASS:skel_load 0 nsec
> libbpf: program 'lsm/file_mprotect': failed to attach: Device or
> resource busy
> libbpf: failed to auto-attach program 'test_int_hook': -16
> test_test_lsm:FAIL:attach lsm attach failed: -16
> #70 test_lsm:FAIL
> Summary: 0/0 PASSED, 0 SKIPPED, 1 FAILED
>
> I get -EBUSY with fentry_fexit test too:
-EBUSY in fentry/fexit kernel code most probably means that there is
either extension program (freplace) installed for that target program
or that same program is already attached through previous fentry/fexit
attachment. See code in bpf_trampoline_link_prog(). If you can, can
you please add a bunch of printk() statements in corresponding error
handling code paths to figure out which one it is?
Also, I wonder if this happens right after you restart your kernel/OS?
Is it happening deterministically or just from time to time?
>
> # ./test_progs -t fentry_fexit
> test_fentry_fexit:PASS:fentry_skel_load 0 nsec
> test_fentry_fexit:PASS:fexit_skel_load 0 nsec
> libbpf: program 'fentry/bpf_fentry_test1': failed to attach: Device or
> resource busy
> libbpf: failed to auto-attach program 'test1': -16
> test_fentry_fexit:FAIL:fentry_attach fentry attach failed: -16
> #13 fentry_fexit:FAIL
> Summary: 0/0 PASSED, 0 SKIPPED, 1 FAILED
>
> However, btf_dump is OK:
>
> # ./test_progs -t btf_dump
> #5/1 btf_dump: syntax:OK
> #5/2 btf_dump: ordering:OK
> #5/3 btf_dump: padding:OK
> #5/4 btf_dump: packing:OK
> #5/5 btf_dump: bitfields:OK
> #5/6 btf_dump: multidim:OK
> #5/7 btf_dump: namespacing:OK
> #5 btf_dump:OK
> Summary: 1/7 PASSED, 0 SKIPPED, 0 FAILED
>
btf_dump is completely irrelevant test here, it tests libbpf's BTF
dumping capabilities and doesn't touch anything in kernel, so this
doesn't give any extra hint, unfortunately.
> Any feedback what to check? I don't have any other tests
> running in parallel.
After this test fails, run `sudo bpftool prog show` and `sudo bpftool
link show`, see if there is anything suspicious. bpftool link show is
available with latest master in bpf-next tree, so you'd have to
rebuild your kernel. If nothing catches your eye and helps resolve
this, please post output here as well.
>
> # clang --version
> clang version 10.0.0
> Target: x86_64-generic-linux
> Thread model: posix
> InstalledDir: /usr/bin
> # pahole --version
> v1.16
>
> 5.7-rc3
>
> -- Regards, Mikko
