[BUG] perf trace: failed to load -E2BIG

[BUG] perf trace: failed to load -E2BIG

[Namhyung Kim]

Hello,

I'm seeing the following error in the current perf-tools[-next].
Do you see you the same?

  $ sudo ./perf trace -a sleep 1
  libbpf: prog 'sys_enter': BPF program load failed: -E2BIG
  libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
  0: R1=ctx() R10=fp0
  ; int sys_enter(struct syscall_enter_args *args) @ augmented_raw_syscalls.bpf.c:527
  0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
  ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
  1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
  2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
  3: (bf) r2 = r10                      ; R2_w=fp0 R10=fp0
  ;  @ augmented_raw_syscalls.bpf.c:0
  4: (07) r2 += -4                      ; R2_w=fp-4
  ; return bpf_map_lookup_elem(pids, &pid) != NULL; @ augmented_raw_syscalls.bpf.c:428
  ...
  140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
  141: (79) r0 = *(u64 *)(r10 -56)
  BPF program is too large. Processed 1000001 insn
  processed 1000001 insns (limit 1000000) max_states_per_insn 28 total_states 37670 peak_states 330 mark_read 16
  -- END PROG LOAD LOG --
  libbpf: prog 'sys_enter': failed to load: -E2BIG
  libbpf: failed to load object 'augmented_raw_syscalls_bpf'
  libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -E2BIG
  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!

The git bisect found this but I couldn't find anything suspicious.

395d38419f1853decab84acc16176b3fa5c96690 is the first bad commit
commit 395d38419f1853decab84acc16176b3fa5c96690
Author: Howard Chu <howardchu95@gmail.com>
Date:   Thu Oct 10 19:14:02 2024 -0700

    perf trace augmented_raw_syscalls: Add more checks to pass the verifier
    
    Add some more checks to pass the verifier in more kernels.
    
    Signed-off-by: Howard Chu <howardchu95@gmail.com>
    Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
    Cc: Adrian Hunter <adrian.hunter@intel.com>
    Cc: Alan Maguire <alan.maguire@oracle.com>
    Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
    Cc: Ian Rogers <irogers@google.com>
    Cc: Ingo Molnar <mingo@redhat.com>
    Cc: Jiri Olsa <jolsa@kernel.org>
    Cc: Kan Liang <kan.liang@linux.intel.com>
    Cc: Mark Rutland <mark.rutland@arm.com>
    Cc: Namhyung Kim <namhyung@kernel.org>
    Cc: Peter Zijlstra <peterz@infradead.org>
    Link: https://lore.kernel.org/r/20241011021403.4089793-3-howardchu95@gmail.com
    [ Reduced the patch removing things that can be done later ]
    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

 .../perf/util/bpf_skel/augmented_raw_syscalls.bpf.c  | 20 ++++++++++++++++++--
 1 file changed, 18 insertions(+), 2 deletions(-)
bisect found first bad commit

Thanks,
Namhyung

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

[Namhyung Kim]

On Thu, Dec 5, 2024 at 4:19 PM Arnaldo Carvalho de Melo
<arnaldo.melo@gmail.com> wrote:
>
>
>
> On Thu, Dec 5, 2024, 9:14 PM Namhyung Kim <namhyung@kernel.org> wrote:
>>
>> Hello,
>>
>> I'm seeing the following error in the current perf-tools[-next].
>> Do you see you the same?
>
> Nope, what's your environment?  Kernel version, clang, etc.

It's a debian derivative and the kernel is v6.9.10 and clang 16.0.6.
But I cannot reproduce it anymore after the bisect. :(
Maybe it's a transient kernel bug.

>
> I think we should and that I'm addition to the verifier error log.

I think the below is the verifier log and I cut it out as it repeated.
It seems the verifier fell into a loop for some reason and thought
the program had too many instructions.

Thanks,
Namhyung

>
>  - Arnaldo
>
>>
>>   $ sudo ./perf trace -a sleep 1
>>   libbpf: prog 'sys_enter': BPF program load failed: -E2BIG
>>   libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
>>   0: R1=ctx() R10=fp0
>>   ; int sys_enter(struct syscall_enter_args *args) @ augmented_raw_syscalls.bpf.c:527
>>   0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
>>   ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
>>   1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
>>   2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
>>   3: (bf) r2 = r10                      ; R2_w=fp0 R10=fp0
>>   ;  @ augmented_raw_syscalls.bpf.c:0
>>   4: (07) r2 += -4                      ; R2_w=fp-4
>>   ; return bpf_map_lookup_elem(pids, &pid) != NULL; @ augmented_raw_syscalls.bpf.c:428
>>   ...
>>   140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
>>   141: (79) r0 = *(u64 *)(r10 -56)
>>   BPF program is too large. Processed 1000001 insn
>>   processed 1000001 insns (limit 1000000) max_states_per_insn 28 total_states 37670 peak_states 330 mark_read 16
>>   -- END PROG LOAD LOG --
>>   libbpf: prog 'sys_enter': failed to load: -E2BIG
>>   libbpf: failed to load object 'augmented_raw_syscalls_bpf'
>>   libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -E2BIG
>>   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!
>>
>> The git bisect found this but I couldn't find anything suspicious.
>>
>> 395d38419f1853decab84acc16176b3fa5c96690 is the first bad commit
>> commit 395d38419f1853decab84acc16176b3fa5c96690
>> Author: Howard Chu <howardchu95@gmail.com>
>> Date:   Thu Oct 10 19:14:02 2024 -0700
>>
>>     perf trace augmented_raw_syscalls: Add more checks to pass the verifier
>>
>>     Add some more checks to pass the verifier in more kernels.
>>
>>     Signed-off-by: Howard Chu <howardchu95@gmail.com>
>>     Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
>>     Cc: Adrian Hunter <adrian.hunter@intel.com>
>>     Cc: Alan Maguire <alan.maguire@oracle.com>
>>     Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
>>     Cc: Ian Rogers <irogers@google.com>
>>     Cc: Ingo Molnar <mingo@redhat.com>
>>     Cc: Jiri Olsa <jolsa@kernel.org>
>>     Cc: Kan Liang <kan.liang@linux.intel.com>
>>     Cc: Mark Rutland <mark.rutland@arm.com>
>>     Cc: Namhyung Kim <namhyung@kernel.org>
>>     Cc: Peter Zijlstra <peterz@infradead.org>
>>     Link: https://lore.kernel.org/r/20241011021403.4089793-3-howardchu95@gmail.com
>>     [ Reduced the patch removing things that can be done later ]
>>     Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
>>
>>  .../perf/util/bpf_skel/augmented_raw_syscalls.bpf.c  | 20 ++++++++++++++++++--
>>  1 file changed, 18 insertions(+), 2 deletions(-)
>> bisect found first bad commit
>>
>> Thanks,
>> Namhyung
>>

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

[Qiao Zhao]

We hit the similar issue on our internal version since v6.11.0 and start with
commit 395d38419f1853decab84acc16176b3fa5c96690
and can easy to reproduce by 'perf trace ls' and get such error log:

------------
# perf trace ls
libbpf: prog 'sys_enter': BPF program load failed: Argument list too long
libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
0: R1=ctx() R10=fp0
; int sys_enter(struct syscall_enter_args *args) @
augmented_raw_syscalls.bpf.c:527
0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
3: (bf) r2 = r10                      ; R2_w=fp0 R10=fp0
4: (07) r2 += -4                      ; R2_w=fp-4
; return bpf_map_lookup_elem(pids, &pid) != NULL; @
augmented_raw_syscalls.bpf.c:428
5: (18) r1 = 0xff45c8d9a56b1c00       ;
R1_w=map_ptr(map=pids_filtered,ks=4,vs=1)
7: (85) call bpf_map_lookup_elem#1    ;
R0=map_value_or_null(id=1,map=pids_filtered,ks=4,vs=1)
8: (bf) r1 = r0                       ;
R0=map_value_or_null(id=1,map=pids_filtered,ks=4,vs=1)
R1_w=map_value_or_null(id=1,map=pids_filtered,ks=4,vs=1)
9: (b7) r0 = 0                        ; R0_w=0
... ...
111: (2d) if r1 > r9 goto pc-22 90:
R0=map_value(map=beauty_payload_,ks=4,vs=24688) R1_w=-6 R2=1
R3=scalar(umin=1) R6=map_value(map=beauty_map_ente,ks=4,vs=24,off=20)
R7=map_value(map=augmented_args_,ks=4,vs=8272,off=56) R8=6
R9=scalar(smin=0xffffffff80000000,smax=smax32=0,umin=2,umax=0xfffffffffffffff9)
R10=fp0 fp-8=mmmmmmmm
fp-16=map_value(map=beauty_payload_,ks=4,vs=24688,off=88)
fp-24=map_value(map=augmented_args_,ks=4,vs=8272,off=16)
fp-32=map_value(map=augmented_args_,ks=4,vs=8272) fp-40=16 fp-48=ctx()
fp-56=map_value(map=beauty_payload_,ks=4,vs=24688) fp-64=1
fp-72=map_value(map=beauty_payload_,ks=4,vs=24688,off=80)
fp-80=map_value(map=beauty_map_ente,ks=4,vs=24)
90: (07) r7 += 8
BPF program is too large. Processed 1000001 insn
processed 1000001 insns (limit 1000000) max_states_per_insn 28
total_states 40283 peak_states 269 mark_read 15
-- END PROG LOAD LOG --
libbpf: prog 'sys_enter': failed to load: -7
libbpf: failed to load object 'augmented_raw_syscalls_bpf'
libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -7
libbpf: map '__augmented_syscalls__': can't use BPF map without FD
(was it created?)
... ...
................
Like some bpf error is printed before the trace is printed.
Hope this can help you to debug.

- Qiao

On Fri, Dec 6, 2024 at 8:49 AM Namhyung Kim <namhyung@kernel.org> wrote:
>
> On Thu, Dec 5, 2024 at 4:19 PM Arnaldo Carvalho de Melo
> <arnaldo.melo@gmail.com> wrote:
> >
> >
> >
> > On Thu, Dec 5, 2024, 9:14 PM Namhyung Kim <namhyung@kernel.org> wrote:
> >>
> >> Hello,
> >>
> >> I'm seeing the following error in the current perf-tools[-next].
> >> Do you see you the same?
> >
> > Nope, what's your environment?  Kernel version, clang, etc.
>
> It's a debian derivative and the kernel is v6.9.10 and clang 16.0.6.
> But I cannot reproduce it anymore after the bisect. :(
> Maybe it's a transient kernel bug.
>
> >
> > I think we should and that I'm addition to the verifier error log.
>
> I think the below is the verifier log and I cut it out as it repeated.
> It seems the verifier fell into a loop for some reason and thought
> the program had too many instructions.
>
> Thanks,
> Namhyung
>
> >
> >  - Arnaldo
> >
> >>
> >>   $ sudo ./perf trace -a sleep 1
> >>   libbpf: prog 'sys_enter': BPF program load failed: -E2BIG
> >>   libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
> >>   0: R1=ctx() R10=fp0
> >>   ; int sys_enter(struct syscall_enter_args *args) @ augmented_raw_syscalls.bpf.c:527
> >>   0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
> >>   ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
> >>   1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
> >>   2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
> >>   3: (bf) r2 = r10                      ; R2_w=fp0 R10=fp0
> >>   ;  @ augmented_raw_syscalls.bpf.c:0
> >>   4: (07) r2 += -4                      ; R2_w=fp-4
> >>   ; return bpf_map_lookup_elem(pids, &pid) != NULL; @ augmented_raw_syscalls.bpf.c:428
> >>   ...
> >>   140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
> >>   141: (79) r0 = *(u64 *)(r10 -56)
> >>   BPF program is too large. Processed 1000001 insn
> >>   processed 1000001 insns (limit 1000000) max_states_per_insn 28 total_states 37670 peak_states 330 mark_read 16
> >>   -- END PROG LOAD LOG --
> >>   libbpf: prog 'sys_enter': failed to load: -E2BIG
> >>   libbpf: failed to load object 'augmented_raw_syscalls_bpf'
> >>   libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -E2BIG
> >>   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!
> >>
> >> The git bisect found this but I couldn't find anything suspicious.
> >>
> >> 395d38419f1853decab84acc16176b3fa5c96690 is the first bad commit
> >> commit 395d38419f1853decab84acc16176b3fa5c96690
> >> Author: Howard Chu <howardchu95@gmail.com>
> >> Date:   Thu Oct 10 19:14:02 2024 -0700
> >>
> >>     perf trace augmented_raw_syscalls: Add more checks to pass the verifier
> >>
> >>     Add some more checks to pass the verifier in more kernels.
> >>
> >>     Signed-off-by: Howard Chu <howardchu95@gmail.com>
> >>     Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> >>     Cc: Adrian Hunter <adrian.hunter@intel.com>
> >>     Cc: Alan Maguire <alan.maguire@oracle.com>
> >>     Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> >>     Cc: Ian Rogers <irogers@google.com>
> >>     Cc: Ingo Molnar <mingo@redhat.com>
> >>     Cc: Jiri Olsa <jolsa@kernel.org>
> >>     Cc: Kan Liang <kan.liang@linux.intel.com>
> >>     Cc: Mark Rutland <mark.rutland@arm.com>
> >>     Cc: Namhyung Kim <namhyung@kernel.org>
> >>     Cc: Peter Zijlstra <peterz@infradead.org>
> >>     Link: https://lore.kernel.org/r/20241011021403.4089793-3-howardchu95@gmail.com
> >>     [ Reduced the patch removing things that can be done later ]
> >>     Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
> >>
> >>  .../perf/util/bpf_skel/augmented_raw_syscalls.bpf.c  | 20 ++++++++++++++++++--
> >>  1 file changed, 18 insertions(+), 2 deletions(-)
> >> bisect found first bad commit
> >>
> >> Thanks,
> >> Namhyung
> >>
>

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

[Howard Chu]

Hi Qiao, Namhyung, and Arnaldo,

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.

perf $ ./perf trace -e write --max-events=1
libbpf: prog 'sys_enter': BPF program load failed: Argument list too long
libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
0: R1=ctx() R10=fp0
; int sys_enter(struct syscall_enter_args *args) @
augmented_raw_syscalls.bpf.c:527
0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
...
140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
141: (79) r0 = *(u64 *)(r10 -56)
BPF program is too large. Processed 1000001 insn
processed 1000001 insns (limit 1000000) max_states_per_insn 28
total_states 37670 peak_states 330 mark_read 16
-- END PROG LOAD LOG --
libbpf: prog 'sys_enter': failed to load: -7
libbpf: failed to load object 'augmented_raw_syscalls_bpf'
libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -7
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!

For clang-14 however, I encountered an unbounded memory access:

perf $ ./perf trace -e write --max-events=1
libbpf: prog 'sys_enter': BPF program load failed: Permission denied
libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
0: R1=ctx() R10=fp0
; int sys_enter(struct syscall_enter_args *args) @
augmented_raw_syscalls.bpf.c:527
0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
88: (79) r1 = *(u64 *)(r10 -16)       ;
R1_w=map_value(map=beauty_payload_,ks=4,vs=24688,off=112) R10=fp0
fp-16=map_value(map=beauty_payload_,ks=4,vs=24688,off=112)
89: (bf) r2 = r9                      ;
R2_w=scalar(id=14,smin=umin=umin32=2,smax=umax=0xffffffff,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!

I thought I had tested them, but apparently I didn’t. My apologies
again, and fixes are on the way.

Thanks,
Howard

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

[Howard Chu]

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

Thanks,
Howard

On Fri, Dec 6, 2024 at 10:36 AM Howard Chu <howardchu95@gmail.com> wrote:
>
> Hi Qiao, Namhyung, and Arnaldo,
>
> 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.
>
> perf $ ./perf trace -e write --max-events=1
> libbpf: prog 'sys_enter': BPF program load failed: Argument list too long
> libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
> 0: R1=ctx() R10=fp0
> ; int sys_enter(struct syscall_enter_args *args) @
> augmented_raw_syscalls.bpf.c:527
> 0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
> ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
> ...
> 140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
> 141: (79) r0 = *(u64 *)(r10 -56)
> BPF program is too large. Processed 1000001 insn
> processed 1000001 insns (limit 1000000) max_states_per_insn 28
> total_states 37670 peak_states 330 mark_read 16
> -- END PROG LOAD LOG --
> libbpf: prog 'sys_enter': failed to load: -7
> libbpf: failed to load object 'augmented_raw_syscalls_bpf'
> libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -7
> 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!
>
> For clang-14 however, I encountered an unbounded memory access:
>
> perf $ ./perf trace -e write --max-events=1
> libbpf: prog 'sys_enter': BPF program load failed: Permission denied
> libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
> 0: R1=ctx() R10=fp0
> ; int sys_enter(struct syscall_enter_args *args) @
> augmented_raw_syscalls.bpf.c:527
> 0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
> ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
> 1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
> 2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
> 88: (79) r1 = *(u64 *)(r10 -16)       ;
> R1_w=map_value(map=beauty_payload_,ks=4,vs=24688,off=112) R10=fp0
> fp-16=map_value(map=beauty_payload_,ks=4,vs=24688,off=112)
> 89: (bf) r2 = r9                      ;
> R2_w=scalar(id=14,smin=umin=umin32=2,smax=umax=0xffffffff,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!
>
> I thought I had tested them, but apparently I didn’t. My apologies
> again, and fixes are on the way.
>
> Thanks,
> Howard

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

[Namhyung Kim]

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
> 
> Thanks,
> Howard
> 
> On Fri, Dec 6, 2024 at 10:36 AM Howard Chu <howardchu95@gmail.com> wrote:
> >
> > Hi Qiao, Namhyung, and Arnaldo,
> >
> > 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.
> >
> > perf $ ./perf trace -e write --max-events=1
> > libbpf: prog 'sys_enter': BPF program load failed: Argument list too long
> > libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
> > 0: R1=ctx() R10=fp0
> > ; int sys_enter(struct syscall_enter_args *args) @
> > augmented_raw_syscalls.bpf.c:527
> > 0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
> > ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
> > ...
> > 140: (79) r7 = *(u64 *)(r10 -48)      ; R7_w=ctx() R10=fp0 fp-48=ctx()
> > 141: (79) r0 = *(u64 *)(r10 -56)
> > BPF program is too large. Processed 1000001 insn
> > processed 1000001 insns (limit 1000000) max_states_per_insn 28
> > total_states 37670 peak_states 330 mark_read 16
> > -- END PROG LOAD LOG --
> > libbpf: prog 'sys_enter': failed to load: -7
> > libbpf: failed to load object 'augmented_raw_syscalls_bpf'
> > libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -7
> > 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!
> >
> > For clang-14 however, I encountered an unbounded memory access:
> >
> > perf $ ./perf trace -e write --max-events=1
> > libbpf: prog 'sys_enter': BPF program load failed: Permission denied
> > libbpf: prog 'sys_enter': -- BEGIN PROG LOAD LOG --
> > 0: R1=ctx() R10=fp0
> > ; int sys_enter(struct syscall_enter_args *args) @
> > augmented_raw_syscalls.bpf.c:527
> > 0: (bf) r7 = r1                       ; R1=ctx() R7_w=ctx()
> > ; return bpf_get_current_pid_tgid(); @ augmented_raw_syscalls.bpf.c:423
> > 1: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
> > 2: (63) *(u32 *)(r10 -4) = r0         ; R0_w=scalar() R10=fp0 fp-8=mmmm????
> > 88: (79) r1 = *(u64 *)(r10 -16)       ;
> > R1_w=map_value(map=beauty_payload_,ks=4,vs=24688,off=112) R10=fp0
> > fp-16=map_value(map=beauty_payload_,ks=4,vs=24688,off=112)
> > 89: (bf) r2 = r9                      ;
> > R2_w=scalar(id=14,smin=umin=umin32=2,smax=umax=0xffffffff,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!
> >
> > I thought I had tested them, but apparently I didn’t. My apologies
> > again, and fixes are on the way.
> >
> > Thanks,
> > Howard

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

[Arnaldo Carvalho de Melo]

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

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

[Howard Chu]

Hi Arnaldo,

On Tue, Dec 10, 2024 at 11:02 AM Arnaldo Carvalho de Melo
<acme@kernel.org> wrote:
>
> 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

Agree, I don't like the constant malloc / free part of the btf_dump.

> 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

This is cool, I'm wondering if you have tried to generate the BPF skel
using clang version <= 16 because that's where problems occured.

> 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.

Thanks a lot Arnaldo :)

Thanks,
Howard
>
> - Arnaldo