We are using NXLog extensively and just recently started seeing some parsing issues, so far specifically on Windows 2012r2 using Windows Event Forwarding, but could be others. It appears to be something with processing self-closed tags at first glance, but I've done a little bit of testing myself and couldn't directly reproduce the problem (so far), so figured I'd come here for guidance. Specific details are included below.

Current Behavior NXLog appears to be improperly parsing empty, self-closed XML tags.

Expected Behavior NXLog properly ignores empty, self-closed XML tags.

NXLog Version: nxlog-ce-2.10.2150

NXLog Configuration File:

##   NXLog configuration file

define ROOT C:\Program Files (x86)\nxlog

define LOGFILE %ROOT%\data\nxlog.log
Moduledir %ROOT%\modules
CacheDir %ROOT%\data
Pidfile %ROOT%\data\nxlog.pid
SpoolDir %ROOT%\data

# Rotate agent logs on the local system such that only the last 4 files are kept
<Extension fileop>
    Module  xm_fileop

    # Check the size of our log file every hour and rotate if it is larger than 1M
        Every  1 hour
        Exec  if (file_size('%LOGFILE%') >= 1M) file_cycle('%LOGFILE%', 4);

    # Rotate our log file every week on sunday at midnight
        When  @weekly
        Exec  file_cycle('%LOGFILE%', 4);

<Extension syslog>
    Module  xm_syslog

<Extension json>
    Module  xm_json

# Agent logs
<Input internal>
    Module  im_internal

# OS logs
<Input eventlog>
    Module  im_msvistalog

    # Drop EventID 5156 logs when application name is nxlog.exe
    Exec  if ($SourceName == 'Microsoft-Windows-Security-Auditing')\
      AND ($EventID == 5156)\
      AND ($Application =~ /nxlog.exe$/)\

<Input forwardedEvents>
    Module im_msvistalog

    Query <QueryList> \
        <Query Id="0"> \
            <Select Path="ForwardedEvents">*</Select>\
        </Query> \

# SIEM port 3514 is listening for JSON-encoded IETF style syslog messages
# OutputType Syslog_TLS required to enable the octet-framing described in RFC5425
<Output out>
    Module  om_tcp
    Port  3514
    OutputType  Syslog_TLS
    Exec  $Message = to_json();

    # Remove param-value pairs from structured data header with names > 32 characters.
    Exec  if ($SourceName == 'Microsoft-Windows-GroupPolicy') {\
                    if ($EventID == 5017) OR ($EventID == 6017) OR ($EventID == 7017)\
                    if ($EventID == 5116) OR ($EventID == 6116) OR ($EventID == 7116)\
                    if ($EventID == 5126) OR ($EventID == 6126) OR ($EventID == 7126)\
                    if ($EventID == 5257) OR ($EventID == 6257) OR ($EventID == 7257)\
                    if ($EventID == 5351) OR ($EventID == 6351) OR ($EventID == 7351)\

    Exec     to_syslog_ietf();

<Route 1>
    Path  internal, eventlog, forwardedEvents => out

Windows Version: Windows 2012r2 (potentially others, but confirmed for sure on this one)

Example Exported XML from EventViewer

<?xml version="1.0" encoding="utf-8" standalone="yes"?>
<Events><Event xmlns='http://schemas.microsoft.com/win/2004/08/events/event' xml:lang='en-US'><System><Provider Name='Microsoft-Windows-Security-Auditing' Guid='{54849625-5478-4994-A5BA-3E3B0328C30D}'/><EventID>4688</EventID><Version>2</Version><Level>0</Level><Task>13312</Task><Opcode>0</Opcode><Keywords>0x8020000000000000</Keywords><TimeCreated SystemTime='2019-10-23T14:01:56.684789600Z'/><EventRecordID>5238702734</EventRecordID><Correlation/><Execution ProcessID='4' ThreadID='3948'/><Channel>Security</Channel><Computer>hostname.domain</Computer><Security/></System><EventData><Data Name='SubjectUserSid'>S-1-5-18</Data><Data Name='SubjectUserName'>workstation$</Data><Data Name='SubjectDomainName'>DOMAIN</Data><Data Name='SubjectLogonId'>0x3e7</Data><Data Name='NewProcessId'>0x1754</Data><Data Name='NewProcessName'>C:\Windows\System32\wbem\WmiApSrv.exe</Data><Data Name='TokenElevationType'>%%1936</Data><Data Name='ProcessId'>0x2f8</Data><Data Name='CommandLine'/><Data Name='TargetUserSid'>S-1-0-0</Data><Data Name='TargetUserName'>-</Data><Data Name='TargetDomainName'>-</Data><Data Name='TargetLogonId'>0x0</Data></EventData><RenderingInfo Culture='en-US'><Message>A new process has been created...</Message><Level>Information</Level><Task>Process Creation</Task><Opcode>Info</Opcode><Channel>Security</Channel><Provider>Microsoft Windows security auditing.</Provider><Keywords><Keyword>Audit Success</Keyword></Keywords></RenderingInfo></Event></Events>

Example Data as Received on the wire:

<14>1 2019-10-21T15:44:36.650065-04:00 hostname.domain Microsoft-Windows-Security-Auditing 4 - [NXLOG@14506 Keywords="-9214364837600034816" EventType="AUDIT_SUCCESS" EventID="4688" ProviderGuid="{54849625-5478-4994-A5BA-3E3B0328C30D}" Version="2" Task="13312" OpcodeValue="0" RecordNumber="355111132" ThreadID="5020" Channel="Security" Category="Process Creation" Opcode="Info" SubjectUserSid="S-1-5-18" SubjectUserName="workstation$" SubjectDomainName="DOMAIN" SubjectLogonId="0x3e7" NewProcessId="0x13a8" NewProcessName="C:\\Windows\\System32\\wbem\\WmiPrvSE.exe" TokenElevationType="%%1936" CommandLine\'/><Data_Name=\'TargetUserSid="S-1-0-0" TargetUserName="workstation$" TargetDomainName="DOMAIN" TargetLogonId="0x3e4" EventReceivedTime="2019-10-21 15:45:38" SourceModuleName="eventlog" SourceModuleType="im_msvistalog"] {"EventTime":"2019-10-21 15:44:36","Hostname":"hostname.domain","Keywords":-9214364837600034816,"EventType":"AUDIT_SUCCESS","SeverityValue":2,"Severity":"INFO","EventID":4688,"SourceName":"Microsoft-Windows-Security-Auditing","ProviderGuid":"{54849625-5478-4994-A5BA-3E3B0328C30D}","Version":2,"Task":13312,"OpcodeValue":0,"RecordNumber":355111132,"ProcessID":4,"ThreadID":5020,"Channel":"Security","Message":"A new process has been created...","Category":"Process Creation","Opcode":"Info","SubjectUserSid":"S-1-5-18","SubjectUserName":"workstation$","SubjectDomainName":"domain","SubjectLogonId":"0x3e7","NewProcessId":"0x13a8","NewProcessName":"C:\\Windows\\System32\\wbem\\WmiPrvSE.exe","TokenElevationType":"%%1936","CommandLine'/><Data Name='TargetUserSid":"S-1-0-0","TargetUserName":"workstation$","TargetDomainName":"DOMAIN","TargetLogonId":"0x3e4","EventReceivedTime":"2019-10-21 15:45:38","SourceModuleName":"eventlog","SourceModuleType":"im_msvistalog"}

NOTE: I know the above two examples don't reference the exact same event. They are just for illustration and reference purposes

You should see that in the XML exported from EventViewer, there's an empty and self-closed 'CommandLine' tag. However, in the example pulled from the wire, you should see that the 'CommandLine' tag has been mangled and parsed as if it were part of the 'TargetUserSid' tag and there's some XML data there.

Have you seen similar behavior when parsing logs either through the ForwardedEvents (Windows Event Forwarding) or otherwise?

Addendum: We have also seen this behavior with other empty, self-closed XML Fields such as a 'TargetDomainName' field, so it does not seem to be specifically related to the CommandLine tag itself.

AskedOctober 31, 2019 - 1:12pm

Answer (1)


I believe we already came across the issue with the self-closing tags and it should be already fixed in the NXLog Enterprise Edition. You could verify this by testing the EE trial.
We'll need to backport the fixes into the NXLog CE.

Comments (1)

  • nwalters's picture

    Thank you for the update b0ti.

    Would you happen to have any idea on when that change might be backported by chance?

    I'm working on deploying the EE trial for testing right now, but have a lot of clients on CE that I'll need to prep upgrades for once that has been backported.