facebookincubator / below

A time traveling resource monitor for modern Linux systems
Apache License 2.0
1.04k stars 60 forks source link

libbpf issue #8188

Closed shtirlic closed 1 year ago

shtirlic commented 1 year ago
libbpf: prog 'tracepoint__sched__sched_process_exit': failed to load: -22
libbpf: failed to load object 'exitstat_bpf'
libbpf: failed to load BPF skeleton 'exitstat_bpf': -22
May 17 06:50:02.720 ERRO System error, errno: 22
^CMay 17 06:50:04.541 ERRO Stop signal received: 2, exiting.
May 17 06:50:07.721 ERRO Stopped by signal: 2
May 17 13:43:17 arazu systemd[1]: Started below system monitor recording daemon.
May 17 13:43:17 arazu below[29640]: May 17 06:43:17.616 DEBG Starting up!
May 17 13:43:22 arazu below[29640]: May 17 06:43:22.617 ERRO System error, errno: 22
May 17 13:43:27 arazu below[29640]: May 17 06:43:27.617 WARN bpf error channel disconnected
May 17 13:46:36 arazu below[29640]: May 17 06:46:36.238 ERRO Stop signal received: 15, exiting.
May 17 13:46:36 arazu systemd[1]: Stopping below system monitor recording daemon...
May 17 13:46:37 arazu below[29640]: May 17 06:46:37.628 ERRO Stopped by signal: 15
May 17 13:46:37 arazu systemd[1]: below.service: Deactivated successfully.
May 17 13:46:37 arazu systemd[1]: Stopped below system monitor recording daemon.
May 17 13:46:37 arazu systemd[1]: below.service: Consumed 1.005s CPU time.
Linux arazu 6.3.2-zen1-1-zen #1 ZEN SMP PREEMPT_DYNAMIC Thu, 11 May 2023 16:40:19 +0000 x86_64 GNU/Linux

log_dir = "/var/log/below"
store_dir = "/var/log/below/store"
cgroup_filter_out = "user.slice.*"
[root@arazu below]# cat /sys/kernel/security/lsm
capability,landlock,lockdown,yama,bpf
journalctl -b | egrep -i '(bpf|lsm)'
egrep: warning: egrep is obsolescent; using grep -E
May 17 12:56:05 arazu kernel: LSM: initializing lsm=capability,landlock,lockdown,yama,integrity,bpf
May 17 12:56:05 arazu kernel: LSM support for eBPF active
May 17 12:56:05 arazu systemd[1]: systemd 253.4-1-arch running in system mode (+PAM +AUDIT -SELINUX -APPARMOR -IMA +SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT -QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK +XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified)
May 17 12:56:05 arazu systemd[1]: bpf-lsm: LSM BPF program attached
May 17 13:41:37 arazu below[26674]: May 17 06:41:37.601 WARN bpf error channel disconnected
May 17 13:42:02 arazu below[27207]: May 17 06:42:02.607 WARN bpf error channel disconnected
May 17 13:43:27 arazu below[29640]: May 17 06:43:27.617 WARN bpf error channel disconnected

arch, installed via AUR from git

brianc118 commented 1 year ago

Hi, sorry about the late response. I see the program is failing to load in daemon mode but the logs don't seem to be too useful.

Can you try running with the --debug flag to see verbose libbpf logs? e.g. sudo below --debug live

shtirlic commented 1 year ago

@brianc118 here it is

libbpf: loading object 'exitstat_bpf' from buffer
libbpf: elf: section(2) .symtab, size 312, link 1, flags 0, type=2
libbpf: elf: section(3) .text, size 152, link 0, flags 6, type=1
libbpf: sec '.text': found program 'task_cpu' at insn offset 0 (0 bytes), code size 19 insns (152 bytes)
libbpf: elf: section(4) tracepoint/sched/sched_process_exit, size 1688, link 0, flags 6, type=1
libbpf: sec 'tracepoint/sched/sched_process_exit': found program 'tracepoint__sched__sched_process_exit' at insn offset 0 (0 bytes), code size 211 insns (1688 bytes)
libbpf: elf: section(5) .maps, size 24, link 0, flags 3, type=1
libbpf: elf: section(6) license, size 4, link 0, flags 3, type=1
libbpf: license of exitstat_bpf is GPL
libbpf: elf: section(7) .reltracepoint/sched/sched_process_exit, size 16, link 2, flags 40, type=9
libbpf: elf: section(8) .BTF, size 53096, link 0, flags 0, type=1
libbpf: elf: section(9) .BTF.ext, size 1916, link 0, flags 0, type=1
libbpf: looking for externs among 13 symbols...
libbpf: collected 0 externs total
libbpf: map 'events': at sec_idx 5, offset 0.
libbpf: map 'events': found type = 4.
libbpf: map 'events': found key_size = 4.
libbpf: map 'events': found value_size = 4.
libbpf: sec '.reltracepoint/sched/sched_process_exit': collecting relocation for section(4) 'tracepoint/sched/sched_process_exit'
libbpf: sec '.reltracepoint/sched/sched_process_exit': relo #0: insn #203 against 'events'
libbpf: prog 'tracepoint__sched__sched_process_exit': found map 0 (events, sec 5, off 0) for insn #203
libbpf: loading kernel BTF '/sys/kernel/btf/vmlinux': 0
libbpf: map 'events': setting size to 8
libbpf: map 'events': created successfully, fd=17
libbpf: sec '.text': found 3 CO-RE relocations
libbpf: CO-RE relocating [13] struct task_struct___pre516: found target candidate [211] struct task_struct in [vmlinux]
libbpf: prog 'task_cpu': relo #0: <field_exists> [13] struct task_struct___pre516.cpu (0:0 @ offset 0)
libbpf: prog 'task_cpu': relo #0: non-matching candidate #0 <field_exists> [211] struct task_struct (0 @ offset 0)
libbpf: prog 'task_cpu': relo #0: no matching targets found
libbpf: prog 'task_cpu': relo #0: patched insn #1 (ALU/ALU64) imm 1 -> 0
libbpf: prog 'task_cpu': relo #1: <byte_off> [13] struct task_struct___pre516.cpu (0:0 @ offset 0)
libbpf: prog 'task_cpu': relo #1: non-matching candidate #0 <byte_off> [211] struct task_struct (0 @ offset 0)
libbpf: prog 'task_cpu': relo #1: no matching targets found
libbpf: prog 'task_cpu': relo #1: substituting insn #3 w/ invalid insn
libbpf: CO-RE relocating [14] struct task_struct___post516: found target candidate [211] struct task_struct in [vmlinux]
libbpf: prog 'task_cpu': relo #2: <byte_off> [14] struct task_struct___post516.thread_info.cpu (0:0:0 @ offset 0)
libbpf: prog 'task_cpu': relo #2: matching candidate #0 <byte_off> [211] struct task_struct.thread_info.cpu (0:0:3 @ offset 20)
libbpf: prog 'task_cpu': relo #2: patched insn #11 (ALU/ALU64) imm 0 -> 20
libbpf: sec 'tracepoint/sched/sched_process_exit': found 20 CO-RE relocations
libbpf: CO-RE relocating [28] struct task_struct: found target candidate [211] struct task_struct in [vmlinux]
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #0: <byte_off> [28] struct task_struct.real_parent (0:73 @ offset 1304)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #0: matching candidate #0 <byte_off> [211] struct task_struct.real_parent (0:88 @ offset 1488)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #0: patched insn #23 (ALU/ALU64) imm 1304 -> 1488
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #1: <byte_off> [28] struct task_struct.tgid (0:71 @ offset 1292)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #1: matching candidate #0 <byte_off> [211] struct task_struct.tgid (0:86 @ offset 1476)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #1: patched insn #30 (ALU/ALU64) imm 1292 -> 1476
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #2: <byte_off> [28] struct task_struct.group_leader (0:77 @ offset 1352)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #2: matching candidate #0 <byte_off> [211] struct task_struct.group_leader (0:92 @ offset 1536)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #2: patched insn #37 (ALU/ALU64) imm 1352 -> 1536
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #3: <byte_off> [28] struct task_struct.sessionid (0:125 @ offset 1956)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #3: matching candidate #0 <byte_off> [211] struct task_struct.sessionid (0:143 @ offset 2236)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #3: patched insn #52 (ALU/ALU64) imm 1956 -> 2236
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #4: <field_exists> [13] struct task_struct___pre516.cpu (0:0 @ offset 0)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #4: non-matching candidate #0 <field_exists> [211] struct task_struct (0 @ offset 0)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #4: no matching targets found
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #4: patched insn #61 (ALU/ALU64) imm 1 -> 0
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #5: <byte_off> [13] struct task_struct___pre516.cpu (0:0 @ offset 0)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #5: non-matching candidate #0 <byte_off> [211] struct task_struct (0 @ offset 0)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #5: no matching targets found
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #5: substituting insn #63 w/ invalid insn
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #6: <byte_off> [14] struct task_struct___post516.thread_info.cpu (0:0:0 @ offset 0)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #6: matching candidate #0 <byte_off> [211] struct task_struct.thread_info.cpu (0:0:3 @ offset 20)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #6: patched insn #65 (ALU/ALU64) imm 0 -> 20
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #7: <byte_off> [28] struct task_struct.min_flt (0:95 @ offset 1600)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #7: matching candidate #0 <byte_off> [211] struct task_struct.min_flt (0:113 @ offset 1848)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #7: patched insn #78 (ALU/ALU64) imm 1600 -> 1848
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #8: <byte_off> [28] struct task_struct.maj_flt (0:96 @ offset 1608)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #8: matching candidate #0 <byte_off> [211] struct task_struct.maj_flt (0:114 @ offset 1856)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #8: patched insn #87 (ALU/ALU64) imm 1608 -> 1856
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #9: <byte_off> [28] struct task_struct.utime (0:87 @ offset 1520)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #9: matching candidate #0 <byte_off> [211] struct task_struct.utime (0:103 @ offset 1712)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #9: patched insn #96 (ALU/ALU64) imm 1520 -> 1712
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #10: <byte_off> [28] struct task_struct.stime (0:88 @ offset 1528)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #10: matching candidate #0 <byte_off> [211] struct task_struct.stime (0:104 @ offset 1720)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #10: patched insn #106 (ALU/ALU64) imm 1528 -> 1720
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #11: <byte_off> [28] struct task_struct.signal (0:113 @ offset 1848)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #11: matching candidate #0 <byte_off> [211] struct task_struct.signal (0:131 @ offset 2128)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #11: patched insn #116 (ALU/ALU64) imm 1848 -> 2128
libbpf: CO-RE relocating [698] struct signal_struct: found target candidate [776] struct signal_struct in [vmlinux]
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #12: <byte_off> [698] struct signal_struct.nr_threads (0:2 @ offset 8)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #12: matching candidate #0 <byte_off> [776] struct signal_struct.nr_threads (0:2 @ offset 8)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #12: patched insn #123 (ALU/ALU64) imm 8 -> 8
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #13: <byte_off> [28] struct task_struct.ioac.read_bytes (0:144:4 @ offset 2144)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #13: matching candidate #0 <byte_off> [211] struct task_struct.ioac.read_bytes (0:163:4 @ offset 2456)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #13: patched insn #134 (ALU/ALU64) imm 2144 -> 2456
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #14: <byte_off> [28] struct task_struct.ioac.write_bytes (0:144:5 @ offset 2152)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #14: matching candidate #0 <byte_off> [211] struct task_struct.ioac.write_bytes (0:163:5 @ offset 2464)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #14: patched insn #143 (ALU/ALU64) imm 2152 -> 2464
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #15: <byte_off> [28] struct task_struct.start_time (0:93 @ offset 1584)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #15: matching candidate #0 <byte_off> [211] struct task_struct.start_time (0:111 @ offset 1832)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #15: patched insn #152 (ALU/ALU64) imm 1584 -> 1832
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #16: <byte_off> [28] struct task_struct.mm (0:45 @ offset 1112)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #16: matching candidate #0 <byte_off> [211] struct task_struct.mm (0:58 @ offset 1352)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #16: patched insn #163 (ALU/ALU64) imm 1112 -> 1352
libbpf: CO-RE relocating [135] struct mm_struct: found target candidate [279] struct mm_struct in [vmlinux]
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #17: <byte_off> [135] struct mm_struct.rss_stat.count[0].counter (0:0:42:0:0:0 @ offset 712)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #17: non-matching candidate #0 <byte_off> [279] struct mm_struct (0:0 @ offset 752)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #17: no matching targets found
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #17: substituting insn #173 w/ invalid insn
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #18: <byte_off> [135] struct mm_struct.rss_stat.count[1].counter (0:0:42:0:1:0 @ offset 720)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #18: non-matching candidate #0 <byte_off> [279] struct mm_struct (0:0 @ offset 752)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #18: no matching targets found
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #18: substituting insn #180 w/ invalid insn
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #19: <byte_off> [135] struct mm_struct.rss_stat.count[3].counter (0:0:42:0:3:0 @ offset 736)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #19: non-matching candidate #0 <byte_off> [279] struct mm_struct (0:0 @ offset 752)
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #19: no matching targets found
libbpf: prog 'tracepoint__sched__sched_process_exit': relo #19: substituting insn #188 w/ invalid insn
libbpf: prog 'tracepoint__sched__sched_process_exit': BPF program load failed: Invalid argument
libbpf: prog 'tracepoint__sched__sched_process_exit': -- BEGIN PROG LOAD LOG --
reg type unsupported for arg#0 function tracepoint__sched__sched_process_exit#27
0: R1=ctx(off=0,imm=0) R10=fp0
; int tracepoint__sched__sched_process_exit(
0: (bf) r6 = r1                       ; R1=ctx(off=0,imm=0) R6_w=ctx(off=0,imm=0)
; struct task_struct* task = (struct task_struct*)bpf_get_current_task();
1: (85) call bpf_get_current_task#35          ; R0_w=scalar()
2: (bf) r7 = r0                       ; R0_w=scalar(id=1) R7_w=scalar(id=1)
; u64 pid_tgid = bpf_get_current_pid_tgid();
3: (85) call bpf_get_current_pid_tgid#14      ; R0_w=scalar()
4: (bf) r9 = r0                       ; R0_w=scalar(id=2) R9_w=scalar(id=2)
; u64 now = bpf_ktime_get_ns();
5: (85) call bpf_ktime_get_ns#5       ; R0_w=scalar()
6: (bf) r8 = r0                       ; R0_w=scalar(id=3) R8_w=scalar(id=3)
7: (b7) r1 = 0                        ; R1_w=0
; struct event data = {};
8: (7b) *(u64 *)(r10 -112) = r1       ; R1_w=0 R10=fp0 fp-112_w=00000000
9: (7b) *(u64 *)(r10 -8) = r1         ; R1_w=0 R10=fp0 fp-8_w=00000000
10: (7b) *(u64 *)(r10 -16) = r1       ; R1_w=0 R10=fp0 fp-16_w=00000000
11: (7b) *(u64 *)(r10 -24) = r1       ; R1_w=0 R10=fp0 fp-24_w=00000000
12: (7b) *(u64 *)(r10 -32) = r1       ; R1_w=0 R10=fp0 fp-32_w=00000000
13: (7b) *(u64 *)(r10 -40) = r1       ; R1_w=0 R10=fp0 fp-40_w=00000000
14: (7b) *(u64 *)(r10 -48) = r1       ; R1_w=0 R10=fp0 fp-48_w=00000000
15: (7b) *(u64 *)(r10 -56) = r1       ; R1_w=0 R10=fp0 fp-56_w=00000000
16: (7b) *(u64 *)(r10 -64) = r1       ; R1_w=0 R10=fp0 fp-64_w=00000000
17: (7b) *(u64 *)(r10 -72) = r1       ; R1_w=0 R10=fp0 fp-72_w=00000000
18: (7b) *(u64 *)(r10 -80) = r1       ; R1_w=0 R10=fp0 fp-80_w=00000000
19: (7b) *(u64 *)(r10 -88) = r1       ; R1_w=0 R10=fp0 fp-88_w=00000000
20: (7b) *(u64 *)(r10 -96) = r1       ; R1_w=0 R10=fp0 fp-96_w=00000000
21: (7b) *(u64 *)(r10 -104) = r1      ; R1_w=0 R10=fp0 fp-104_w=00000000
; data.meta.tid = pid_tgid & 0xFFFFFFFF;
22: (63) *(u32 *)(r10 -112) = r9      ; R9_w=scalar(id=2) R10=fp0 fp-112_w=0000mmmm
23: (b7) r1 = 1488                    ; R1_w=1488
24: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7_w=scalar(id=1)
25: (0f) r3 += r1                     ; R1_w=1488 R3_w=scalar()
26: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
;
27: (07) r1 += -120                   ; R1_w=fp-120
; data.meta.ppid = BPF_CORE_READ(task, real_parent, tgid);
28: (b7) r2 = 8                       ; R2_w=8
29: (85) call bpf_probe_read_kernel#113       ; R0=scalar() fp-120=mmmmmmmm
30: (b7) r9 = 1476                    ; R9_w=1476
31: (79) r3 = *(u64 *)(r10 -120)      ; R3_w=scalar() R10=fp0
32: (0f) r3 += r9                     ; R3_w=scalar() R9_w=1476
; data.meta.ppid = BPF_CORE_READ(task, real_parent, tgid);
33: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
34: (07) r1 += -108                   ; R1_w=fp-108
; data.meta.ppid = BPF_CORE_READ(task, real_parent, tgid);
35: (b7) r2 = 4                       ; R2_w=4
36: (85) call bpf_probe_read_kernel#113       ; R0_w=scalar() fp-112=mmmmmmmm
37: (b7) r1 = 1536                    ; R1_w=1536
38: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
39: (0f) r3 += r1                     ; R1_w=1536 R3_w=scalar()
40: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
;
41: (07) r1 += -120                   ; R1_w=fp-120
; data.meta.pgrp = BPF_CORE_READ(task, group_leader, tgid);
42: (b7) r2 = 8                       ; R2_w=8
43: (85) call bpf_probe_read_kernel#113       ; R0=scalar() fp-120=mmmmmmmm
44: (79) r3 = *(u64 *)(r10 -120)      ; R3_w=scalar() R10=fp0
45: (0f) r3 += r9                     ; R3_w=scalar() R9=1476
46: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
;
47: (07) r1 += -124                   ; R1_w=fp-124
; data.meta.pgrp = BPF_CORE_READ(task, group_leader, tgid);
48: (b7) r2 = 4                       ; R2_w=4
49: (85) call bpf_probe_read_kernel#113       ; R0_w=scalar() fp-128=mmmm????
; data.meta.pgrp = BPF_CORE_READ(task, group_leader, tgid);
50: (61) r1 = *(u32 *)(r10 -124)      ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0
; data.meta.pgrp = BPF_CORE_READ(task, group_leader, tgid);
51: (63) *(u32 *)(r10 -104) = r1      ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0 fp-104=
52: (b7) r1 = 2236                    ; R1_w=2236
53: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
54: (0f) r3 += r1                     ; R1_w=2236 R3_w=scalar()
55: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
;
56: (07) r1 += -120                   ; R1_w=fp-120
; data.meta.sid = BPF_CORE_READ(task, sessionid);
57: (b7) r2 = 4                       ; R2_w=4
58: (85) call bpf_probe_read_kernel#113       ; R0=scalar() fp-120=mmmmmmmm
; data.meta.sid = BPF_CORE_READ(task, sessionid);
59: (61) r1 = *(u32 *)(r10 -120)      ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0
; data.meta.sid = BPF_CORE_READ(task, sessionid);
60: (63) *(u32 *)(r10 -100) = r1      ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0 fp-104=mmmmmmmm
61: (b7) r1 = 0                       ; R1_w=0
; if (bpf_core_field_exists(struct task_struct___pre516, cpu)) {
62: (15) if r1 == 0x0 goto pc+2       ; R1_w=0
65: (b7) r1 = 20                      ; R1_w=20
66: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
67: (0f) r3 += r1                     ; R1_w=20 R3_w=scalar()
68: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
;
69: (07) r1 += -120                   ; R1_w=fp-120
70: (b7) r2 = 4                       ; R2_w=4
71: (85) call bpf_probe_read_kernel#113       ; R0=scalar() fp-120=mmmmmmmm
72: (61) r1 = *(u32 *)(r10 -120)      ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0
; data.meta.cpu = task_cpu(task);
73: (63) *(u32 *)(r10 -96) = r1       ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0 fp-96=
; bpf_get_current_comm(&data.meta.comm, sizeof(data.meta.comm));
74: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
75: (07) r1 += -92                    ; R1_w=fp-92
; bpf_get_current_comm(&data.meta.comm, sizeof(data.meta.comm));
76: (b7) r2 = 16                      ; R2_w=16
77: (85) call bpf_get_current_comm#16         ; R0_w=scalar() fp-80=0000mmmm fp-88=mmmmmmmm fp-96=mmmmmmmm
78: (b7) r1 = 1848                    ; R1_w=1848
79: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
80: (0f) r3 += r1                     ; R1_w=1848 R3_w=scalar()
81: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
82: (07) r1 += -120                   ; R1_w=fp-120
; data.stats.min_flt = BPF_CORE_READ(task, min_flt);
83: (b7) r2 = 8                       ; R2_w=8
84: (85) call bpf_probe_read_kernel#113       ; R0=scalar() fp-120=mmmmmmmm
; data.stats.min_flt = BPF_CORE_READ(task, min_flt);
85: (79) r1 = *(u64 *)(r10 -120)      ; R1_w=scalar() R10=fp0
; data.stats.min_flt = BPF_CORE_READ(task, min_flt);
86: (7b) *(u64 *)(r10 -72) = r1       ; R1_w=scalar() R10=fp0 fp-72_w=mmmmmmmm
87: (b7) r1 = 1856                    ; R1_w=1856
88: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
89: (0f) r3 += r1                     ; R1_w=1856 R3_w=scalar()
90: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
91: (07) r1 += -120                   ; R1_w=fp-120
; data.stats.maj_flt = BPF_CORE_READ(task, maj_flt);
92: (b7) r2 = 8                       ; R2_w=8
93: (85) call bpf_probe_read_kernel#113       ; R0_w=scalar() fp-120=mmmmmmmm
; data.stats.maj_flt = BPF_CORE_READ(task, maj_flt);
94: (79) r1 = *(u64 *)(r10 -120)      ; R1_w=scalar() R10=fp0
; data.stats.maj_flt = BPF_CORE_READ(task, maj_flt);
95: (7b) *(u64 *)(r10 -64) = r1       ; R1_w=scalar() R10=fp0 fp-64_w=mmmmmmmm
96: (b7) r1 = 1712                    ; R1_w=1712
97: (bf) r3 = r7                      ; R3_w=scalar(id=1) R7=scalar(id=1)
98: (0f) r3 += r1                     ; R1_w=1712 R3_w=scalar()
99: (bf) r1 = r10                     ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
100: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.utime_us = BPF_CORE_READ(task, utime) / 1000;
101: (b7) r2 = 8                      ; R2_w=8
102: (85) call bpf_probe_read_kernel#113      ; R0=scalar() fp-120=mmmmmmmm
; data.stats.utime_us = BPF_CORE_READ(task, utime) / 1000;
103: (79) r1 = *(u64 *)(r10 -120)     ; R1_w=scalar() R10=fp0
; data.stats.utime_us = BPF_CORE_READ(task, utime) / 1000;
104: (37) r1 /= 1000                  ; R1_w=scalar()
; data.stats.utime_us = BPF_CORE_READ(task, utime) / 1000;
105: (7b) *(u64 *)(r10 -56) = r1      ; R1_w=scalar() R10=fp0 fp-56_w=mmmmmmmm
106: (b7) r1 = 1720                   ; R1_w=1720
107: (bf) r3 = r7                     ; R3_w=scalar(id=1) R7=scalar(id=1)
108: (0f) r3 += r1                    ; R1_w=1720 R3_w=scalar()
109: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
110: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.stime_us = BPF_CORE_READ(task, stime) / 1000;
111: (b7) r2 = 8                      ; R2_w=8
112: (85) call bpf_probe_read_kernel#113      ; R0_w=scalar() fp-120=mmmmmmmm
; data.stats.stime_us = BPF_CORE_READ(task, stime) / 1000;
113: (79) r1 = *(u64 *)(r10 -120)     ; R1_w=scalar() R10=fp0
; data.stats.stime_us = BPF_CORE_READ(task, stime) / 1000;
114: (37) r1 /= 1000                  ; R1_w=scalar()
; data.stats.stime_us = BPF_CORE_READ(task, stime) / 1000;
115: (7b) *(u64 *)(r10 -48) = r1      ; R1_w=scalar() R10=fp0 fp-48_w=mmmmmmmm
116: (b7) r1 = 2128                   ; R1_w=2128
117: (bf) r3 = r7                     ; R3_w=scalar(id=1) R7=scalar(id=1)
118: (0f) r3 += r1                    ; R1_w=2128 R3_w=scalar()
119: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
120: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.nr_threads = BPF_CORE_READ(task, signal, nr_threads);
121: (b7) r2 = 8                      ; R2_w=8
122: (85) call bpf_probe_read_kernel#113      ; R0=scalar() fp-120=mmmmmmmm
123: (b7) r1 = 8                      ; R1_w=8
124: (79) r3 = *(u64 *)(r10 -120)     ; R3_w=scalar() R10=fp0
125: (0f) r3 += r1                    ; R1_w=8 R3_w=scalar()
126: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
127: (07) r1 += -124                  ; R1_w=fp-124
; data.stats.nr_threads = BPF_CORE_READ(task, signal, nr_threads);
128: (b7) r2 = 4                      ; R2_w=4
129: (85) call bpf_probe_read_kernel#113      ; R0_w=scalar() fp-128=mmmm????
; data.stats.nr_threads = BPF_CORE_READ(task, signal, nr_threads);
130: (61) r1 = *(u32 *)(r10 -124)     ; R1_w=scalar(umax=4294967295,var_off=(0x0; 0xffffffff)) R10=fp0
131: (67) r1 <<= 32                   ; R1_w=scalar(smax=9223372032559808512,umax=18446744069414584320,var_off=(0x0; 0xffffffff00000000),s32_min=0,s32_max=0,u32_max=0)
132: (c7) r1 s>>= 32                  ; R1_w=scalar(smin=-2147483648,smax=2147483647)
; data.stats.nr_threads = BPF_CORE_READ(task, signal, nr_threads);
133: (7b) *(u64 *)(r10 -32) = r1      ; R1_w=scalar(smin=-2147483648,smax=2147483647) R10=fp0 fp-32_w=
134: (b7) r1 = 2456                   ; R1_w=2456
135: (bf) r3 = r7                     ; R3_w=scalar(id=1) R7=scalar(id=1)
136: (0f) r3 += r1                    ; R1_w=2456 R3_w=scalar()
137: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
138: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.io_read_bytes = BPF_CORE_READ(task, ioac.read_bytes);
139: (b7) r2 = 8                      ; R2_w=8
140: (85) call bpf_probe_read_kernel#113      ; R0=scalar() fp-120=mmmmmmmm
; data.stats.io_read_bytes = BPF_CORE_READ(task, ioac.read_bytes);
141: (79) r1 = *(u64 *)(r10 -120)     ; R1_w=scalar() R10=fp0
; data.stats.io_read_bytes = BPF_CORE_READ(task, ioac.read_bytes);
142: (7b) *(u64 *)(r10 -24) = r1      ; R1_w=scalar() R10=fp0 fp-24_w=mmmmmmmm
143: (b7) r1 = 2464                   ; R1_w=2464
144: (bf) r3 = r7                     ; R3_w=scalar(id=1) R7=scalar(id=1)
145: (0f) r3 += r1                    ; R1_w=2464 R3_w=scalar()
146: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
147: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.io_write_bytes = BPF_CORE_READ(task, ioac.write_bytes);
148: (b7) r2 = 8                      ; R2_w=8
149: (85) call bpf_probe_read_kernel#113      ; R0_w=scalar() fp-120=mmmmmmmm
; data.stats.io_write_bytes = BPF_CORE_READ(task, ioac.write_bytes);
150: (79) r1 = *(u64 *)(r10 -120)     ; R1_w=scalar() R10=fp0
; data.stats.io_write_bytes = BPF_CORE_READ(task, ioac.write_bytes);
151: (7b) *(u64 *)(r10 -16) = r1      ; R1_w=scalar() R10=fp0 fp-16_w=mmmmmmmm
152: (b7) r1 = 1832                   ; R1_w=1832
153: (bf) r3 = r7                     ; R3_w=scalar(id=1) R7=scalar(id=1)
154: (0f) r3 += r1                    ; R1_w=1832 R3_w=scalar()
155: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
156: (07) r1 += -120                  ; R1_w=fp-120
; data.stats.etime_us = (now - BPF_CORE_READ(task, start_time)) / 1000;
157: (b7) r2 = 8                      ; R2_w=8
158: (85) call bpf_probe_read_kernel#113      ; R0=scalar() fp-120=mmmmmmmm
; data.stats.etime_us = (now - BPF_CORE_READ(task, start_time)) / 1000;
159: (79) r1 = *(u64 *)(r10 -120)     ; R1_w=scalar() R10=fp0
; data.stats.etime_us = (now - BPF_CORE_READ(task, start_time)) / 1000;
160: (1f) r8 -= r1                    ; R1_w=scalar() R8_w=scalar()
; data.stats.etime_us = (now - BPF_CORE_READ(task, start_time)) / 1000;
161: (37) r8 /= 1000                  ; R8_w=scalar()
; data.stats.etime_us = (now - BPF_CORE_READ(task, start_time)) / 1000;
162: (7b) *(u64 *)(r10 -40) = r8      ; R8_w=scalar() R10=fp0 fp-40_w=mmmmmmmm
163: (b7) r1 = 1352                   ; R1_w=1352
164: (0f) r7 += r1                    ; R1_w=1352 R7_w=scalar()
165: (bf) r1 = r10                    ; R1_w=fp0 R10=fp0
; data.meta.cpu = task_cpu(task);
166: (07) r1 += -120                  ; R1_w=fp-120
; const struct mm_struct* mm = BPF_CORE_READ(task, mm);
167: (b7) r2 = 8                      ; R2_w=8
168: (bf) r3 = r7                     ; R3_w=scalar(id=4) R7_w=scalar(id=4)
169: (85) call bpf_probe_read_kernel#113      ; R0_w=scalar() fp-120=mmmmmmmm
170: (b7) r8 = 0                      ; R8_w=0
; const struct mm_struct* mm = BPF_CORE_READ(task, mm);
171: (79) r7 = *(u64 *)(r10 -120)     ; R7_w=scalar() R10=fp0
; if (mm) {
172: (15) if r7 == 0x0 goto pc+26     ; R7_w=scalar()
173: <invalid CO-RE relocation>
failed to resolve CO-RE relocation <byte_off> [135] struct mm_struct.rss_stat.count[0].counter (0:0:42:0:0:0 @ offset 712)
processed 172 insns (limit 1000000) max_states_per_insn 0 total_states 9 peak_states 9 mark_read 9
-- END PROG LOAD LOG --
libbpf: prog 'tracepoint__sched__sched_process_exit': failed to load: -22
libbpf: failed to load object 'exitstat_bpf'
libbpf: failed to load BPF skeleton 'exitstat_bpf': -22
brianc118 commented 1 year ago

Looks like https://lore.kernel.org/all/20221024052841.3291983-1-shakeelb@google.com/T/#u changes rss_stat to a per-cpu counter

Let me figure out how to fix this.

brianc118 commented 1 year ago

@shtirlic this should be fixed with e96c4280b872b03fc5c159d2acf885023989af61. Let me know if it doesn't work.

brianc118 commented 1 year ago

@shtirlic can you try installing the latest version of below (0.7.0) and see if that fixes the issue? If you are building from source / using cargo install you'll need clang-15+.