https://github.com/osquery/osquery logo
Join Slack
Powered by
<@U6EFFT5FG> I’ve been seeing this too. Giving som...
# ebpf
z
@alessandrogario I’ve been seeing this too. Giving some information:
Copy code
[STD-DEV]15:26:53 root@si-i-0fe66e9061a89d90d /home/zmackie # uname -a
Linux si-i-0fe66e9061a89d90d 5.4.0-1054-aws #57~18.04.1-Ubuntu SMP Thu Jul 15 03:21:36 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
[STD-DEV]15:26:55 root@si-i-0fe66e9061a89d90d /home/zmackie # cat /etc/issue
Ubuntu 18.04.5 LTS \n \l
With 
--verbose
a
I'll create a PR with the fix I was talking about
Would it be possible to test it on your system? I used kernel 4.19 on Debian Stretch to replicate the problem, and switching from In to Out alleviated the issue
I believe newer kernels will have better handling of page faults
Some things can't be switched from In to Out though (like execve, execveat for example, because when we exit the system call the mapped memory will change)
z
I can test it yes.
a
🦜 2
z
Ah great. Will test out today.
a
Thanks! This should at least improve the situation 🙂
z
Copy code
I0908 16:45:09.437614 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fork (20)
I0908 16:45:09.442298 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall vfork (28)
I0908 16:45:09.447696 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall clone (36)
I0908 16:45:09.451020 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall close (44)
I0908 16:45:09.454308 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup (50)
I0908 16:45:09.457621 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup2 (56)
I0908 16:45:09.460983 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup3 (62)
I0908 16:45:09.471495 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall creat (71)
I0908 16:45:09.475664 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknod (77)
I0908 16:45:09.479838 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknodat (83)
I0908 16:45:09.490257 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open (91)
I0908 16:45:09.494812 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall openat (97)
I0908 16:45:09.494910 25867 bpfeventpublisher.cpp:243] Failed to load the BPF probe for syscall openat2: Failed to open the tracepoint descriptor file: /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat2/id. This syscall may not be available on this system, continuing despite the error
I0908 16:45:09.504556 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall socket (105)
I0908 16:45:09.507974 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fcntl (111)
I0908 16:45:09.512300 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall connect (117)
I0908 16:45:09.516983 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept (123)
I0908 16:45:09.521683 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept4 (129)
I0908 16:45:09.525904 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall bind (135)
I0908 16:45:09.529222 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall listen (141)
I0908 16:45:09.539371 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall chdir (149)
I0908 16:45:09.542677 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fchdir (155)
I0908 16:45:09.547883 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall name_to_handle_at (161)
I0908 16:45:09.551900 25867 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open_by_handle_at (167)
I0908 16:45:09.674875 25867 bpfeventpublisher.cpp:243] Failed to load the BPF probe for syscall execve: The 'enter' program could not be loaded: The program could not be loaded: 0: (bf) r8 = r1
Then there was a bunch of what looks like bpf ouput:
Copy code
I0908 16:45:09.674875 25867 bpfeventpublisher.cpp:243] Failed to load the BPF probe for syscall execve: The 'enter' program could not be loaded: The program could not be loaded: 0: (bf) r8 = r1
1: (85) call bpf_get_current_pid_tgid#14
2: (77) r0 >>= 32
3: (55) if r0 != 0x650b goto pc+2
 R0_w=inv25867 R8_w=ctx(id=0,off=0,imm=0) R10=fp0
4: (b7) r0 = 0
5: (95) exit

from 3 to 6: R0_w=inv(id=0,umax_value=4294967295,var_off=(0x0; 0xffffffff)) R8_w=ctx(id=0,off=0,imm=0) R10=fp0
6: (b7) r7 = 0
7: (63) *(u32 *)(r10 -172) = r7
last_idx 7 first_idx 0
regs=80 stack=0 before 6: (b7) r7 = 0
8: (18) r1 = 0xffff901d8f2eae00
10: (bf) r2 = r10
11: (07) r2 += -172
12: (85) call bpf_map_lookup_elem#1
13: (bf) r6 = r0
14: (55) if r6 != 0x0 goto pc+2
 R0=inv0 R6_w=inv0 R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
15: (b7) r0 = 0
16: (95) exit

from 14 to 17: R0=map_value(id=0,off=0,ks=4,vs=92,imm=0) R6_w=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
17: (b7) r1 = 175
18: (7b) *(u64 *)(r6 +4) = r1
 R0=map_value(id=0,off=0,ks=4,vs=92,imm=0) R1_w=inv175 R6_w=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
19: (b7) r1 = 92
20: (63) *(u32 *)(r6 +0) = r1
 R0=map_value(id=0,off=0,ks=4,vs=92,imm=0) R1_w=inv92 R6_w=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
21: (85) call bpf_ktime_get_ns#5
22: (7b) *(u64 *)(r6 +12) = r0
 R0=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
23: (85) call bpf_get_current_pid_tgid#14
24: (7b) *(u64 *)(r6 +20) = r0
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
25: (85) call bpf_get_current_uid_gid#15
26: (7b) *(u64 *)(r6 +28) = r0
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
27: (85) call bpf_get_current_cgroup_id#80
28: (7b) *(u64 *)(r6 +36) = r0
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
29: (7b) *(u64 *)(r6 +60) = r7
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
30: (7b) *(u64 *)(r6 +52) = r7
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
31: (7b) *(u64 *)(r6 +44) = r7
 R0_w=inv(id=0) R6=map_value(id=0,off=0,ks=4,vs=92,imm=0) R7=invP0 R8=ctx(id=0,off=0,imm=0) R10=fp0 fp-176=mmmm????
32: (63) *(u32 *)(r10 -172) = r7
33: (18) r1 = 0xffff901d8f2eac00
35: (bf) r2 = r10
36: (07) r2 += -172
37: (85) call bpf_map_lookup_elem#1
etc. Tables don’t seem to be working:
Copy code
osquery> select * from bpf_socket_events;
osquery>
a
thanks for testing this! can you tell me which distro and kernel version are you using?
is this still debian stretch with kernel 4.19?
z
Copy code
[STD-DEV]19:53:43 zmackie@si-i-0fe66e9061a89d90d ~ $ uname -srm
Linux 5.4.0-1054-aws x86_64
[STD-DEV]19:53:45 zmackie@si-i-0fe66e9061a89d90d ~ $ cat /etc/issue
Ubuntu 18.04.5 LTS \n \l
a
I've updated the PR, hopefully the packages will be created soon by the CI
z
Ok great. I’ll test it out today.
❤️ 1
Still seems to be acting up a bit, but the tables are populating at least:
Copy code
[STD-DEV]16:56:12 root@si-i-02caa65087583c219 /home/zmackie # osqueryi --flagfile=/etc/osquery/osquery.flags --config_path /etc/osquery/osquery.conf --disable_events=false --enable_bpf_events=true --verbose
I0915 16:56:23.435357  3334 init.cpp:357] osquery initialized [version=5.0.1-5-gd63adb159]
I0915 16:56:23.435413  3334 extensions.cpp:453] Could not autoload extensions: Cannot open file for reading: /etc/osquery/extensions.load
I0915 16:56:23.435511  3334 dispatcher.cpp:78] Adding new service: ExtensionWatcher (0x555dd0005ad8) to thread: 139808879249152 (0x555dd0004820) in process 3334
I0915 16:56:23.435555  3334 dispatcher.cpp:78] Adding new service: ExtensionRunnerCore (0x555dd0005e58) to thread: 139808870856448 (0x555dd0006060) in process 3334
I0915 16:56:23.435577  3334 auto_constructed_tables.cpp:97] Removing stale ATC entries
I0915 16:56:23.435611  3336 interface.cpp:299] Extension manager service starting: /root/.osquery/shell.em
I0915 16:56:23.435998  3334 packs.cpp:177] No queries defined for pack testing
W0915 16:56:23.436026  3334 config.cpp:755] Error reading the query pack named: osquery-monitoring
I0915 16:56:23.437970  3334 virtual_table.cpp:1081] Table curl is disabled, not attaching
I0915 16:56:23.449920  3334 smbios_tables.cpp:105] Reading SMBIOS from sysfs DMI node
I0915 16:56:23.469677  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fork (20)
I0915 16:56:23.474203  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall vfork (28)
I0915 16:56:23.479529  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall clone (36)
I0915 16:56:23.482815  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall close (44)
I0915 16:56:23.486101  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup (50)
I0915 16:56:23.489410  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup2 (56)
I0915 16:56:23.492754  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup3 (62)
I0915 16:56:23.503108  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall creat (71)
I0915 16:56:23.507138  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknod (77)
I0915 16:56:23.511209  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknodat (83)
I0915 16:56:23.521512  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open (91)
I0915 16:56:23.525660  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall openat (97)
I0915 16:56:23.525754  3334 bpfeventpublisher.cpp:243] Failed to load the BPF probe for syscall openat2: Failed to open the tracepoint descriptor file: /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat2/id. This syscall may not be available on this system, continuing despite the error
I0915 16:56:23.535298  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall socket (105)
I0915 16:56:23.538671  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fcntl (111)
I0915 16:56:23.542870  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall connect (117)
I0915 16:56:23.547585  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept (123)
I0915 16:56:23.552459  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept4 (129)
I0915 16:56:23.556568  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall bind (135)
I0915 16:56:23.559815  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall listen (141)
I0915 16:56:23.571007  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall chdir (149)
I0915 16:56:23.574292  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fchdir (155)
I0915 16:56:23.579437  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall name_to_handle_at (161)
I0915 16:56:23.583361  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open_by_handle_at (167)
I0915 16:56:23.618160  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall execve (175)
I0915 16:56:23.646396  3334 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall execveat (181)
I0915 16:56:23.681736  3334 eventfactory.cpp:156] Event publisher not enabled: auditeventpublisher: Publisher disabled via configuration
I0915 16:56:23.681777  3334 eventfactory.cpp:156] Event publisher not enabled: syslog: Publisher disabled via configuration
I0915 16:56:23.681882  3334 events.cpp:70] Skipping subscriber: apparmor_events: Subscriber disabled via configuration
I0915 16:56:23.681939  3334 events.cpp:70] Skipping subscriber: process_file_events: Subscriber disabled via configuration
I0915 16:56:23.681952  3334 events.cpp:70] Skipping subscriber: seccomp_events: Seccomp subscriber disabled via configuration
I0915 16:56:23.681962  3334 events.cpp:70] Skipping subscriber: selinux_events: Subscriber disabled via configuration
I0915 16:56:23.681978  3334 events.cpp:70] Skipping subscriber: socket_events: Subscriber disabled via configuration
I0915 16:56:23.682354  3339 eventfactory.cpp:390] Starting event publisher run loop: BPFEventPublisher
I0915 16:56:23.682379  3340 eventfactory.cpp:390] Starting event publisher run loop: inotify
Using a virtual database. Need help, type '.help'
I0915 16:56:23.682407  3341 eventfactory.cpp:390] Starting event publisher run loop: udev
osquery> I0915 16:56:35.073837  3339 bpfeventpublisher.cpp:341] Lost BPF events counter: 9283
I0915 16:56:35.110466  3339 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #97
I0915 16:56:35.118145  3339 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #97
E0915 16:56:35.182487  3339 bpfeventpublisher.cpp:381] BPFEventPublisher has encountered 2 malformed events
[STD-DEV]17:02:25 root@si-i-02caa65087583c219 /home/zmackie # echo "select * from osquery_info;" | osqueryi
W0915 17:02:28.368788 16518 config.cpp:755] Error reading the query pack named: osquery-monitoring
+-------+--------------------------------------+--------------------------------------+--------------------+------------------------------------------+--------------+------------+----------------+--------------+------------+---------+---------------+
| pid   | uuid                                 | instance_id                          | version            | config_hash                              | config_valid | extensions | build_platform | build_distro | start_time | watcher | platform_mask |
+-------+--------------------------------------+--------------------------------------+--------------------+------------------------------------------+--------------+------------+----------------+--------------+------------+---------+---------------+
| 16518 | ec29909d-71b1-7cd2-d9ee-2bf019d2a31b | f555a96f-e9ff-4da5-9591-434d588ce084 | 5.0.1-5-gd63adb159 | 8f988a69ffeeac0cca33904ed4227b8a06b4d32c | 1            | inactive   | linux          | centos7      | 1631725348 | -1      | 9             |
+-------+--------------------------------------+--------------------------------------+--------------------+------------------------------------------+--------------+------------+----------------+--------------+------------+---------+---------------+
[STD-DEV]17:02:29 root@si-i-02caa65087583c219 /home/zmackie #
a
You may need to increase the perf output size to solve the following issue:
Copy code
I0915 16:56:35.073837  3339 bpfeventpublisher.cpp:341] Lost BPF events counter: 9283
Events are being lost even before osquery has a chance to look at the perf output
That is a message generated by the kernel, whenever it detects that the perf ring buffer has wrapped around, overwriting data we didn't have a chance to read
z
Gotcha. You know how to tune that offhand? I’m digging…
a
z
TY!
That seems to have helped with those lost event counter messages
🎉 1
a
If the fix actually works, could you mention it in the PR with a comments? 🙂
I'll look at the memory issue next
z
I’m still seeing the malformed event warnings, but the lost event counter warnings are gone. Left comments in the PR.
a
I see! I can't update the execve as I did with the other syscalls 😞
The filename parameter needs to be capture upon entering the syscalls, because when we are at the exit the original address space is lost
13 Views
Open in Slack
PreviousNext
Powered by