im_vistalog parser failure. Introducing \n characters in syslog output that split a single record in two records...
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</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.

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&#xD;
 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><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</ObjectName><HandleId>0x1054</HandleId><AccessList>%%4416
 </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
 </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;
 " 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
<QueryXML>
<QueryList>
<Query Id="10">
<Select Path="ForwardedEvents">*</Select>
</Query>
<Query Id="20">
<Select Path="Application">*</Select>
<Select Path="System">*</Select>
</Query>
</QueryList>
</QueryXML>
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>
I'm not sure if that's a bug....Unix-based systems are using 
 as the newline character, while Windows uses the CR-LF PAIR "#xD;
 ". NXLog can alter fields content regarding CR and LF characters according to W3C recommendations. Any CR LF and any CR that is not followed by an LF will be translated to a single LF.
Have you tried switching the Message field to XML after converting the log to the syslog format? What did you get without the "Exec $Message = to_xml();" part?
