Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

events: Windows Event Log may not grab all data from events #4364

Closed
muffins opened this issue May 3, 2018 · 14 comments
Closed

events: Windows Event Log may not grab all data from events #4364

muffins opened this issue May 3, 2018 · 14 comments

Comments

@muffins
Copy link
Contributor

@muffins muffins commented May 3, 2018

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
Copy link

@tdesrochers tdesrochers commented May 4, 2018

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
Copy link
Contributor Author

@muffins muffins commented May 4, 2018

@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
Copy link

@tdesrochers tdesrochers commented May 4, 2018

@tdesrochers
Copy link

@tdesrochers tdesrochers commented May 4, 2018

@muffins
Copy link
Contributor Author

@muffins muffins commented May 4, 2018

@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
Copy link

@tdesrochers tdesrochers commented May 4, 2018

@tdesrochers
Copy link

@tdesrochers tdesrochers commented May 4, 2018

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
Copy link

@tdesrochers tdesrochers commented May 7, 2018

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
Copy link
Contributor Author

@muffins muffins commented May 7, 2018

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

@zwass
Copy link
Member

@zwass zwass commented Jan 15, 2020

@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
Copy link
Contributor Author

@muffins muffins commented Jan 15, 2020

@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
Copy link

@verntx verntx commented Jan 15, 2020

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
Copy link
Contributor

@alessandrogario alessandrogario commented Apr 9, 2020

This should be solved in PR #6280

@directionless
Copy link
Contributor

@directionless directionless commented Jul 7, 2020

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
6 participants