Robust RFC 5424, RFC 3339, ISO 8601, timestamp formatting

[apolloclark]

Expected Behavior

Fluentd syslog collector can collect RFC 5424 formatted syslog messages from both the Rsyslog Windows Agent, and Rsyslog Linux Agent, with or without fractional seconds, per RFC 5424, RFC 3339, and ISO 8601.

Actual Behavior

Rsyslog Linux Agent timestamp (with microseconds) is accepted, but the Rsyslog Windows Agent timestamp (without microseconds) causes errors.

Error Log

2018-02-17 23:20:23 +0000 [error]: #0 invalid input data="<134>1 2018-02-17T15:20:23-07:00 vagrant-2008R2 EvntSLog - - - Provider \"FileSystem\" is Started. Details: ProviderName=FileSystem NewProviderState=Started SequenceNumber=4 HostName=ConsoleHost HostVersion=2.0 HostId=06dbbd91-401c-47e7-b5d5-39658de1ae24 EngineVersion= RunspaceId= PipelineId= CommandName= CommandType= ScriptName= CommandPath= CommandLine=" error_class=Fluent::TimeParser::TimeParseError error="invalid time format: value = 1 2018-02-17T15:20:23-07:00 vagrant-2008R2, error_class = ArgumentError, error = string doesn't match"

Environment

• RHEL 7.2, fluentd syslog collector, td-agent 1.0.2
• RHEL 7.2, rsyslog forwarder 8.24.0
• Windows 2008 R2 SP1, rsyslog forwarder 4.3.0.255

Configuration

td-agent

<source>
  @type syslog
  port 5140
  bind 0.0.0.0
  protocol_type tcp
  tag  rsyslog
  <parse>
    message_format rfc5424
  </parse>
</source>

Rsyslog Linux Agent

*.* @@127.0.0.1:5141;RSYSLOG_SyslogProtocol23Format

Rsyslog Windows Agent

$szCustomSyslogHeader <%syslogprifac%>%syslogver% %timereported:::date-rfc3339% %source% %syslogappname% %syslogprocid% %syslogmsgid% %syslogstructdata% 

Details

The Rsyslog Windows Agent, when configured to send RFC 5424, does not include fractional seconds / microseconds in the timestamp. I found a fluentd git commit which defines the default filter, and only supports fractional seconds:

https://github.com/cosmo0920/fluentd/blob/866b2caf0891b805fca54efff6c28e10cd617f35/lib/fluent/plugin/parser_syslog.rb#L36

The RFC 5424, RFC 3339, and ISO 8601 say that fractional seconds are optional. It also mentions that the "T" and "Z" separators may be upper or lower case. Here's some examples of valid timestamps:

### simple form
2018-01-02T01:01:01Z
2018-01-02T01:01:01-01:00
2018-01-02T01:01:01+01:00

### mixed case T, Z
2018-01-02T01:01:01z
2018-01-02t01:01:01Z
2018-01-02t01:01:01z
2018-01-02t01:01:01-01:00
2018-01-02t01:01:01+01:00

### fractional seconds
2018-01-02T01:01:01.1Z
2018-01-02T01:01:01.1-01:00
2018-01-02T01:01:01.1+01:00

2018-01-02T01:01:01.01Z
2018-01-02T01:01:01.01-01:00
2018-01-02T01:01:01.01+01:00

2018-01-02T01:01:01.001Z
2018-01-02T01:01:01.001-01:00
2018-01-02T01:01:01.001+01:00

2018-01-02T01:01:01.0001Z
2018-01-02T01:01:01.0001-01:00
2018-01-02T01:01:01.0001+01:00

2018-01-02T01:01:01.00001Z
2018-01-02T01:01:01.00001-01:00
2018-01-02T01:01:01.00001+01:00

2018-01-02T01:01:01.00001Z
2018-01-02T01:01:01.00001-01:00
2018-01-02T01:01:01.00001+01:00

I've created a temporary fix, by configuring fluentd / td-agent to not look for fractional seconds, and to make the Rsyslog Linux Agent not send fractional seconds. A better long-term solution would be for the fluentd in_syslog collector to support the wider range of timestamps. Thoughts?

Work-around

fluentd / td-agent config

# https://docs.fluentd.org/articles/in_syslog
<source>
  @type syslog
  port 5140
  bind 0.0.0.0
  protocol_type tcp
  tag  rsyslog
  <parse>
    message_format rfc5424
    # set this format to be compatible with Rsyslog Windows Agent
    # https://docs.fluentd.org/v1.0/articles/parser_syslog#time_format
    time_format "%Y-%m-%dT%H:%M:%S%z"
  </parse>
</source>

Rsyslog Linux 8.24.0 Agent config

# rsyslog linux agent remove timestamp microseconds / fractional seconds
$template TimeStampFix,"<%pri%>1 %timestamp:::date-year%-%timestamp:::date-month%-%timestamp:::date-day%T%timestamp:::date-hour%:%timestamp:::date-minute%:%timestamp:::date-second%%timestamp:::date-tzoffsdirection%%timestamp:::date-tzoffshour%:%timestamp:::date-tzoffsmin% %hostname% %app-name% %procid% %msgid% %structured-data% %msg%\n"

*.* @@127.0.0.1:5140;TimeStampFix

Rsyslog Linux 5.8.10 Agent config

# fix to include PID for local logger
$SystemLogUsePIDFromSystem on

# rsyslog linux agent remove timestamp microseconds / fractional seconds
$template TimeStampFix,"<%pri%>1 %timegenerated:1:10:date-rfc3339%T%timegenerated:12:19:date-rfc3339%+00:00 %hostname% %app-name% %procid% %msgid% %structured-data% %msg%\n"

*.* @@127.0.0.1:5140;TimeStampFix

[repeatedly]

One possible idea is supporting multiple format in time_format.

To avoid current limitation, setup 2 syslog input plugins is one way.
One is for RHEL microsecond timestamp and another one is for Windows second-unit timestamp.

[okkez]

https://tools.ietf.org/html/rfc5424#section-6.2.3

The originator SHOULD include TIME-SECFRAC if its clock accuracy and performance permit.

So you should send timestamp includes TIME-SECFRAC from Windows agent.
Does Windows agent support timereported:::date-rfc5424 or something?

I could not find date-rfc5424 like options in https://www.rsyslog.com/download/files/windows-agent-manual/propreplaceroptions.html .

[masterada]

Any update on this? Should means the implementation is still valid if it does not send TIME-SECFRAC. https://tools.ietf.org/html/rfc2119

3. SHOULD   This word, or the adjective "RECOMMENDED", mean that there
   may exist valid reasons in particular circumstances to ignore a
   particular item, but the full implications must be understood and
   carefully weighed before choosing a different course.

[okkez]

I've checked RFC5424 again.
TIME-SECFRAC can be omittable, but current implementation requires it.

https://tools.ietf.org/html/rfc5424#section-6

  TIMESTAMP       = NILVALUE / FULL-DATE "T" FULL-TIME
  FULL-DATE       = DATE-FULLYEAR "-" DATE-MONTH "-" DATE-MDAY
  DATE-FULLYEAR   = 4DIGIT
  DATE-MONTH      = 2DIGIT  ; 01-12
  DATE-MDAY       = 2DIGIT  ; 01-28, 01-29, 01-30, 01-31 based on
                            ; month/year
  FULL-TIME       = PARTIAL-TIME TIME-OFFSET
  PARTIAL-TIME    = TIME-HOUR ":" TIME-MINUTE ":" TIME-SECOND
                    [TIME-SECFRAC]
  TIME-HOUR       = 2DIGIT  ; 00-23
  TIME-MINUTE     = 2DIGIT  ; 00-59
  TIME-SECOND     = 2DIGIT  ; 00-59
  TIME-SECFRAC    = "." 1*6DIGIT
  TIME-OFFSET     = "Z" / TIME-NUMOFFSET
  TIME-NUMOFFSET  = ("+" / "-") TIME-HOUR ":" TIME-MINUTE