Osquery: events: Windows Event Log may not grab all data from events

[muffins]

The Windows event log parsing is somewhat incomplete. This was known at the time of development, as some of the values in the System XML attribute didn't seem necessary, however considering more folks are relying on this data pipeline, we should extend our schema to get all fields out of the System attribute.

Further, we currently only process the System and Event XML attributes and children. This means that if there's any other attributes in the Windows event log, we wont get this data. These occurrences are relatively rare, and I haven't seem them very frequently, but we need to investigate a more robust XML -> JSON conversion pipeline to ensure we're getting all of the data.

[tdesrochers]

Besides the missing/omitted fields there is also an issue with the JSON produced.

This snippit is from columns.data of a WEL taken from osqueryd.results.log.

      "data": "{\"EventData\":{\"<xmlattr>\":\"\",\"Name\":\"TMP_EVENT_TIME_JUMP_AUDIT,TimeOffsetSeconds\",\"TimeOffsetSeconds\":\"72038\"}}\\x0A",

The escapes and \\x0A create invalid json. If you remove them you have valid json that can be parsed by tools like nxlog/winlogbeat/logstash/etc.

{"EventData":{"Name":"TMP_EVENT_TIME_JUMP_AUDIT,TimeOffsetSeconds","TimeOffsetSeconds":"72038"}}

{
  "EventData": {
    "Name": "TMP_EVENT_TIME_JUMP_AUDIT,TimeOffsetSeconds",
    "TimeOffsetSeconds": "72038"
  }
}

The rest of the fields parse as expected

[muffins]

@tdesrochers ah yes, this was definitely an issue, but was supposed to have been fixed in osquery 2.11.0+. I know that it just released, but if you have a chance and can pull down osquery 3.2.4 could you take a stab at reproducing and see if the issue persists for you on the latest version? I'll try and repro on my system locally, but haven't seen this except on servers running a dated version

[tdesrochers]

I will grab a new version today/this weekend and check.

On Fri, May 4, 2018, 00:53 Nick Anderson [e-mail] wrote:

@tdesrochers https://github.com/tdesrochers ah yes, this was definitely
an issue, but was supposed to have been fixed in osquery 2.11.0+
https://github.com/facebook/osquery/pull/3985. I know that it just
released, but if you have a chance and can pull down osquery 3.2.4 could
you take a stab at reproducing and see if the issue persists for you on the
latest version? I'll try and repro on my system locally, but haven't seen
this except on servers running a dated version

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/osquery/issues/4364#issuecomment-386505499,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AI1DF9bztZHG-fdrs7Jf7_ECZgqy5jQCks5tu97VgaJpZM4TxjHf
.

[tdesrochers]

Also does osquery allow you to specify specific eventids to collect or only
categories.

On Fri, May 4, 2018, 07:49 tgdesrochers [e-mail] wrote:

I will grab a new version today/this weekend and check.

On Fri, May 4, 2018, 00:53 Nick Anderson [e-mail] wrote:

@tdesrochers https://github.com/tdesrochers ah yes, this was
definitely an issue, but was supposed to have been fixed in osquery
2.11.0+ https://github.com/facebook/osquery/pull/3985. I know that it
just released, but if you have a chance and can pull down osquery 3.2.4
could you take a stab at reproducing and see if the issue persists for you
on the latest version? I'll try and repro on my system locally, but haven't
seen this except on servers running a dated version

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/osquery/issues/4364#issuecomment-386505499,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AI1DF9bztZHG-fdrs7Jf7_ECZgqy5jQCks5tu97VgaJpZM4TxjHf
.

[muffins]

@tdesrochers you can use the SQL filtering to get only the event IDs that you want, however by default we collect _everything_. One could make a feature request to extend our capability to turn on more fine grained filtering ;) But by default for a first attempt at that logging pipeline we wanted as much data as possible. Using something like:

select * from windows_events where eventid=4688;

is about as good as you could do for limiting your eids, but that should work well for getting that data you desire to your backend :)

[tdesrochers]

That's the answer I was hoping for, define collection based upon the query.
I'm running "select * from windows_events;" for initial testing.

Thank you

On Fri, May 4, 2018, 12:19 Nick Anderson [e-mail] wrote:

@tdesrochers https://github.com/tdesrochers you can use the SQL
filtering to get only the event IDs that you want, however by default we
collect everything. One could make a feature request to extend our
capability to turn on more fine grained filtering ;) But by default for a
first attempt at that logging pipeline we wanted as much data as possible.
Using something like:

select * from windows_events where eventid=4688;

is about as good as you could do for limiting your eids, but that should
work well for getting that data you desire to your backend :)

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/osquery/issues/4364#issuecomment-386652017,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AI1DF_uFpwLqrA07oQxX-GCR1S9RNT_7ks5tvH-fgaJpZM4TxjHf
.

[tdesrochers]

tested with osquery 3.2.4 and I get the following in osquery results log:

{"name":"windows_events","hostIdentifier":"CAPITAL-70PUP9O","calendarTime":"Fri May  4 06:51:26 2018 UTC","unixTime":1525416686,"epoch":0,"counter":0,"decorations":{"host_uuid":"BD804D56-9368-07D4-B37E-FB9038ABD62D","os_name":"Microsoft Windows 10 Enterprise","os_version":"10.0.14393"},"columns":{"data":"{\"EventData\":{\"<xmlattr>\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\WINDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-B740-5AEB-0000-0010DC9E0300}\",\"SourceProcessId\":\"2868\",\"SourceThreadId\":\"18632\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-B735-5AEB-0000-001045BF0000}\",\"TargetProcessId\":\"696\",\"UtcTime\":\"2018-05-04 06:51:24.136\"}}\\x0A","datetime":"2018-05-04T06:51:24.144988000Z","eventid":"10","keywords":"-1","level":"4","provider_guid":"{5770385F-C22A-43E0-BF4C-06F5698FFBD9}","provider_name":"Microsoft-Windows-Sysmon","source":"Microsoft-Windows-Sysmon/Operational","task":"10","time":"1525416685"},"action":"added"}

When parsed I am still left with:

"data": "{\"EventData\":{\"<xmlattr>\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\WINDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-B740-5AEB-0000-0010DC9E0300}\",\"SourceProcessId\":\"2868\",\"SourceThreadId\":\"18632\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-B735-5AEB-0000-001045BF0000}\",\"TargetProcessId\":\"696\",\"UtcTime\":\"2018-05-04 06:51:24.136\"}}\\x0A"

The \\x0A still makes the json invalid along with the escapes.

[tdesrochers]

Continued testing on 3.2.4 shows that all data is parsed correctly except for columns.data.EventData . If the EventData field were parsed correctly then the logs could be shipped and read without additional logic for the shipper.

I have tried shipping the logs with filebeat/winlogbeat/NXlog/ and fluentd. All give the same result unless I start logic to detect escapes and /r/n to parse the logs correctly.

[muffins]

Got it, will look into fixing that, thanks for the triage @tdesrochers!

[zwass]

@muffins are you saying that you expect the JSON for the event data to not be escaped? It's not clear to me how this would work given that the JSON is output as a string -- don't all the quotes need to be escaped? Or am I misunderstanding the issue here.

[muffins]

@zwass nah I think that all of the escaping has been working correctly on most builds after like 3.2.X. The issue that this was originally tracking is that for some custom WEL channels, there may be extra data fields in the XML that we're "missing". I need to find more specific examples of this happening and get them posted here, as I don't think this happens commonly, and is for custom WEL providers. I'll try and get some examples up here today, hope that makes sense?

[verntx]

This from our 3.3.1 fork:

{"name":"windows_events","hostIdentifier":"HID","calendarTime":"Fri Jan 10 15:10:51 2020 UTC","unixTime":"1578669051","epoch":0,"counter":0,"log_type":"result","decorations":{"control_id":"CID","optimized":"false","source_asset_id":"SAID"},"columns":{"data":"{\"UserData\":{\"BackupPath\":\"\",\"Channel\":\"Windows PowerShell\",\"LogFileCleared\":\"\",\"SubjectDomainName\":\"MACHINENAME\",\"SubjectUserName\":\"UserName\"}}
x0A","datetime":"2020-01-10T15:10:10.537543400Z","eventid":"104","keywords":"-1","level":"4","provider_guid":"{fc65ddd8-d6ef-4962-83d5-6e5cfe9ce148}","provider_name":"Microsoft-Windows-Eventlog","source":"System","task":"104","time":"1578669010"},"action":"added"}

Some attribute values are missing inside the data field.. e.g.
\"LogFileCleared\":\"\" → "LogFileCleared”:””

[alessandrogario]

This should be solved in PR https://github.com/osquery/osquery/pull/6280

[directionless]

I'm going to assume #6280 solved this. Please comment or reopen if there's still an issue