https://github.com/osquery/osquery logo
Join Slack
Powered by
do the ebpf socket and process tables age out or o...
# ebpf
m
do the ebpf socket and process tables age out or otherwise trim records? Looking that the ever-increasing memory utilization we’ve been seeing, and we can see that those tables seem to continue to grow in record count.
z
Spitballing here, but you could watch the size of the database? That has to be loaded in memory so if its growing unboundedly that’d be bad.
m
we’ve been watching the record card so far, which has continued to grow
do you know how to get the total db size?
z
Something like 
du -h /var/osquery/osquery.db
(I believe)
m
ah! so it’s cached on disk? I thought it was wholly in memory
but this is the deepest I’ve been into osquery so far heh
z
Not sure exactly when its flushed to disk, but that’s the backing for it. You can, for example, load that db with osqueryi to see all the events the daemon is collecting (although not at the same time as the daemon - there’s a lock)
z
I'll watch the size of the DB for a while, right now it's at 38MB
the 
bpf_socket_events
table eventually started to get trimmed/pruned and osqueryi also stablized around 538MB taken for it's process and stopped increasing
z
And you’re still having OOM issues? BTW I remembered you can tune events a bit if needed: https://osquery.readthedocs.io/en/latest/installation/cli-flags/#events-control-flags Depending on your query schedule you could shrink 
--events_max=50000
or 
--events_expiry=3600
I wonder if you could shrink events_max and test if that helps things? And BTW, @Matt Uebel I saw this, germaine to the backing store and events:
Expiration age for evented data (in seconds), applied once the data is queried. Until an evented table is queried, its collected events are cached in backing-store. Events are only expired (i.e., removed from the table) when the evented table is queried. For example, if --events_expiry=1, then events older than 1 second will only appear in the next SELECT from the subscriber. If no SELECT occurs, those events will be saved in the backing store indefinitely or until the events_max limit is reached (see below). If, on the other hand, the table contains recent events that have not yet reached expiration age, the same table can be queried repeatedly in quick succession and the same data will continue to be present unless it had reached the expiration age when it was last queried, at which point it will be removed. 3600 seconds is the default, but if querying on an interval shorter than 3600, you may wish to lower this value to avoid retrieving duplicate events.
(still not sure if that indicated being flushed to disk, but my guess is yes)
m
I remembered you can tune events a bit if needed:
events == records in tables?
z
events == records in 
*_events
tables
m
👍
looks like this gives us some options, we don’t have any of the 
events_*
flags set
although we did have more events than 
--events_max=50000
Zac would know better, but I think we had ~200,000 events in one of the tables, and that was at a point where it was still growing
we’ve seen osquery use >2GB with the latest trial in prod (had watchdog set to 2GB)
z
oh nice I'll take a look at those flags and try them out
a
m
Monday at the latest! 🙇‍♂️
a
Whenever you have time! Thanks so much for helping us test this!
z
Will take a spin monday. Thank you!
❤️ 1
z
Just checked it out on a test instance and I'm not seeing any malformed events and osqueryd is only using about 100mb of ram with bpf_events enabled
🙌 2
a
that is great to hear! thanks so much for testing it! Can you leave a comment to the PR?
👍 1
z
Copy code
[STD-DEV]20:34:16 root@si-i-0e48e6f2c9f015d2f /home/zmackie # osqueryi --flagfile=/etc/osquery/osquery.flags --config_path /etc/osquery/osquery.conf --disable_events=false --enable_bpf_events=true --verbose
I1004 20:35:18.236025 25045 init.cpp:357] osquery initialized [version=5.0.1-5-gd63adb159]
I1004 20:35:18.236084 25045 extensions.cpp:453] Could not autoload extensions: Cannot open file for reading: /etc/osquery/extensions.load
I1004 20:35:18.236202 25045 dispatcher.cpp:78] Adding new service: ExtensionWatcher (0x561cdd51ead8) to thread: 139672016529152 (0x561cdd51d820) in process 25045
I1004 20:35:18.236251 25045 dispatcher.cpp:78] Adding new service: ExtensionRunnerCore (0x561cdd51ee58) to thread: 139672008136448 (0x561cdd51f060) in process 25045
I1004 20:35:18.236304 25045 auto_constructed_tables.cpp:97] Removing stale ATC entries
I1004 20:35:18.236299 25057 interface.cpp:299] Extension manager service starting: /root/.osquery/shell.em
I1004 20:35:18.236738 25045 packs.cpp:177] No queries defined for pack testing
W1004 20:35:18.236768 25045 config.cpp:755] Error reading the query pack named: osquery-monitoring
I1004 20:35:18.239046 25045 virtual_table.cpp:1081] Table curl is disabled, not attaching
I1004 20:35:18.256918 25045 smbios_tables.cpp:105] Reading SMBIOS from sysfs DMI node
I1004 20:35:18.278662 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fork (20)
I1004 20:35:18.284932 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall vfork (28)
I1004 20:35:18.291116 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall clone (36)
I1004 20:35:18.294901 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall close (44)
I1004 20:35:18.298766 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup (50)
I1004 20:35:18.302650 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup2 (56)
I1004 20:35:18.306568 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall dup3 (62)
I1004 20:35:18.320216 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall creat (71)
I1004 20:35:18.325398 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknod (77)
I1004 20:35:18.331529 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall mknodat (83)
I1004 20:35:18.343015 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open (91)
I1004 20:35:18.348021 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall openat (97)
I1004 20:35:18.348151 25045 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
I1004 20:35:18.358871 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall socket (105)
I1004 20:35:18.363005 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fcntl (111)
I1004 20:35:18.368074 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall connect (117)
I1004 20:35:18.373728 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept (123)
I1004 20:35:18.379179 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall accept4 (129)
I1004 20:35:18.384074 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall bind (135)
I1004 20:35:18.387928 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall listen (141)
I1004 20:35:18.400112 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall chdir (149)
I1004 20:35:18.404018 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall fchdir (155)
I1004 20:35:18.410305 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall name_to_handle_at (161)
I1004 20:35:18.415171 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall open_by_handle_at (167)
I1004 20:35:18.455710 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall execve (175)
I1004 20:35:18.490099 25045 bpfeventpublisher.cpp:256] Initialized BPF probe for syscall execveat (181)
I1004 20:35:18.533653 25045 eventfactory.cpp:156] Event publisher not enabled: auditeventpublisher: Publisher disabled via configuration
I1004 20:35:18.533687 25045 eventfactory.cpp:156] Event publisher not enabled: inotify: Publisher disabled via configuration
I1004 20:35:18.533704 25045 eventfactory.cpp:156] Event publisher not enabled: syslog: Publisher disabled via configuration
I1004 20:35:18.533785 25045 events.cpp:70] Skipping subscriber: apparmor_events: Subscriber disabled via configuration
I1004 20:35:18.533859 25045 events.cpp:70] Skipping subscriber: process_file_events: Subscriber disabled via configuration
I1004 20:35:18.533877 25045 events.cpp:70] Skipping subscriber: seccomp_events: Seccomp subscriber disabled via configuration
I1004 20:35:18.533890 25045 events.cpp:70] Skipping subscriber: selinux_events: Subscriber disabled via configuration
I1004 20:35:18.533905 25045 events.cpp:70] Skipping subscriber: socket_events: Subscriber disabled via configuration
Using a virtual database. Need help, type '.help'
I1004 20:35:18.534046 25174 eventfactory.cpp:390] Starting event publisher run loop: BPFEventPublisher
osquery> I1004 20:35:18.534104 25176 eventfactory.cpp:390] Starting event publisher run loop: udev
I1004 20:35:21.561990 25174 systemstatetracker.cpp:257] Created empty process context for pid 25069. Fields will show up empty
I1004 20:35:22.563069 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.563122 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.563146 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.563165 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.564069 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.564110 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.564128 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.564143 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.568567 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.568610 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.568632 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
I1004 20:35:22.568643 25174 bpfeventpublisher.cpp:374] BPFEventPublisher failed to process event from tracer #175
E1004 20:35:22.572381 25174 bpfeventpublisher.cpp:381] BPFEventPublisher has encountered 12 malformed events
Looks like I’m still getting the malformed events:
a
Is this the correct version? It does not seem to be matching the latest commit
The correct version should be:
Copy code
osqueryi --version
osqueryi version 5.0.1-9-g63e5dd6fb
z
hmmm welp looks like I screwed up my scp.
okay this is what I’m seeing. Much less noisey:
Copy code
[STD-DEV]21:05:06 root@si-i-0e48e6f2c9f015d2f /home/zmackie # osqueryi --flagfile=/etc/osquery/osquery.flags --config_path /etc/osquery/osquery.conf --disable_events=false --enable_bpf_events=true --verbose
I1004 21:05:07.955135 13113 init.cpp:357] osquery initialized [version=5.0.1-9-g63e5dd6fb]
I1004 21:05:07.955199 13113 extensions.cpp:453] Could not autoload extensions: Cannot open file for reading: /etc/osquery/extensions.load
I1004 21:05:07.955307 13113 dispatcher.cpp:78] Adding new service: ExtensionWatcher (0x5648bbc85aa8) to thread: 140594447243008 (0x5648bbc955f0) in process 13113
I1004 21:05:07.955356 13113 dispatcher.cpp:78] Adding new service: ExtensionRunnerCore (0x5648bbc8a978) to thread: 140594438850304 (0x5648bbc85bf0) in process 13113
I1004 21:05:07.955379 13113 auto_constructed_tables.cpp:97] Removing stale ATC entries
I1004 21:05:07.955463 13203 interface.cpp:299] Extension manager service starting: /root/.osquery/shell.em
I1004 21:05:07.955785 13113 packs.cpp:177] No queries defined for pack testing
W1004 21:05:07.955816 13113 config.cpp:755] Error reading the query pack named: osquery-monitoring
I1004 21:05:07.959053 13113 virtual_table.cpp:1081] Table curl is disabled, not attaching
I1004 21:05:07.975880 13113 smbios_tables.cpp:105] Reading SMBIOS from sysfs DMI node
I1004 21:05:07.999199 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall fork (20)
I1004 21:05:08.005453 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall vfork (28)
I1004 21:05:08.014268 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall clone (36)
I1004 21:05:08.018450 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall close (44)
I1004 21:05:08.022289 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall dup (50)
I1004 21:05:08.026479 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall dup2 (56)
I1004 21:05:08.032091 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall dup3 (62)
I1004 21:05:08.044445 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall creat (71)
I1004 21:05:08.049504 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall mknod (77)
I1004 21:05:08.054567 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall mknodat (83)
I1004 21:05:08.067884 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall open (91)
I1004 21:05:08.073886 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall openat (97)
I1004 21:05:08.074015 13113 bpfeventpublisher.cpp:250] 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
I1004 21:05:08.085897 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall socket (105)
I1004 21:05:08.090232 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall fcntl (111)
I1004 21:05:08.095454 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall connect (117)
I1004 21:05:08.102764 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall accept (123)
I1004 21:05:08.109112 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall accept4 (129)
I1004 21:05:08.115283 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall bind (135)
I1004 21:05:08.119899 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall listen (141)
I1004 21:05:08.133257 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall chdir (149)
I1004 21:05:08.137338 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall fchdir (155)
I1004 21:05:08.144110 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall name_to_handle_at (161)
I1004 21:05:08.149477 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall open_by_handle_at (167)
I1004 21:05:08.193707 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall execve (175)
I1004 21:05:08.229805 13113 bpfeventpublisher.cpp:263] Initialized BPF probe for syscall execveat (181)
I1004 21:05:08.279366 13113 eventfactory.cpp:156] Event publisher not enabled: auditeventpublisher: Publisher disabled via configuration
I1004 21:05:08.279400 13113 eventfactory.cpp:156] Event publisher not enabled: inotify: Publisher disabled via configuration
I1004 21:05:08.279417 13113 eventfactory.cpp:156] Event publisher not enabled: syslog: Publisher disabled via configuration
I1004 21:05:08.279505 13113 events.cpp:70] Skipping subscriber: apparmor_events: Subscriber disabled via configuration
I1004 21:05:08.279568 13113 events.cpp:70] Skipping subscriber: process_file_events: Subscriber disabled via configuration
I1004 21:05:08.279589 13113 events.cpp:70] Skipping subscriber: seccomp_events: Seccomp subscriber disabled via configuration
I1004 21:05:08.279609 13113 events.cpp:70] Skipping subscriber: selinux_events: Subscriber disabled via configuration
I1004 21:05:08.279628 13113 events.cpp:70] Skipping subscriber: socket_events: Subscriber disabled via configuration
I1004 21:05:08.279786 13934 eventfactory.cpp:390] Starting event publisher run loop: BPFEventPublisher
Using a virtual database. Need help, type '.help'
I1004 21:05:08.279819 13935 eventfactory.cpp:390] Starting event publisher run loop: udev
osquery> I1004 21:05:11.584556 13934 systemstatetracker.cpp:294] Created empty process context for pid 13336. Fields will show up empty
I1004 21:05:11.584614 13934 systemstatetracker.cpp:294] Created empty process context for pid 13339. Fields will show up empty
I1004 21:05:14.021695 13934 bpferrorstate.cpp:55] Buffers/strings that could not be captured by the probe: 6
I1004 21:05:14.572054 13934 systemstatetracker.cpp:294] Created empty process context for pid 19051. Fields will show up empty
I1004 21:05:14.572099 13934 systemstatetracker.cpp:294] Created empty process context for pid 19050. Fields will show up empty
I1004 21:05:14.572144 13934 systemstatetracker.cpp:294] Created empty process context for pid 18792. Fields will show up empty
I1004 21:05:14.572163 13934 systemstatetracker.cpp:294] Created empty process context for pid 19053. Fields will show up empty
I1004 21:05:14.572185 13934 systemstatetracker.cpp:294] Created empty process context for pid 19052. Fields will show up empty
I1004 21:05:17.569274 13934 systemstatetracker.cpp:294] Created empty process context for pid 25481. Fields will show up empty
I1004 21:05:17.569336 13934 systemstatetracker.cpp:294] Created empty process context for pid 25479. Fields will show up empty
I1004 21:05:20.011721 13934 bpferrorstate.cpp:55] Buffers/strings that could not be captured by the probe: 6
I1004 21:05:20.570852 13934 systemstatetracker.cpp:294] Created empty process context for pid 32490. Fields will show up empty
I1004 21:05:20.570906 13934 systemstatetracker.cpp:294] Created empty process context for pid 32493. Fields will show up empty
I1004 21:05:20.570973 13934 systemstatetracker.cpp:294] Created empty process context for pid 32494. Fields will show up empty
I1004 21:05:22.590359 13934 systemstatetracker.cpp:294] Created empty process context for pid 31807. Fields will show up empty
I1004 21:05:22.593210 13934 systemstatetracker.cpp:294] Created empty process context for pid 31808. Fields will show up empty
I1004 21:05:23.575183 13934 systemstatetracker.cpp:294] Created empty process context for pid 6849. Fields will show up empty
I1004 21:05:23.575224 13934 systemstatetracker.cpp:294] Created empty process context for pid 6851. Fields will show up empty
🚀 1
a
That seems to be much better
When osquery starts, it takes a snapshot of procfs; this could change while the snapshot is being taken, leading to those "created empty process context for pid...."
now in this latest PR, there is also an auto-restart of the system state tracker which creates new snapshots once in a while (configurable with a flag)
the 
Buffers/strings that could not be captured by the probe:
can be 2 things
1. Too many argv 2. An argv entry that is too long
sadly there's not much we can do for that given how BPF works
for 1: we are stuck because we can only have so many BPF instructions in the probe, and they are not enough to capture all the argvs we want (this limit has been relaxed in more recent kernels but we are supporting kernel 4.18+)
for 2: we have to pre-allocate the buffer where we save the string (buffer storage size in the osquery flag options)
we could try to stream strings using perf (which does not require us to pre-allocate everything in advance), but that would also require more instruction space in the probe
z
For 1, I was watching a talk by some of the google krsi folks and they talked about something to do with addressing this problem by adding atomics and using basically “futures” for the argv members, in which a UUID is mapped to an arg, and the probe returns a list off uuids and then subsequently uuid:arg pairs, which allow reconstruction. As you said regarding kernel versions, this might not go back to 4.18. I’ll try and dig up the talk…

https://www.youtube.com/watch?v=N4YKcMV8iaY▾

And oh yeah this is going into 5.12 I think so never mind…
a
Ah, those features are really nice! I am actually considering adding additional functionality reserved for newer kernels
Right now I have a maps where strings are saved, and the event data contains a reference ID to look it up again when reading the probe output from user mode
r
Guys, have you finally be able to stablize the system where you were seeing that ever increasing memory consumption using the event_expiry and event_max tunables? I'm seeing the same behavior on a moderately loaded/beafy system (48 cores, 128GB mem)... I've tried various combination of bpf tunables w/o seeing an improvement. Any hints welcome 🙂 (btw, I'm running 5.1.0 on same kernel mentioned in this thread: 4.19 on Debian 10)
a
Prior to version 5.1.0, there was a memory leak; I believe the problem you are experiencing is different
Is the memory consumption stable within a specific range?
r
Yes, I had followed the discussion about it, that's why we went for 5.1 in the first place. About your question, I'll have to double check. I should have the data early next week. Is there anything else you would advise to collect/look for/test with as parameters?
a
BPF has to correlate many things happening on the system, including all the open/close/dup/fork/execve/socket/accept/listen and variants
If there are many things happening on that host (containers/processes that are opening many files/processes/connections) then it's normal that cpu/memory is used
watchdog limits + bpf memory settings should be raised according to the system load
if the memory is stable within a certain range, everything is fine and it's just the normal process of osquery generating, storing and then expiring the table rows
👍 1
15 Views
Open in Slack
PreviousNext
Powered by