sysmon.service failed because the control process exited with error code

[team480]

Sysmon on a Red Hat Enterprise Linux release 8.4 (Ootpa) running on a Oracle VirtuabBox failed to run. From the journalctl -xe file: sysmon[3080]: parent already had regs=0 stack=0 marks sysmon[3080]: math between map_value pointer and register with unbounded min value is not allowed sysmon[3080]: processed 4010 insns (limit 1000000) max_states_per_insn 6 total_states 264 peak_states 251 mark_read 105 sysmon[3080]: -- END PROG LOAD LOG -- sysmon[3080]: libbpf: prog 'ProcCreateRawExit': failed to load: -22 sysmon[3080]: libbpf: failed to load object './/sysmonEBPFkern4.17-5.1_core.o' sysmon[3080]: ERROR: failed to load prog: 'Invalid argument' sysmon[3080]: Telemetry failed to start: eBPF object could not be loaded

As a newbie will appreciate how to proceed.

[MarioHewardt]

Can you add the -t switch and paste a more complete log from ''journalctl -xe"?

Also, is this file present on the system? /sys/kernel/btf/vmlinux

[MarioHewardt]

@team480 - I reproduced the issue and a fix will be pushed shortly.

[MarioHewardt]

@team480 - Fix has now been merged. Please try it out and let me know. Thanks.

[team480]

Hi @MarioHewardt - file vmlinux - exists.

From the ''journalctl -xe":

Mar 28 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 926: (79) r8 = (u64 )(r10 -72) Mar 28 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; event->m_Extensions[PC_CommandLine] = extLen; Mar 28 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 927: (79) r1 = (u64 )(r10 -64) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 928: (63) (u32 )(r1 +108) = r8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: R0=inv0 R1_w=map_value(id=0,off=0,ks=4,vs=65512,imm=0) R2=inv0 R6=inv(id=0) R7=invP0 R8_w=inv(id=0) R9=map_value(id=0,off=128,ks=4,vs=65512,imm> 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 929: (b7) r1 = 2840 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 930: (79) r6 = (u64 )(r10 -80) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 931: (0f) r6 += r1 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 932: (bf) r1 = r10 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 933: (07) r1 += -32 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; dentry = BPF_CORE_READ((struct task_struct )base, fs, pwd.dentry); 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 934: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 935: (bf) r3 = r6 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 936: (85) call bpf_probe_read_kernel#113 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: last_idx 936 first_idx 926 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=4 stack=0 before 935: (bf) r3 = r6 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=4 stack=0 before 934: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 937: (b7) r1 = 48 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 938: (79) r3 = (u64 )(r10 -32) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 939: (0f) r3 += r1 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 940: (bf) r1 = r10 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 941: (07) r1 += -24 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; dentry = BPF_CORE_READ((struct task_struct )base, fs, pwd.dentry); 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 942: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 943: (85) call bpf_probe_read_kernel#113 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: last_idx 943 first_idx 926 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=4 stack=0 before 942: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 944: (7b) (u64 )(r10 -56) = r9 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ; ptr += (extLen & (CMDLINE_MAX_LEN - 1)); 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 945: (bf) r7 = r9 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: 946: (0f) r7 += r8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: last_idx 946 first_idx 944 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 945: (bf) r7 = r9 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 944: (7b) (u64 )(r10 -56) = r9 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: R0_w=inv(id=0) R6_w=inv(id=0) R7=invP0 R8_rw=invP(id=0) R9_r=map_value(id=0,off=128,ks=4,vs=65512,imm=0) R10=fp0 fp-24=mmmmmmmm fp-32=mmmmmmmm > 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: parent didn't have regs=100 stack=0 marks 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: last_idx 943 first_idx 926 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 943: (85) call bpf_probe_read_kernel#113 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 942: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 941: (07) r1 += -24 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 940: (bf) r1 = r10 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 939: (0f) r3 += r1 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 938: (79) r3 = (u64 )(r10 -32) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 937: (b7) r1 = 48 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 936: (85) call bpf_probe_read_kernel#113 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 935: (bf) r3 = r6 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 934: (b7) r2 = 8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 933: (07) r1 += -32 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 932: (bf) r1 = r10 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 931: (0f) r6 += r1 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 930: (79) r6 = (u64 )(r10 -80) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 929: (b7) r1 = 2840 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 928: (63) (u32 )(r1 +108) = r8 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 927: (79) r1 = (u64 )(r10 -64) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: regs=100 stack=0 before 926: (79) r8 = (u64 )(r10 -72) 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: R0_w=inv0 R1_w=map_value(id=0,off=128,ks=4,vs=65512,umax_value=16383,var_off=(0x0; 0x3fff)) R2_w=inv0 R6=inv(id=0) R7=invP0 R8_w=invP(id=0,umax> 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: parent already had regs=0 stack=0 marks 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: math between map_value pointer and register with unbounded min value is not allowed 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: processed 4010 insns (limit 1000000) max_states_per_insn 6 total_states 264 peak_states 251 mark_read 105 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: -- END PROG LOAD LOG -- 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: libbpf: prog 'ProcCreateRawExit': failed to load: -22 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: libbpf: failed to load object './/sysmonEBPFkern4.17-5.1_core.o' 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: ERROR: failed to load prog: 'Invalid argument' 19:28:09 RHEL8.4.myguest.virtualbox.org sysmon[1684]: Telemetry failed to start: eBPF object could not be loaded

Could you elaborate the full command context "with a -t"?

[MarioHewardt]

Hi, I was able to reproduce the issue and the fix has been merged. For now, you will need to build Sysmon until a new package has been released (preliminary in a couple of days).

The -t switch adds extended logging that is helpful when troubleshooting. You can add it as a switch when starting sysmon. For example:

sudo sysmon -t -i sysmon_config_file

[macolinob]

I have this issue as well with a Proxmox LXC

Proxmox version 7.4-3 Guest is Ubuntu 22.04

Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sched/sched_process_exit': relo #5: insn #117 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'ProcTerminated': found map 7 (perfErrorsMap, sec 13, off 224) for insn #117 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': collecting relocation for section(9) 'tracepoint/sock/inet_soc> Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #0: insn #9 against 'configMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 0 (configMap, sec 13, off 0) for insn #9 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #1: insn #22 against 'eventStorageMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 8 (eventStorageMap, sec 13, off 256) for insn #22 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #2: insn #144 against 'eventMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 5 (eventMap, sec 13, off 160) for insn #144 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #3: insn #157 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 7 (perfErrorsMap, sec 13, off 224) for insn #157 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #4: insn #169 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 7 (perfErrorsMap, sec 13, off 224) for insn #169 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/sock/inet_sock_set_state': relo #5: insn #182 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'TCPconnection': found map 7 (perfErrorsMap, sec 13, off 224) for insn #182 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': collecting relocation for section(11) 'tracepoint/skb/consume_skb' Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #0: insn #10 against 'configMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 0 (configMap, sec 13, off 0) for insn #10 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #1: insn #44 against 'packetStorageMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 3 (packetStorageMap, sec 13, off 96) for insn #44 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #2: insn #420 against 'UDPsendAge' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 4 (UDPsendAge, sec 13, off 128) for insn #420 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #3: insn #441 against 'UDPsendAge' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 4 (UDPsendAge, sec 13, off 128) for insn #441 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #4: insn #449 against 'eventStorageMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 8 (eventStorageMap, sec 13, off 256) for insn #449 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #5: insn #548 against 'eventMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 5 (eventMap, sec 13, off 160) for insn #548 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #6: insn #561 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 7 (perfErrorsMap, sec 13, off 224) for insn #561 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #7: insn #573 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 7 (perfErrorsMap, sec 13, off 224) for insn #573 Apr 05 10:21:50 lino sysmon[47250]: libbpf: sec '.reltracepoint/skb/consume_skb': relo #8: insn #586 against 'perfErrorsMap' Apr 05 10:21:50 lino sysmon[47250]: libbpf: prog 'UDPsend': found map 7 (perfErrorsMap, sec 13, off 224) for insn #586 Apr 05 10:21:50 lino sysmon[47250]: libbpf: Failed to bump RLIMIT_MEMLOCK (err = -1), you might need to do it explicitly! Apr 05 10:21:50 lino sysmon[47250]: libbpf: Error in bpf_object__probe_loading():Operation not permitted(1). Couldn't load trivial BPF program. Make sure> Apr 05 10:21:50 lino sysmon[47250]: libbpf: failed to load object './/sysmonEBPFkern5.6-_core.o' Apr 05 10:21:50 lino sysmon[47250]: ERROR: failed to load prog: 'Operation not permitted' Apr 05 10:21:50 lino sysmon[47204]: Telemetry failed to start: eBPF object could not be loaded

[MarioHewardt]

@macolinob - Please file a new issue (looks to be different than the one reported here).

[MarioHewardt]

@team480 - Since a fix has been merged, I'm closing this issue. If you see it again, please feel free to reopen. Thanks.