Re: [BUG] perf trace: failed to load -E2BIG

[Arnaldo Carvalho de Melo <acme@kernel.org>]

On Fri, Dec 06, 2024 at 12:23:09PM -0800, Namhyung Kim wrote:
> Cc-ing bpf list.
 
> On Fri, Dec 06, 2024 at 11:03:19AM -0800, Howard Chu wrote:
> > Forgot to mention clang-13 gave unbounded memory access too:

> > ffffffff,var_off=(0x0; 0xffffffff))
> > R9=scalar(id=14,smin=umin=umin32=2,smax=umax=0xffffffff,var_off=(0x0;
> > 0xffffffff))
> > 90: (85) call bpf_probe_read_user#112
> > R2 unbounded memory access, use 'var &= const' or 'if (var < const)'
> > processed 490 insns (limit 1000000) max_states_per_insn 2 total_states
> > 23 peak_states 23 mark_read 15
> > -- END PROG LOAD LOG --
> > libbpf: prog 'sys_enter': failed to load: -13
> > libbpf: failed to load object 'augmented_raw_syscalls_bpf'
> > libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -13
> > libbpf: map '__augmented_syscalls__': can't use BPF map without FD
> > (was it created?)
> > libbpf: map '__augmented_syscalls__': can't use BPF map without FD
> > (was it created?)
> > libbpf: map '__augmented_syscalls__': can't use BPF map without FD
> > (was it created?)
> > libbpf: map '__augmented_syscalls__': can't use BPF map without FD
> > (was it created?)
> > Not enough memory to run!

> > Kernel:

> > perf $ uname -r
> > 6.11.0-061100-generic
> > On Fri, Dec 6, 2024 at 10:36 AM Howard Chu <howardchu95@gmail.com> wrote:

> > > Apologies. I observed the same issue and tested perf with trace BPF
> > > skel generated by clang-13 to clang-18, turns out BPF skelw generated
> > > by clang version <= clang-16 are not loadable, with clang-15 and -16
> > > showing the same error as yours. Additionally, the BPF verifier is
> > > running longer than usual to process the instructions.


Some more datapoints, here it is working, below you'll see a 'perf
trace' session tracing bpf syscalls (that use libbpf btf pretty printing
routines, that has to be improved) emitted by a 'perf trace' session
augmenting open* syscalls (i.e. using BPF to get the syscall pointer
args, namely pathnames), and here is the environment:

⬢ [acme@toolbox perf-tools-next]$ rpm -q clang
clang-18.1.8-1.fc40.x86_64
root@number:~# uname -a
Linux number 6.13.0-rc2 #1 SMP PREEMPT_DYNAMIC Mon Dec  9 12:33:35 -03 2024 x86_64 GNU/Linux
root@number:~# 

root@number:~# perf trace -e bpf --max-events=3 perf trace -e open* -a sleep 0.0001 |& head 
     0.000 ( 0.005 ms): :3117755/3117755 bpf(cmd: 36, uattr: (union bpf_attr){.batch = (struct){.in_batch = (__u64)42949672960,.out_batch = (__u64)18446744073709551448,.keys = (__u64)2,.values = (__u64)801012880,.elem_flags = (__u64)140154830285504,.flags = (__u64)11424,},(struct){.pathname = (__u64)42949672960,.bpf_fd = (__u32)4294967128,.file_flags = (__u32)4294967295,.path_fd = (__s32)2,},.raw_tracepoint = (struct){.name = (__u64)42949672960,.prog_fd = (__u32)4294967128,.cookie = (__u64)2,},(struct){.btf = (__u64)42949672960,.btf_log_buf = (__u64)18446744073709551448,.btf_size = (__u32)2,.btf_log_level = (__u32)801012880,},}, size: 8) = -1 EOPNOTSUPP (Operation not supported)
     0.009 ( 0.042 ms): :3117755/3117755 bpf(cmd: PROG_LOAD, uattr: (union bpf_attr){(struct){.map_type = (__u32)1,.key_size = (__u32)2,.value_size = (__u32)2233669616,.max_entries = (__u32)32767,.map_flags = (__u32)7334203,},(struct){.map_fd = (__u32)1,.key = (__u64)140735427057648,(union){.value = (__u64)7334203,.next_key = (__u64)7334203,},},.batch = (struct){.in_batch = (__u64)8589934593,.out_batch = (__u64)140735427057648,.keys = (__u64)7334203,},(struct){.prog_type = (__u32)1,.insn_cnt = (__u32)2,.insns = (__u64)140735427057648,.license = (__u64)7334203,},(struct){.pathname = (__u64)8589934593,.bpf_fd = (__u32)2233669616,.file_flags = (__u32)32767,.path_fd = (__s32)7334203,},(struct){(union){.target_fd = (__u32)1,.target_ifindex = (__u32)1,},.attach_bpf_fd = (__u32)2,.attach_type = (__u32)2233669616,.attach_flags = (__u32)32767,.replace_bpf_fd = (__u32)7334203,},.test = (struct){.prog_fd = (__u32)1,.retval = (__u32)2,.data_size_in = (__u32)2233669616,.data_size_out = (__u32)32767,.data_in = (__u64)7334203,},(struct){(union){.start_id = (__u32)1,.prog_id = (__u32)1,.map_id = (__u32)1,.btf_id = (__u32)1,.link_id = (__u32)1,},.next_id = (__u32)2,.open_flags = (__u32)2233669616,},.info = (struct){.bpf_fd = (__u32)1,.info_len = (__u32)2,.info = (__u64)140735427057648,},.query = (struct){(union){.target_fd = (__u32)1,.target_ifindex = (__u32)1,},.attach_type = (__u32)2,.query_flags = (__u32)2233669616,.attach_flags = (__u32)32767,.prog_ids = (__u64)7334203,},.raw_tracepoint = (struct){.name = (__u64)8589934593,.prog_fd = (__u32)2233669616,.cookie = (__u64)7334203,},(struct){.btf = (__u64)8589934593,.btf_log_buf = (__u64)140735427057648,.btf_size = (__u32)7334203,},.task_fd_query = (struct){.pid = (__u32)1,.fd = (__u32)2,.flags = (__u32)2233669616,.buf_len = (__u32)32767,.buf = (__u64)7334203,},.link_create = (struct){(union){.prog_fd = (__u32)1,.map_fd = (__u32)1,},(union){.target_fd = (__u32)2,.target_ifindex = (__u32)2,},.attach_type = (__u32)2233669616,.flags = (__u32)32767,(union){.target_btf_id = (__u32)7334203,(struct){.iter_info = (__u64)7334203) = 10
     0.054 ( 0.010 ms): :3117755/3117755 bpf(cmd: PROG_LOAD, uattr: (union bpf_attr){(struct){.map_type = (__u32)1,.key_size = (__u32)2,.value_size = (__u32)2233670144,.max_entries = (__u32)32767,.map_flags = (__u32)7314455,},(struct){.map_fd = (__u32)1,.key = (__u64)140735427058176,(union){.value = (__u64)7314455,.next_key = (__u64)7314455,},},.batch = (struct){.in_batch = (__u64)8589934593,.out_batch = (__u64)140735427058176,.keys = (__u64)7314455,},(struct){.prog_type = (__u32)1,.insn_cnt = (__u32)2,.insns = (__u64)140735427058176,.license = (__u64)7314455,},(struct){.pathname = (__u64)8589934593,.bpf_fd = (__u32)2233670144,.file_flags = (__u32)32767,.path_fd = (__s32)7314455,},(struct){(union){.target_fd = (__u32)1,.target_ifindex = (__u32)1,},.attach_bpf_fd = (__u32)2,.attach_type = (__u32)2233670144,.attach_flags = (__u32)32767,.replace_bpf_fd = (__u32)7314455,},.test = (struct){.prog_fd = (__u32)1,.retval = (__u32)2,.data_size_in = (__u32)2233670144,.data_size_out = (__u32)32767,.data_in = (__u64)7314455,},(struct){(union){.start_id = (__u32)1,.prog_id = (__u32)1,.map_id = (__u32)1,.btf_id = (__u32)1,.link_id = (__u32)1,},.next_id = (__u32)2,.open_flags = (__u32)2233670144,},.info = (struct){.bpf_fd = (__u32)1,.info_len = (__u32)2,.info = (__u64)140735427058176,},.query = (struct){(union){.target_fd = (__u32)1,.target_ifindex = (__u32)1,},.attach_type = (__u32)2,.query_flags = (__u32)2233670144,.attach_flags = (__u32)32767,.prog_ids = (__u64)7314455,},.raw_tracepoint = (struct){.name = (__u64)8589934593,.prog_fd = (__u32)2233670144,.cookie = (__u64)7314455,},(struct){.btf = (__u64)8589934593,.btf_log_buf = (__u64)140735427058176,.btf_size = (__u32)7314455,},.task_fd_query = (struct){.pid = (__u32)1,.fd = (__u32)2,.flags = (__u32)2233670144,.buf_len = (__u32)32767,.buf = (__u64)7314455,},.link_create = (struct){(union){.prog_fd = (__u32)1,.map_fd = (__u32)1,},(union){.target_fd = (__u32)2,.target_ifindex = (__u32)2,},.attach_type = (__u32)2233670144,.flags = (__u32)32767,(union){.target_btf_id = (__u32)7314455,(struct){.iter_info = (__u64)7314455) = 10
     0.000 ( 0.007 ms): sleep/3117756 openat(dfd: CWD, filename: "/etc/ld.so.cache", flags: RDONLY|CLOEXEC) = 3
     0.022 ( 0.004 ms): sleep/3117756 openat(dfd: CWD, filename: "/lib64/libc.so.6", flags: RDONLY|CLOEXEC) = 3
     0.201 ( 0.006 ms): sleep/3117756 openat(dfd: CWD, filename: "/usr/lib/locale/locale-archive", flags: RDONLY|CLOEXEC) = 3
     0.247 ( 0.004 ms): sleep/3117756 openat(dfd: CWD, filename: "/usr/share/locale/locale.alias", flags: RDONLY|CLOEXEC) = 3
     0.283 ( 0.003 ms): sleep/3117756 openat(dfd: CWD, filename: "/usr/share/locale/en_US.UTF-8/LC_MESSAGES/coreutils.mo") = -1 ENOENT (No such file or directory)
     0.287 ( 0.002 ms): sleep/3117756 openat(dfd: CWD, filename: "/usr/share/locale/en_US.utf8/LC_MESSAGES/coreutils.mo") = -1 ENOENT (No such file or directory)
     0.290 ( 0.003 ms): sleep/3117756 openat(dfd: CWD, filename: "/usr/share/locale/en_US/LC_MESSAGES/coreutils.mo") = -1 ENOENT (No such file or directory)
root@number:~#

root@number:~# perf trace -e connect
     0.000 ( 0.020 ms): pool/3112 connect(fd: 7, uservaddr: { .family: LOCAL, path: /var/run/.heim }, addrlen: 110) = 0
   665.621 ( 0.029 ms): Chrome_ChildIO/3102157 connect(fd: 26, uservaddr: { .family: INET6, port: 443, addr: 2001:4860:4860::900:0, scope_id: 5767169 }, addrlen: 28) = 0
  4422.069 ( 0.024 ms): DNS Res~ver #2/19644 connect(fd: 230, uservaddr: { .family: INET, port: 53, addr: 127.0.0.53 }, addrlen: 16) = 0
  4422.354 ( 0.012 ms): systemd-resolv/1213 connect(fd: 14, uservaddr: { .family: INET, port: 53, addr: 192.168.86.1 }, addrlen: 16) = 0
  4422.225 ( 0.017 ms): DNS Res~ver #6/3099285 connect(fd: 227, uservaddr: { .family: LOCAL, path: /run/systemd/r }, addrlen: 42) = 0
  4422.590 ( 0.010 ms): systemd-resolv/1213 connect(fd: 26, uservaddr: { .family: INET, port: 53, addr: 192.168.86.1 }, addrlen: 16) = 0
  4422.642 ( 0.003 ms): systemd-resolv/1213 connect(fd: 27, uservaddr: { .family: INET, port: 53, addr: 192.168.86.1 }, addrlen: 16) = 0
  4457.908 ( 0.014 ms): DNS Res~ver #6/3099285 connect(fd: 227, uservaddr: { .family: INET6, port: 0, addr: 2800:3f0:4001:837::900:0, scope_id: 5767169 }, addrlen: 28) = 0
  4457.924 ( 0.001 ms): DNS Res~ver #6/3099285 connect(fd: 227, uservaddr: { .family: UNSPEC }, addrlen: 16)         = 0
  4457.926 ( 0.004 ms): DNS Res~ver #6/3099285 connect(fd: 227, uservaddr: { .family: INET, port: 0, addr: 142.251.128.234 }, addrlen: 16) = 0
  5000.793 ( 0.059 ms): pool/3112 connect(fd: 7, uservaddr: { .family: LOCAL, path: /var/run/.heim }, addrlen: 110) = 0
^Croot@number:~#

I'll try with some other systems and report.

- Arnaldo