im_vistalog parser failure. Introducing \n characters in syslog output that split a single record in two records...

View thread

Ak0

Hello,

I am experiencing truncated syslog messages, and found the root cause. Event are not correctly parsed such as this example:

Here is the original message read from eventviewer:

  • <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  • <System> <Provider Name="Microsoft-Windows-Security-Auditing" Guid="{54849625-5478-4994-a5ba-3e3b0328c30d}" /> <EventID>4663</EventID> <Version>1</Version> <Level>0</Level> <Task>12812</Task> <Opcode>0</Opcode> <Keywords>0x8020000000000000</Keywords> <TimeCreated SystemTime="2022-09-22T13:19:53.982486800Z" /> <EventRecordID>5610</EventRecordID> <Correlation /> <Execution ProcessID="4" ThreadID="2724" /> <Channel>Security</Channel> <Computer>PC-1304.domain.priv</Computer> <Security /> </System>
  • <EventData> <Data Name="SubjectUserSid">S-1-5-21-894803723-839211917-112803419-1225</Data> <Data Name="SubjectUserName">username</Data> <Data Name="SubjectDomainName">Domain</Data> <Data Name="SubjectLogonId">0x71979</Data> <Data Name="ObjectServer">Security</Data> <Data Name="ObjectType">File</Data> <Data Name="ObjectName">\Device\HarddiskVolume5&lt;/Data> <Data Name="HandleId">0x1054</Data> <Data Name="AccessList">%%4416</Data> <Data Name="AccessMask">0x1</Data> <Data Name="ProcessId">0x484</Data> <Data Name="ProcessName">C:\Windows\System32\mstsc.exe</Data> <Data Name="ResourceAttributes" /> </EventData>
  • <RenderingInfo Culture="fr-FR"> <Message>Une tentative d’accès à un objet a été effectuée. Sujet : ID de sécurité : S-1-5-21-894803723-839211917-112803419-1225 Nom du compte : username Domaine du compte : Domain ID d’ouverture de session : 0x71979 Objet : Serveur de l’objet : Security Type d’objet : File Nom de l’objet : \Device\HarddiskVolume5\ ID du handle : 0x1054 Attributs de ressource : Informations sur le processus : ID du processus : 0x484 Nom du processus : C:\Windows\System32\mstsc.exe Informations sur la demande d’accès : Accès : Lecture données (ou liste de répertoire) Masque d’accès : 0x1</Message> <Level>Information</Level> <Task>Removable Storage</Task> <Opcode>Informations</Opcode> <Channel>Sécurité</Channel> <Provider>Microsoft Windows security auditing.</Provider>
  • <Keywords> <Keyword>Succès de l’audit</Keyword> </Keywords> </RenderingInfo> </Event>

Here's the corresponding syslog line produced by om_syslog. Please note that this line is spannig more than one line, this is the problem, read more please. (Forum post format may alter the rendering...)

<14>1 2022-09-22T15:19:53.982486+02:00 PC-1304.domain.priv Microsoft-Windows-Security-Auditing 4 - [NXLOG@14506 Keywords="-9214364837600034816" EventType="AUDIT_SUCCESS" EventID="4663" ProviderGuid="{54849625-5478-4994-A5BA-3E3B0328C30D}" Version="1" Task="12812" OpcodeValue="0" RecordNumber="5610" ThreadID="2724" Channel="Security" Category="Removable Storage" Opcode="Informations" SubjectUserSid="S-1-5-21-894803723-839211917-112803419-1225" SubjectUserName="username" SubjectDomainName="domain" SubjectLogonId="0x71979" ObjectServer="Security" ObjectType="File" ObjectName="\Device\HarddiskVolume5\" HandleId="0x1054" AccessList="%%4416 " AccessMask="0x1" ProcessName="C:\Windows\System32\mstsc.exe" EventReceivedTime="2022-09-22 15:20:26" SourceModuleName="eventlog" SourceModuleType="im_msvistalog"] <Event><EventTime>2022-09-22 15:19:53</EventTime><Hostname>PC-1304.domain.priv</Hostname><Keywords>-9214364837600034816</Keywords><EventType>AUDIT_SUCCESS</EventType><SeverityValue>2</SeverityValue><Severity>INFO</Severity><EventID>4663</EventID><SourceName>Microsoft-Windows-Security-Auditing</SourceName><ProviderGuid>{54849625-5478-4994-A5BA-3E3B0328C30D}</ProviderGuid><Version>1</Version><Task>12812</Task><OpcodeValue>0</OpcodeValue><RecordNumber>5610</RecordNumber><ProcessID>4</ProcessID><ThreadID>2724</ThreadID><Channel>Security</Channel><Message>Une tentative d’accès à un objet a été effectuée.&#xD;&#xA;&#xD;&#xA;Sujet :&#xD;&#xA; ID de sécurité : S-1-5-21-894803723-839211917-112803419-1225&#xD;&#xA; Nom du compte : username&#xD;&#xA; Domaine du compte : domain&#xD;&#xA; ID d’ouverture de session : 0x71979&#xD;&#xA;&#xD;&#xA;Objet :&#xD;&#xA; Serveur de l’objet : Security&#xD;&#xA; Type d’objet : File&#xD;&#xA; Nom de l’objet : \Device\HarddiskVolume5&amp;#xD;&#xA; ID du handle : 0x1054&#xD;&#xA; Attributs de ressource : &#xD;&#xA;&#xD;&#xA;Informations sur le processus :&#xD;&#xA; ID du processus : 0x484&#xD;&#xA; Nom du processus : C:\Windows\System32\mstsc.exe&#xD;&#xA;&#xD;&#xA;Informations sur la demande d’accès :&#xD;&#xA; Accès : Lecture données (ou liste de répertoire)&#xD;&#xA; &#xD;&#xA; Masque d’accès : 0x1</Message><Category>Removable Storage</Category><Opcode>Informations</Opcode><SubjectUserSid>S-1-5-21-894803723-839211917-112803419-1225</SubjectUserSid><SubjectUserName>username</SubjectUserName><SubjectDomainName>Domain</SubjectDomainName><SubjectLogonId>0x71979</SubjectLogonId><ObjectServer>Security</ObjectServer><ObjectType>File</ObjectType><ObjectName>\Device\HarddiskVolume5&lt;/ObjectName><HandleId>0x1054</HandleId><AccessList>%%4416&#xD;&#xA; </AccessList><AccessMask>0x1</AccessMask><ProcessName>C:\Windows\System32\mstsc.exe</ProcessName><EventReceivedTime>2022-09-22 15:20:26</EventReceivedTime><SourceModuleName>eventlog</SourceModuleName><SourceModuleType>im_msvistalog</SourceModuleType></Event>

Problem is the AccessList value (read from the syslog message):

HandleId="0x1054" AccessList="%%4416 " AccessMask="0x1" ProcessName="C:\Windows\System32\mstsc.exe"

If we comparing XML and syslog output: XML output <Data Name="AccessList">%%4416</Data> syslog output AccessList="%%4416 " ^^^^^^^^^^^^^^^^ Mind those characters !

AccessList="%%4416 <---- a new line character is invisible but here (this is THE bug, splitting the syslog message) " <----- multiple tab characters are invisible but here (because of HTML)

End of line \x0a is record separator in syslog format so the line is split in two syslog records (of course the second record is invalid)

It seems that the content of AccessList Key Value is not extracted from XML but from the Message.

Looking at the <Message> we see AccessList is incorrect: <AccessList>%%4416&#xD;&#xA; </AccessList>

where AccessList in XML is: <Data Name="AccessList">%%4416</Data>

Conclusion there is a bug in the event parser that do not escape "#xD;&#xA; " characters correctly, decoding the #xA; in \x0a cutting the syslog message...

You can easily reproduce the problem using this configuration:

<Input eventlog> Module im_msvistalog

SavePos	True
&lt;QueryXML&gt;
    &lt;QueryList&gt;
        &lt;Query Id=&quot;10&quot;&gt;
            &lt;Select Path=&quot;ForwardedEvents&quot;&gt;*&lt;/Select&gt;
        &lt;/Query&gt;
        &lt;Query Id=&quot;20&quot;&gt;
            &lt;Select Path=&quot;Application&quot;&gt;*&lt;/Select&gt;
            &lt;Select Path=&quot;System&quot;&gt;*&lt;/Select&gt;
        &lt;/Query&gt;
    &lt;/QueryList&gt;
&lt;/QueryXML&gt;

Exec $Message = to_xml(); 

</Input>

<Output debugsyslog> Module om_file File 'C:\Install\nxlog.debug.syslog.txt'

Exec to_syslog_ietf(); </Output>

<Route syslog_file> Path eventlog => debugsyslog </Route>