[root@jouet ~]# trace -e /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o event syntax error: '/wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o' \___ Operation not permitted (add -v to see detail) Run 'perf list' for a list of valid events Usage: perf trace [] [] or: perf trace [] -- [] or: perf trace record [] [] or: perf trace record [] -- [] -e, --event event/syscall selector. use 'perf list' to list available events # Bump verbosity level to see where it fails: [root@jouet ~]# trace -v -e /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o libbpf: loading /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o libbpf: section(1) .strtab, size 834, 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) syscalls:sys_enter_openat, size 560, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_openat libbpf: section(4) .relsyscalls:sys_enter_openat, size 16, link 28, flags 0, type=9 libbpf: section(5) syscalls:sys_exit_openat, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_openat libbpf: section(6) syscalls:sys_enter_open, size 552, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_open libbpf: section(7) .relsyscalls:sys_enter_open, size 16, link 28, flags 0, type=9 libbpf: section(8) syscalls:sys_exit_open, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_open libbpf: section(9) syscalls:sys_enter_inotify_add_watch, size 552, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_inotify_add_watch libbpf: section(10) .relsyscalls:sys_enter_inotify_add_watch, size 16, link 28, flags 0, type=9 libbpf: section(11) syscalls:sys_exit_inotify_add_watch, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_inotify_add_watch libbpf: section(12) syscalls:sys_enter_newstat, size 544, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_newstat libbpf: section(13) .relsyscalls:sys_enter_newstat, size 16, link 28, flags 0, type=9 libbpf: section(14) syscalls:sys_exit_newstat, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_newstat libbpf: section(15) syscalls:sys_enter_bind, size 176, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_bind libbpf: section(16) .relsyscalls:sys_enter_bind, size 16, link 28, flags 0, type=9 libbpf: section(17) syscalls:sys_exit_bind, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_bind libbpf: section(18) syscalls:sys_enter_connect, size 176, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_connect libbpf: section(19) .relsyscalls:sys_enter_connect, size 16, link 28, flags 0, type=9 libbpf: section(20) syscalls:sys_exit_connect, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_connect libbpf: section(21) syscalls:sys_enter_sendto, size 176, link 0, flags 6, type=1 libbpf: found program syscalls:sys_enter_sendto libbpf: section(22) .relsyscalls:sys_enter_sendto, size 16, link 28, flags 0, type=9 libbpf: section(23) syscalls:sys_exit_sendto, size 16, link 0, flags 6, type=1 libbpf: found program syscalls:sys_exit_sendto libbpf: section(24) maps, size 56, link 0, flags 3, type=1 libbpf: section(25) license, size 4, link 0, flags 3, type=1 libbpf: license of /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o is GPL libbpf: section(26) version, size 4, link 0, flags 3, type=1 libbpf: kernel version of /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o is 41300 libbpf: section(27) .llvm_addrsig, size 18, link 28, flags 80000000, type=1879002115 libbpf: skip section(27) .llvm_addrsig libbpf: section(28) .symtab, size 552, link 1, flags 0, type=2 libbpf: maps in /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o: 2 maps in 56 bytes libbpf: map 0 is "__augmented_syscalls__" libbpf: map 1 is "__bpf_stdout__" libbpf: collecting relocating info for: 'syscalls:sys_enter_openat' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=63 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 63 libbpf: collecting relocating info for: 'syscalls:sys_enter_open' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=62 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 62 libbpf: collecting relocating info for: 'syscalls:sys_enter_inotify_add_watch' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=62 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 62 libbpf: collecting relocating info for: 'syscalls:sys_enter_newstat' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=61 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 61 libbpf: collecting relocating info for: 'syscalls:sys_enter_bind' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=13 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 13 libbpf: collecting relocating info for: 'syscalls:sys_enter_connect' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=13 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 13 libbpf: collecting relocating info for: 'syscalls:sys_enter_sendto' libbpf: relo for 5 value 28 name 783 libbpf: relocation: insn_idx=13 libbpf: relocation: find map 1 (__augmented_syscalls__) for insn 13 bpf: config program 'syscalls:sys_enter_openat' bpf: config program 'syscalls:sys_exit_openat' bpf: config program 'syscalls:sys_enter_open' bpf: config program 'syscalls:sys_exit_open' bpf: config program 'syscalls:sys_enter_inotify_add_watch' bpf: config program 'syscalls:sys_exit_inotify_add_watch' bpf: config program 'syscalls:sys_enter_newstat' bpf: config program 'syscalls:sys_exit_newstat' bpf: config program 'syscalls:sys_enter_bind' bpf: config program 'syscalls:sys_exit_bind' bpf: config program 'syscalls:sys_enter_connect' bpf: config program 'syscalls:sys_exit_connect' bpf: config program 'syscalls:sys_enter_sendto' bpf: config program 'syscalls:sys_exit_sendto' libbpf: failed to create map (name: '__bpf_stdout__'): Operation not permitted libbpf: failed to load object '/wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o' bpf: load objects failed: err=-1: (Operation not permitted) event syntax error: '/wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o' \___ Operation not permitted (add -v to see detail) Run 'perf list' for a list of valid events Usage: perf trace [] [] or: perf trace [] -- [] or: perf trace record [] [] or: perf trace record [] -- [] -e, --event event/syscall selector. use 'perf list' to list available events [root@jouet ~]# EPERM when creating a map? It used to work, lets see inside the kernel: # perf ftrace -G "*bpf*" perf trace -v -e /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o 0) | __x64_sys_bpf() { 0) 0.065 us | bpf_check_uarg_tail_zero(); 0) | __check_object_size() { 0) 0.073 us | __virt_addr_valid(); 0) 0.071 us | check_stack_object(); 0) 1.581 us | } 0) | security_bpf() { 0) | selinux_bpf() { 0) 0.244 us | avc_has_perm(); 0) 0.688 us | } 0) 1.313 us | } 0) | map_create() { 0) | fd_array_map_alloc_check() { 0) 0.092 us | array_map_alloc_check(); 0) 0.606 us | } 0) | array_map_alloc() { 0) | capable() { 0) | ns_capable_common() { 0) | security_capable() { 0) 0.100 us | cap_capable(); 0) | selinux_capable() { 0) 0.371 us | cred_has_capability(); 0) 0.831 us | } 0) 2.137 us | } 0) 2.670 us | } 0) 3.133 us | } 0) | bpf_map_precharge_memlock() { 0) 0.101 us | free_uid(); 0) 0.675 us | } 0) 4.781 us | } 0) 6.788 us | } 0) + 12.176 us | } int bpf_map_precharge_memlock(u32 pages) { struct user_struct *user = get_current_user(); unsigned long memlock_limit, cur; memlock_limit = rlimit(RLIMIT_MEMLOCK) >> PAGE_SHIFT; cur = atomic_long_read(&user->locked_vm); free_uid(user); if (cur + pages > memlock_limit) return -EPERM; return 0; } So its about memory limits, lets try bumping that: [root@jouet ~]# ulimit -a | grep locked max locked memory (kbytes, -l) 64 [root@jouet ~]# ulimit -l 128 [root@jouet ~]# ulimit -a | grep locked max locked memory (kbytes, -l) 128 [root@jouet ~]# Not even with 2048 :-\ Ok, works with 4096: [root@jouet ~]# ulimit -l 4096 [root@jouet ~]# [root@jouet ~]# perf trace -e /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o 0.000 ( 0.038 ms): weechat/9489 stat(filename: /etc/localtime, statbuf: 0x7fff87394be0) = 0 0.096 ( ): perf/12819 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_stat/format) ... 0.140 ( ): perf/12819 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_newstat/format) ... 0.396 ( ): perf/12819 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_openat/format) ... 1000.561 ( 0.067 ms): weechat/9489 stat(filename: /etc/localtime, statbuf: 0x7fff87394be0) = 0 2000.087 ( 0.104 ms): weechat/9489 stat(filename: /etc/localtime, statbuf: 0x7fff87394be0) = 0 2195.367 ( 0.049 ms): gmain/2436 inotify_add_watch(fd: 7, pathname: /home/acme/~, mask: 16789454) = -1 ENOENT No such file or directory 2195.542 ( ): perf/12819 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_inotify_add_watch/format) ... 2255.317 ( 0.055 ms): gmain/2923 inotify_add_watch(fd: 4, pathname: /var/lib/fwupd/remotes.d/lvfs-testing, mask: 16789454) = -1 ENOENT No such file or directory 2309.461 ( 0.049 ms): gmain/1670 inotify_add_watch(fd: 3, pathname: /var/lib/gdm/~, mask: 16789454) = -1 ENOENT No such file or directory ^C[root@jouet ~]# And that happened because I forgot a 'perf top' running, so used part of that "locked mem" rlimit. ^C[root@jouet ~]# ulimit -l 64 [root@jouet ~]# perf trace -e /wb/bpf/4.19.0-rc4-00022-gad3273d5f1b9/augmented_syscalls.o 0.000 ( 0.097 ms): tmux: server/4058 stat(filename: /etc/localtime, statbuf: 0x7ffeba23b1a0 ) = 0 0.307 ( 0.019 ms): tmux: server/4058 stat(filename: /etc/localtime, statbuf: 0x7ffeba23b1a0 ) = 0 0.550 ( 0.019 ms): tmux: server/4058 stat(filename: /etc/localtime, statbuf: 0x7ffeba23b1a0 ) = 0 0.170 ( ): perf/12826 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_stat/format) ... 0.261 ( ): perf/12826 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_newstat/format) ... 1.021 ( ): perf/12826 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_openat/format) ... 155.823 ( 0.059 ms): weechat/9489 stat(filename: /etc/localtime, statbuf: 0x7fff87394be0 ) = 0 351.128 ( 0.055 ms): gmain/2436 inotify_add_watch(fd: 7, pathname: /home/acme/~, mask: 16789454) = -1 ENOENT No such file or directory 351.259 ( ): perf/12826 openat(dfd: CWD, filename: /sys/kernel/debug/tracing//events/syscalls/sys_enter_inotify_add_watch/format) ... 410.658 ( 0.053 ms): gmain/2923 inotify_add_watch(fd: 4, pathname: /var/lib/fwupd/remotes.d/lvfs-testing, mask: 16789454) = -1 ENOENT No such file or directory 465.071 ( 0.215 ms): gmain/1670 inotify_add_watch(fd: 3, pathname: /var/lib/gdm/~, mask: 16789454) = -1 ENOENT No such file or directory ^C[root@jouet ~]# So its just a matter of trying to improve that error message to say something about 'ulimit -l'...