Skip to content

"shared mem buffer full" after ~1s of recording #7

@michaellilltokiwa

Description

@michaellilltokiwa

sudo ./build/bin/feeze_recorder
[sudo] password for sam:
entries start offset 0x20, entry size 0x40
sched starting:
libbpf: loading object 'feeze_recorder_bpf' from buffer
libbpf: elf: section(3) tracepoint/sched/sched_switch, size 744, link 0, flags 6, type=1
libbpf: sec 'tracepoint/sched/sched_switch': found program 'on_task_switch' at insn offset 0 (0 bytes), code size 93 insns (744 bytes)
libbpf: elf: section(4) .reltracepoint/sched/sched_switch, size 32, link 26, flags 40, type=9
libbpf: elf: section(5) license, size 7, link 0, flags 3, type=1
libbpf: license of feeze_recorder_bpf is AGPLv3
libbpf: elf: section(6) .maps, size 48, link 0, flags 3, type=1
libbpf: elf: section(16) .BTF, size 3481, link 0, flags 0, type=1
libbpf: elf: section(18) .BTF.ext, size 1932, link 0, flags 0, type=1
libbpf: elf: section(26) .symtab, size 360, link 1, flags 0, type=2
libbpf: looking for externs among 15 symbols...
libbpf: collected 0 externs total
libbpf: map 'heap': at sec_idx 6, offset 0.
libbpf: map 'heap': found type = 6.
libbpf: map 'heap': found key [2], sz = 4.
libbpf: map 'heap': found value [9], sz = 56.
libbpf: map 'heap': found max_entries = 1.
libbpf: map 'rb': at sec_idx 6, offset 32.
libbpf: map 'rb': found type = 27.
libbpf: map 'rb': found max_entries = 10485760.
libbpf: sec '.reltracepoint/sched/sched_switch': collecting relocation for section(3) 'tracepoint/sched/sched_switch'
libbpf: sec '.reltracepoint/sched/sched_switch': relo #0: insn #5 against 'heap'
libbpf: prog 'on_task_switch': found map 0 (heap, sec 6, off 0) for insn #5
libbpf: sec '.reltracepoint/sched/sched_switch': relo #1: insn #85 against 'rb'
libbpf: prog 'on_task_switch': found map 1 (rb, sec 6, off 32) for insn #85
libbpf: object 'feeze_recorder_': failed (-95) to create BPF token from '/sys/fs/bpf', skipping optional step...
libbpf: loaded kernel BTF from '/sys/kernel/btf/vmlinux'
libbpf: sec 'tracepoint/sched/sched_switch': found 36 CO-RE relocations
libbpf: CO-RE relocating [25] struct trace_event_raw_sched_switch: found target candidate [9660] struct trace_event_raw_sched_switch in [vmlinux]
libbpf: prog 'on_task_switch': relo #0: <byte_off> [25] struct trace_event_raw_sched_switch.prev_pid (0:2 @ offset 24)
libbpf: prog 'on_task_switch': relo #0: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_pid (0:2 @ offset 24)
libbpf: prog 'on_task_switch': relo #0: patched insn #10 (LDX/ST/STX) off 24 -> 24
libbpf: prog 'on_task_switch': relo #1: <byte_off> [25] struct trace_event_raw_sched_switch.prev_prio (0:3 @ offset 28)
libbpf: prog 'on_task_switch': relo #1: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_prio (0:3 @ offset 28)
libbpf: prog 'on_task_switch': relo #1: patched insn #12 (LDX/ST/STX) off 28 -> 28
libbpf: prog 'on_task_switch': relo #2: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[0] (0:1:0 @ offset 8)
libbpf: prog 'on_task_switch': relo #2: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[0] (0:1:0 @ offset 8)
libbpf: prog 'on_task_switch': relo #2: patched insn #14 (LDX/ST/STX) off 8 -> 8
libbpf: prog 'on_task_switch': relo #3: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[1] (0:1:1 @ offset 9)
libbpf: prog 'on_task_switch': relo #3: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[1] (0:1:1 @ offset 9)
libbpf: prog 'on_task_switch': relo #3: patched insn #16 (LDX/ST/STX) off 9 -> 9
libbpf: prog 'on_task_switch': relo #4: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[2] (0:1:2 @ offset 10)
libbpf: prog 'on_task_switch': relo #4: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[2] (0:1:2 @ offset 10)
libbpf: prog 'on_task_switch': relo #4: patched insn #18 (LDX/ST/STX) off 10 -> 10
libbpf: prog 'on_task_switch': relo #5: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[3] (0:1:3 @ offset 11)
libbpf: prog 'on_task_switch': relo #5: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[3] (0:1:3 @ offset 11)
libbpf: prog 'on_task_switch': relo #5: patched insn #20 (LDX/ST/STX) off 11 -> 11
libbpf: prog 'on_task_switch': relo #6: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[4] (0:1:4 @ offset 12)
libbpf: prog 'on_task_switch': relo #6: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[4] (0:1:4 @ offset 12)
libbpf: prog 'on_task_switch': relo #6: patched insn #22 (LDX/ST/STX) off 12 -> 12
libbpf: prog 'on_task_switch': relo #7: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[5] (0:1:5 @ offset 13)
libbpf: prog 'on_task_switch': relo #7: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[5] (0:1:5 @ offset 13)
libbpf: prog 'on_task_switch': relo #7: patched insn #24 (LDX/ST/STX) off 13 -> 13
libbpf: prog 'on_task_switch': relo #8: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[6] (0:1:6 @ offset 14)
libbpf: prog 'on_task_switch': relo #8: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[6] (0:1:6 @ offset 14)
libbpf: prog 'on_task_switch': relo #8: patched insn #26 (LDX/ST/STX) off 14 -> 14
libbpf: prog 'on_task_switch': relo #9: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[7] (0:1:7 @ offset 15)
libbpf: prog 'on_task_switch': relo #9: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[7] (0:1:7 @ offset 15)
libbpf: prog 'on_task_switch': relo #9: patched insn #28 (LDX/ST/STX) off 15 -> 15
libbpf: prog 'on_task_switch': relo #10: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[8] (0:1:8 @ offset 16)
libbpf: prog 'on_task_switch': relo #10: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[8] (0:1:8 @ offset 16)
libbpf: prog 'on_task_switch': relo #10: patched insn #30 (LDX/ST/STX) off 16 -> 16
libbpf: prog 'on_task_switch': relo #11: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[9] (0:1:9 @ offset 17)
libbpf: prog 'on_task_switch': relo #11: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[9] (0:1:9 @ offset 17)
libbpf: prog 'on_task_switch': relo #11: patched insn #32 (LDX/ST/STX) off 17 -> 17
libbpf: prog 'on_task_switch': relo #12: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[10] (0:1:10 @ offset 18)
libbpf: prog 'on_task_switch': relo #12: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[10] (0:1:10 @ offset 18)
libbpf: prog 'on_task_switch': relo #12: patched insn #34 (LDX/ST/STX) off 18 -> 18
libbpf: prog 'on_task_switch': relo #13: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[11] (0:1:11 @ offset 19)
libbpf: prog 'on_task_switch': relo #13: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[11] (0:1:11 @ offset 19)
libbpf: prog 'on_task_switch': relo #13: patched insn #36 (LDX/ST/STX) off 19 -> 19
libbpf: prog 'on_task_switch': relo #14: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[12] (0:1:12 @ offset 20)
libbpf: prog 'on_task_switch': relo #14: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[12] (0:1:12 @ offset 20)
libbpf: prog 'on_task_switch': relo #14: patched insn #38 (LDX/ST/STX) off 20 -> 20
libbpf: prog 'on_task_switch': relo #15: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[13] (0:1:13 @ offset 21)
libbpf: prog 'on_task_switch': relo #15: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[13] (0:1:13 @ offset 21)
libbpf: prog 'on_task_switch': relo #15: patched insn #40 (LDX/ST/STX) off 21 -> 21
libbpf: prog 'on_task_switch': relo #16: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[14] (0:1:14 @ offset 22)
libbpf: prog 'on_task_switch': relo #16: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[14] (0:1:14 @ offset 22)
libbpf: prog 'on_task_switch': relo #16: patched insn #42 (LDX/ST/STX) off 22 -> 22
libbpf: prog 'on_task_switch': relo #17: <byte_off> [25] struct trace_event_raw_sched_switch.prev_comm[15] (0:1:15 @ offset 23)
libbpf: prog 'on_task_switch': relo #17: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.prev_comm[15] (0:1:15 @ offset 23)
libbpf: prog 'on_task_switch': relo #17: patched insn #44 (LDX/ST/STX) off 23 -> 23
libbpf: prog 'on_task_switch': relo #18: <byte_off> [25] struct trace_event_raw_sched_switch.next_pid (0:6 @ offset 56)
libbpf: prog 'on_task_switch': relo #18: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_pid (0:6 @ offset 56)
libbpf: prog 'on_task_switch': relo #18: patched insn #46 (LDX/ST/STX) off 56 -> 56
libbpf: prog 'on_task_switch': relo #19: <byte_off> [25] struct trace_event_raw_sched_switch.next_prio (0:7 @ offset 60)
libbpf: prog 'on_task_switch': relo #19: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_prio (0:7 @ offset 60)
libbpf: prog 'on_task_switch': relo #19: patched insn #48 (LDX/ST/STX) off 60 -> 60
libbpf: prog 'on_task_switch': relo #20: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[0] (0:5:0 @ offset 40)
libbpf: prog 'on_task_switch': relo #20: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[0] (0:5:0 @ offset 40)
libbpf: prog 'on_task_switch': relo #20: patched insn #50 (LDX/ST/STX) off 40 -> 40
libbpf: prog 'on_task_switch': relo #21: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[1] (0:5:1 @ offset 41)
libbpf: prog 'on_task_switch': relo #21: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[1] (0:5:1 @ offset 41)
libbpf: prog 'on_task_switch': relo #21: patched insn #52 (LDX/ST/STX) off 41 -> 41
libbpf: prog 'on_task_switch': relo #22: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[2] (0:5:2 @ offset 42)
libbpf: prog 'on_task_switch': relo #22: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[2] (0:5:2 @ offset 42)
libbpf: prog 'on_task_switch': relo #22: patched insn #54 (LDX/ST/STX) off 42 -> 42
libbpf: prog 'on_task_switch': relo #23: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[3] (0:5:3 @ offset 43)
libbpf: prog 'on_task_switch': relo #23: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[3] (0:5:3 @ offset 43)
libbpf: prog 'on_task_switch': relo #23: patched insn #56 (LDX/ST/STX) off 43 -> 43
libbpf: prog 'on_task_switch': relo #24: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[4] (0:5:4 @ offset 44)
libbpf: prog 'on_task_switch': relo #24: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[4] (0:5:4 @ offset 44)
libbpf: prog 'on_task_switch': relo #24: patched insn #58 (LDX/ST/STX) off 44 -> 44
libbpf: prog 'on_task_switch': relo #25: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[5] (0:5:5 @ offset 45)
libbpf: prog 'on_task_switch': relo #25: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[5] (0:5:5 @ offset 45)
libbpf: prog 'on_task_switch': relo #25: patched insn #60 (LDX/ST/STX) off 45 -> 45
libbpf: prog 'on_task_switch': relo #26: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[6] (0:5:6 @ offset 46)
libbpf: prog 'on_task_switch': relo #26: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[6] (0:5:6 @ offset 46)
libbpf: prog 'on_task_switch': relo #26: patched insn #62 (LDX/ST/STX) off 46 -> 46
libbpf: prog 'on_task_switch': relo #27: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[7] (0:5:7 @ offset 47)
libbpf: prog 'on_task_switch': relo #27: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[7] (0:5:7 @ offset 47)
libbpf: prog 'on_task_switch': relo #27: patched insn #64 (LDX/ST/STX) off 47 -> 47
libbpf: prog 'on_task_switch': relo #28: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[8] (0:5:8 @ offset 48)
libbpf: prog 'on_task_switch': relo #28: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[8] (0:5:8 @ offset 48)
libbpf: prog 'on_task_switch': relo #28: patched insn #66 (LDX/ST/STX) off 48 -> 48
libbpf: prog 'on_task_switch': relo #29: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[9] (0:5:9 @ offset 49)
libbpf: prog 'on_task_switch': relo #29: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[9] (0:5:9 @ offset 49)
libbpf: prog 'on_task_switch': relo #29: patched insn #68 (LDX/ST/STX) off 49 -> 49
libbpf: prog 'on_task_switch': relo #30: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[10] (0:5:10 @ offset 50)
libbpf: prog 'on_task_switch': relo #30: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[10] (0:5:10 @ offset 50)
libbpf: prog 'on_task_switch': relo #30: patched insn #70 (LDX/ST/STX) off 50 -> 50
libbpf: prog 'on_task_switch': relo #31: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[11] (0:5:11 @ offset 51)
libbpf: prog 'on_task_switch': relo #31: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[11] (0:5:11 @ offset 51)
libbpf: prog 'on_task_switch': relo #31: patched insn #72 (LDX/ST/STX) off 51 -> 51
libbpf: prog 'on_task_switch': relo #32: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[12] (0:5:12 @ offset 52)
libbpf: prog 'on_task_switch': relo #32: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[12] (0:5:12 @ offset 52)
libbpf: prog 'on_task_switch': relo #32: patched insn #74 (LDX/ST/STX) off 52 -> 52
libbpf: prog 'on_task_switch': relo #33: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[13] (0:5:13 @ offset 53)
libbpf: prog 'on_task_switch': relo #33: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[13] (0:5:13 @ offset 53)
libbpf: prog 'on_task_switch': relo #33: patched insn #76 (LDX/ST/STX) off 53 -> 53
libbpf: prog 'on_task_switch': relo #34: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[14] (0:5:14 @ offset 54)
libbpf: prog 'on_task_switch': relo #34: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[14] (0:5:14 @ offset 54)
libbpf: prog 'on_task_switch': relo #34: patched insn #78 (LDX/ST/STX) off 54 -> 54
libbpf: prog 'on_task_switch': relo #35: <byte_off> [25] struct trace_event_raw_sched_switch.next_comm[15] (0:5:15 @ offset 55)
libbpf: prog 'on_task_switch': relo #35: matching candidate #0 <byte_off> [9660] struct trace_event_raw_sched_switch.next_comm[15] (0:5:15 @ offset 55)
libbpf: prog 'on_task_switch': relo #35: patched insn #80 (LDX/ST/STX) off 55 -> 55
libbpf: map 'heap': created successfully, fd=4
libbpf: map 'rb': created successfully, fd=5
thread switch 1: 1992/1937339243 (temstats) -> 0/0 () at 140724603453439ns
thread switch 2: 1992/1992 (k) -> 0/0 () at 140543891876224ns
thread switch 4: 0/-1 (s) -> 0/0 () at 140543891876224ns
thread switch 8: 1838/120 (kded6) -> 0/120 (swapper/8) at 3213305211018ns
thread switch 16: 1140/1140 (u) -> 0/0 () at 14ns
thread switch 32: 0/120 (swapper/2) -> 1/120 (systemd) at 3213305433145ns
thread switch 64: 2107/1969971577 (ake) -> 0/0 () at 4294967295ns
thread switch 128: 0/120 (swapper/11) -> 614/120 (kworker/u48:1) at 3213312138584ns
thread switch 256: 2107/120 (yakuake) -> 0/120 (swapper/2) at 3213323607226ns
thread switch 512: 0/120 (swapper/1) -> 5774/120 (ThreadPoolSingl) at 3213414919905ns
thread switch 1024: 0/120 (swapper/9) -> 7904/120 (BBBBB) at 3213507187485ns
thread switch 2048: 0/120 (swapper/4) -> 7903/120 (AAAAA) at 3213508795407ns
thread switch 4096: 0/120 (swapper/4) -> 7903/120 (AAAAA) at 3213512127846ns
thread switch 8192: 0/120 (swapper/10) -> 7904/120 (BBBBB) at 3213518871655ns
thread switch 16384: 0/120 (swapper/5) -> 7903/120 (AAAAA) at 3213532376851ns
thread switch 32768: 7903/120 (AAAAA) -> 0/120 (swapper/11) at 3213559128757ns
thread switch 65536: 7904/120 (BBBBB) -> 0/120 (swapper/9) at 3213612304378ns
thread switch 131072: 0/120 (swapper/2) -> 7904/120 (BBBBB) at 3213678883030ns
thread switch 262144: 7903/120 (AAAAA) -> 0/120 (swapper/1) at 3214209419688ns
thread switch 524288: 7903/120 (AAAAA) -> 0/120 (swapper/1) at 3215278463754ns
shared mem buffer full
make: *** [Makefile:123: run_recorder] Error 1

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions