1
response

I am using nxLog CE as log shipper, but I found issue for GELP module with millisecond precision in time stamp. The millisecond precision is not added to timestamp (EventTime as well) When I use gelf extension the millisecond precision is dropped. Basically although I have in log file something like this:

...
2021-04-26T14:28:14.269+00:00   [sync_ldap_trigger.sh]  [DEBUG] Get list of users from AD/LDAP successfully (with 1 records)
...

and for parsing I am using REGEX for multi line detection. Doesn't matter if I am using parsing date function parsedate or strptime or nothing just pure $1

#Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = parsedate($1); $script = $2 ; $Severity = $3 ; $Message = $4 ;
#Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = strptime($1, '%Y-%m-%d%t%H:%M:%S.%N%Z'); $script = $2 ; $Severity = $3 ; $Message = $4 ;
Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = $1; $script = $2 ; $Severity = $3 ; $Message = $4 ;

I excluded "buffer" from path to be sure and all parsing are done in im_file section. For sure I am testing it with file output from the same source. But on the tcpdump I still have timestamp without the millisecond precision - which I confirmation form me that this information is lost on shipper site.

tcpdump detailed packet output:

CNSCNc@{"version":"1.1","_EventReceivedTime":"2021-04-26 14:32:15","_SourceModuleName":"peosynclog","_SourceModuleType":"im_file","_script":"sync_ldap_trigger.sh","_Severity":"DEBUG","_SyslogSeverityValue":7,"_FileName":"/home/adsync/bin/adsync2amish/log/sync_general.log","_order":"VNB","_environment":"TEST","host":"amishd-test.vnbrno.cz","short_message":"Get list of users from AD/LDAP successfully (with 1 records)","full_message":"Get list of users from AD/LDAP successfully (with 1 records)","timestamp":1619447535,"level":7} 

nxlog.conf:

########################################
# Global directives                    #
########################################
User nxlog
Group nxlog
LogFile /var/log/nxlog/nxlog.log
LogLevel INFO
# PeoSYNC
define PEOSYNCREGEX /^(?<EventTime>\d{4}\-\d{2}\-\d{2}T\d{2}\:\d{2}\:\d{2}.\d{3}\+\d{4})[\ ,\t]*\[(?<Script>[\S,\.,\_]+)\][\ ,\t]*\[(?<Severity>[\S,\-,\ ]+)\][\ ,\t]*(?<Message>[\S,\s]*)/
define ROOT /var/spool/nxlog
CacheDir %ROOT%/data
SpoolDir %ROOT%/data
########################################
# Modules                              #
########################################
<Extension multilinepeosync>
    Module      xm_multiline
    HeaderLine  %PEOSYNCREGEX%
</Extension>
<Extension gelf>
    Module      xm_gelf
</Extension>
########################################
# Inputs                               #
########################################
<Input peosynclog>
    Module      im_file
    File        "/home/adsync/bin/engine/log/sync_general.log"
    InputType   multilinepeosync
    SavePos     TRUE
    #Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = parsedate($1); $script = $2 ; $Severity = $3 ; $Message = $4 ;
    #Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = strptime($1, '%Y-%m-%d%t%H:%M:%S.%N%Z'); $script = $2 ; $Severity = $3 ; $Message = $4 ;
    Exec        if $raw_event =~ %PEOSYNCREGEX%  $EventTime = $1; $script = $2 ; $Severity = $3 ; $Message = $4 ;
    <Exec>
        if $Severity !~ /NEVERUSEDSTRING/
        {
                if $Severity =~ /ALERT/ $SyslogSeverityValue = 1;
                if $Severity =~ /CRIT/ $SyslogSeverityValue = 2;
                if $Severity =~ /ERR/ $SyslogSeverityValue = 3;
                if $Severity =~ /WARN/ $SyslogSeverityValue = 4;
                if $Severity =~ /NOTICE/ $SyslogSeverityValue = 5;
                if $Severity =~ /INFO/ $SyslogSeverityValue = 6;
                if $Severity =~ /---/ $SyslogSeverityValue = 6;
                if $Severity =~ /SQL/ $SyslogSeverityValue = 7;
                if $Severity =~ /DEBUG/ $SyslogSeverityValue = 7;
        } else {
                # Parsing and dropping all messages which are NEVERUSEDSTRING (or INFO|DEBUG if you want change) severity
                drop();
        }
        $FileName = file_name();
        $Hostname = 'someserver-dev.loc';
        $order = 'ORDER';
        $environment = 'DEV';
        # if not defined($EventTime) $EventTime = now();
    </Exec>
</Input>
########################################
# Outputs                              #
########################################
<Output graylogtcppeosyncrewrite>
    Module      om_tcp
    Host        127.0.0.1
    Port        20228
    OutputType  GELF_TCP
</Output>
<Output file>
    Module      om_file
    File        "/tmp/sync_general.log"
</Output>
########################################
# Define Processor Modules             #
########################################
<Processor bufferpeosync>
        Module  pm_buffer
        MaxSize 524288
        Type    disk
        WarnLimit       393216
</Processor>
########################################
# Routes                               #
########################################
<Route 1>
        #Path    peosynclog => bufferpeosync => graylogtcppeosyncrewrite
        Path    peosynclog => graylogtcppeosyncrewrite
</Route>
<Route 2>
        Path    peosynclog => file
</Route>

Please anyone for help or solution for this issue.

Michal

BTW: Of course that I tried more format for timestamp as 2021-04-26T14:28:04.240+02:00 or 2021-04-26T14:28:04.240+0200 etc. The format in log is in my hands too.

AskedApril 26, 2021 - 3:35pm

Answer (1)

Hi Michal,

Thanks for sharing your observations.

I'll try to reproduce your problem, and share the outcomes with you.

Best regards,
Rafal