Millisecond issue on XM_GELF for parsing timestamp

View thread

juvie

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:
<br/>... <br/>2021-04-26T14:28:14.269+00:00 [sync_ldap_trigger.sh] [DEBUG] Get list of users from AD/LDAP successfully (with 1 records) <br/>... <br/>
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
<br/>#Exec if $raw_event =~ %PEOSYNCREGEX% $EventTime = parsedate($1); $script = $2 ; $Severity = $3 ; $Message = $4 ; <br/>#Exec if $raw_event =~ %PEOSYNCREGEX% $EventTime = strptime($1, '%Y-%m-%d%t%H:%M:%S.%N%Z'); $script = $2 ; $Severity = $3 ; $Message = $4 ; <br/>Exec if $raw_event =~ %PEOSYNCREGEX% $EventTime = $1; $script = $2 ; $Severity = $3 ; $Message = $4 ; <br/>
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:
<br/>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} <br/>

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

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.