[Sysmon] UtcTime and other fields are wrong in DnsQuery events from short-lived processes
I'm seeing something strange in the Sysmon ETW events for DnsQuery events (ID=22). The UtcTime field in the DnsQuery event is about 12 seconds earlier than the actual time, and the ProcessGuid and ImageName fields contains default values. The problem is specific to very short-lived processes.
I've pasted below a condensed XML-ified trace to illustrate. Some PII has been obfuscated. In this test, I ran "ping -n 1 www.rte.ie". The UtcTime field (line 19) for the ProcessCreate event is correct. Notice how closely this timestamp aligns with the TimeCreated value (line 11) in the ETW header. But the UtcTime field for the DnsQuery event (line 59) is 12 seconds before the process has even started! Note however that the TimeCreated value (line 51) in the ETW header for this event is correct. Note too that the ProcessGuid is all zeroes, and that the ImageName is "<unknown process>".
This doesn't happen if I do "ping -n 4 www.rte.ie" so that the process runs for several seconds. I suspect that in short-lived processes the Sysmon service is receiving the DNS notification after the process has already exited. It then doesn't know the process to which the event should be attributed. But I don't know where the 12 second thing is coming from. I'm not running on a VM.
<Events>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-Windows-Sysmon" Guid="{5770385f-c22a-43e0-bf4c-06f5698ffbd9}" />
<EventID>1</EventID>
<Version>5</Version>
<Level>4</Level>
<Task>1</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000000</Keywords>
<TimeCreated SystemTime="2021-02-09T13:18:18.099828300+00:00" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="4760" ThreadID="5780" ProcessorID="0" KernelTime="2984340" UserTime="1146105" />
<Channel>Microsoft-Windows-Sysmon/Operational</Channel>
<Computer />
</System>
<EventData>
<Data Name="RuleName">-</Data>
<Data Name="UtcTime">2021-02-09 13:18:18.097</Data>
<Data Name="ProcessGuid">{********-8b9a-6022-001f-010000002200}</Data>
<Data Name="ProcessId"> 22776</Data>
<Data Name="Image">C:\Windows\System32\PING.EXE</Data>
<Data Name="FileVersion">10.0.19041.1 (WinBuild.160101.0800)</Data>
<Data Name="Description">TCP/IP Ping Command</Data>
<Data Name="Product">Microsoft® Windows® Operating System</Data>
<Data Name="Company">Microsoft Corporation</Data>
<Data Name="OriginalFileName">ping.exe</Data>
<Data Name="CommandLine">ping -n 1 www.rte.ie</Data>
<Data Name="CurrentDirectory">C:\Users\myusername\Desktop\</Data>
<Data Name="User">MYCOMPUTERNAME\myusername</Data>
<Data Name="LogonGuid">{********-114c-601a-9f2f-030000000000}</Data>
<Data Name="LogonId">0x32F9F</Data>
<Data Name="TerminalSessionId"> 1</Data>
<Data Name="IntegrityLevel">High</Data>
<Data Name="Hashes">MD5=2F46799D79D22AC72C241EC0322B011D,SHA256=7AF50FA112932EA3284F7821B2EEA2B7582F558DBA897231BB82182003C29F8B</Data>
<Data Name="ParentProcessGuid">{********-068d-6021-bf00-010000002200}</Data>
<Data Name="ParentProcessId"> 30808</Data>
<Data Name="ParentImage">C:\Windows\System32\cmd.exe</Data>
<Data Name="ParentCommandLine">cmd.exe</Data>
</EventData>
</Event>
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
<System>
<Provider Name="Microsoft-Windows-Sysmon" Guid="{5770385f-c22a-43e0-bf4c-06f5698ffbd9}" />
<EventID>22</EventID>
<Version>5</Version>
<Level>4</Level>
<Task>22</Task>
<Opcode>0</Opcode>
<Keywords>0x8000000000000000</Keywords>
<TimeCreated SystemTime="2021-02-09T13:18:20.167048200+00:00" />
<Correlation ActivityID="{00000000-0000-0000-0000-000000000000}" />
<Execution ProcessID="4760" ThreadID="6260" ProcessorID="2" KernelTime="2940" UserTime="6405" />
<Channel>Microsoft-Windows-Sysmon/Operational</Channel>
<Computer />
</System>
<EventData>
<Data Name="RuleName">-</Data>
<Data Name="UtcTime">2021-02-09 13:18:05.847</Data>
<Data Name="ProcessGuid">{00000000-0000-0000-0000-000000000000}</Data>
<Data Name="ProcessId"> 22776</Data>
<Data Name="QueryName">www.rte.ie</Data>
<Data Name="QueryStatus">0</Data>
<Data Name="QueryResults">::ffff:104.18.142.17;::ffff:104.18.143.17;162.159.0.73;162.159.1.73;162.159.2.27;162.159.3.18;2400:cb00:2049:1::a29f:49;2400:cb00:2049:1::a29f:149;2400:cb00:2049:1::a29f:21b;2400:cb00:2049:1::a29f:312;</Data>
<Data Name="Image"><unknown process></Data>
</EventData>
</Event>
</Events>