Title
#eclecticiq-polylogyx-extension
l

lvferdi

05/20/2022, 3:53 PM
Is there any other logging location for the extension other than
plgx-win-extension
. I have been getting what appears to be resource exhaustion. I start the extension and it collects logs for about 1 minute then stops collecting. tailing the extension log I can see it reapplying the event filters and re-reading the config then eventually show the error below. Is there a place I can find more logs on this issue so I can try to fix it.
3:53 PM
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:862: Event filters removed successfully.
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:868: Event filters applied successfully.
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:1607: Config: key:: [utc] value:: [true]
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:1607: Config: key:: [custom_plgx_EnableSSL] value:: [true]
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:1607: Config: key:: [custom_plgx_EnableAmsiStreamEventData] value:: [true]
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:1607: Config: key:: [custom_plgx_EnablePacketInspection] value:: [true]
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:543: Event controls (remove) stage crossed.
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:2630: No event control (blocking) filter found in config.
2022-05-20_15.46.12 INFO  plgx_agent_windows_tlsconfig.cpp:545: Event controls (apply) stage crossed.
2022-05-20_15.46.14 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
2022-05-20_15.46.14 INFO  plgx_win_extension.ext.cpp:229: Starting extension.
2022-05-20_15.46.19 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
2022-05-20_15.46.19 INFO  plgx_win_extension.ext.cpp:229: Starting extension.
2022-05-20_15.46.24 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
2022-05-20_15.46.24 INFO  plgx_win_extension.ext.cpp:229: Starting extension.
2022-05-20_15.46.29 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
2022-05-20_15.46.29 INFO  plgx_win_extension.ext.cpp:229: Starting extension.
2022-05-20_15.46.34 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
2022-05-20_15.46.34 INFO  plgx_win_extension.ext.cpp:229: Starting extension.
2022-05-20_15.46.39 INFO  plgx_win_extension.ext.cpp:237: Reiniting extension due to error.
h

himanshu

05/20/2022, 6:38 PM
your osquery.conf file can have the below config to control logging
"options" :
{
    "custom_plgx_LogLevel": "3",
    "custom_plgx_LogFileName": "C:\\Program Files\\osquery\\plgx-win-extension.log",
    "custom_plgx_EnableLogging": "true"
},
for verbose logging, change custom_plgx_LogLevel to 1 and restart osqueryd and extension. refer here for sample log settings:https://github.com/eclecticiq/osq-ext-bin/blob/master/install/osquery.conf
6:51 PM
config refresh is done by extension every 60 seconds for its own purpose of getting updated with latest osquery config. you can control the gap between two consecutive refresh cycles through the following flag in osquery.flags (value in seconds), lets say: --config_refresh_interval=300 will set the config refresh cycle to every 5 minutes.
l

lvferdi

05/23/2022, 12:08 PM
thank you
2:55 PM
After enabling the verbose logging I see that the extension appears to "crash" and restart after receiving a lot of ASMI requests and yara scan requests. I don't have any yara rules so the debug log for file not found makes sense, but I am unsure why yara is attempting to scan any of the files\
3:36 PM
I still observe the behavior when I remove AMSI scans. I have only a single filter and a single query enabled at this time.
h

himanshu

05/23/2022, 5:23 PM
when any file WRITE event happens, the file is submitted for yara scan as well. but it will exit from that logic soon realizing there is no yara signatures to work with. regarding amsi scan, do you have "custom_plgx_EnableAmsiStreamEventData": "true"? if yes, and you dont want AMSI scan, you can set it to false to disable it. this scan also triggers when any file WRITE event is raised.
5:34 PM
it is best to keep filters as many as possible so that events data traffic can be minimized. removing the filters for any event type means no event for that event type will be filtered or excluded causing unnecessary event traffic. my guess is osquery is unloading extension owing to lot of event data processing increasing cpu usage.
l

lvferdi

05/23/2022, 5:35 PM
The scans are fine and even the yara debug messages are fine, but it seems that I have run into a scenario where I can start the agent with a valid config, it will collect for a short time, that data will be the race condition data, then it stops collecting and the extension restarts repeatedly. This happens with my custom config, your default config and packs, and a stripped down config and queries.
5:38 PM
I am happy to provide any data that may help determine what is happening. I am doing this work on Amazon ec2 windows server 2016 Datacenter
h

himanshu

05/23/2022, 6:32 PM
sure. please share the copy of config file. what is the
Amazon ec2 windows server 2016 Datacenter
vm size? need to try on exact configuration as number of cpus may be critical to repro the issue.
6:34 PM
please share flags file as well
l

lvferdi

05/23/2022, 6:35 PM
sure, I will have to edit the config as it can leak data I am not comfortable sharing. But for the most part (with the exception of some security agents and such) will be what I am running now.
6:42 PM
I have a repeatable scenario also where I have the
win_registry_events
query set to exclude
REG_CREATE
but I get all the reg_create events for the extension itself, which is a lot (understandably), and I have the extension path in the exclusions filter. This extends past start and is continually reoccuring. I would have expected the race condition to have rectified itself after the first filter then I would only receive events matching the filter from there forward. Yet I still get events for reg_create even with it excluded in the config.
h

himanshu

05/23/2022, 6:57 PM
sure you can share config after editing.
7:11 PM
also please share what is your event sink where events are observed continually reoccuring even after applying the filters. is it event viewer, osquery filesystem logger logs, anything else?
l

lvferdi

05/23/2022, 7:14 PM
I use the file system logger then I ship to an elastic cluster
7:14 PM
I use a different logger for shipping not osquery itself
o

OpenPlgx

05/24/2022, 3:22 AM
The filter thing certainly needs to be looked into and fixed if there is a bug. However you can also create a SQL query on registry table to not collect REG_CREATE events, so at least when you are shipping them off the box, there is less volume of data
h

himanshu

05/24/2022, 6:18 AM
it seems there is a bug with action based registry filters in latest code and already identified by the internal testing team. but we have also identified invalid json in config filter file shared to us by you which wont allow filters to get applied. please verify.
4:31 AM
running your configuration internally on a 2 core system, we are seeing some logs from osquery:
osqueryd worker () memory limits exceeded
which would unload the extension. running osquery with the flag
--disable_watchdog=true
should make it work on 2 core system. ideally you dont need to disable osquery watchdog on a higher cpu core system.
4:53 AM
internally testing on 2 cores, it worked.