Failed to parse data for Syslog 5424 format

[evandam]

Hi again,

I'm seeing some more issues processing syslog records, not sure if related to #245.

• Ubuntu 18.04
• td-agent package version 3.6.0
• td-agent 1.9.2

Input:

<source>
  @type syslog
  tag syslog.docker.containers
  port 5140
  protocol_type udp
  <parse>
    message_format rfc5424
  </parse>
  @log_level info
</source>

Logs:

020-04-06 21:32:24 +0000 [warn]: #0 failed to parse message data="<30>1 2020-04-06T21:32:24Z compute-i-12345.prod-usw2-prod1 2da252122640 9911 2da252122640 - "

Thanks!

[ganmacs]

with_priority is missing. see https://docs.fluentd.org/input/syslog#with_priority it's not related' let me check.

[ganmacs]

I've confirmed. And it's not related to #245 because fluentd 1.9.2 doesn't contain the root cause of #245. it seems to be a bug fluentd has had.

[ganmacs]

Ah, I got it. your message doesn't follow the RFC5424

Your message is PRI VERSION SP TIMESTAMP SP HOSTNAME SP APP-NAME SP PROCID SP MSGID SP STRUCTURED-DATA SP.
rfc5424 doesn't allow such message. https://tools.ietf.org/html/rfc5424#section-6

[evandam]

My logs are coming straight from Docker with the Syslog driver, so I don't understand how the issue could be an invalid format.

I'm able to reproduce the issue by logging blank lines from Docker as well:

Commands

docker run --rm --name test --log-driver syslog --log-opt syslog-address=udp://127.0.0.1:5140 --log-opt tag="{{.ImageName}}/{{.Name}}/{{.ID}}" --log-opt syslog-format=rfc5424  alpine echo "hello"

docker run --rm --name test --log-driver syslog --log-opt syslog-address=udp://127.0.0.1:5140 --log-opt tag="{{.ImageName}}/{{.Name}}/{{.ID}}" --log-opt syslog-format=rfc5424  alpine echo ""

/var/log/td-agent/td-agent.log

2020-04-07 17:56:11.000000000 +0000 syslog.docker.containers.daemon.info: {"host":"default-ubuntu-1804","ident":"alpine/test/1088c3d1ad59","message":"hello","docker_version":"19.03.8","docker_image":"alpine","docker_tag":"alpine","docker_exec":"echo hello","docker_started_at":"2020-04-07 17:56:11 UTC","docker_container":"test"}

2020-04-07 17:56:27 +0000 [warn]: #0 failed to parse message data="<30>1 2020-04-07T17:56:27Z default-ubuntu-1804 alpine/test/108f9383b979 12537 alpine/test/108f9383b979 - "

[ganmacs]

It's not fluentd's issue because fluentd tries to parse data as RFC5424.
If the coming data doesn't follow the RFC, it's a forwarder's issue.

[repeatedly]

SYSLOG-MSG = HEADER SP STRUCTURED-DATA [SP MSG]

From RFC5424, if MSG doesn't exist, SP should not be added.
But your log contains additional SP in the end of line.

[evandam]

Thanks for the clarification. Would it be possible to filter out the log if it's empty, or simply trim the trailing whitespace first?

[evandam]

I've also noticed it looks like logging to the host's syslog looks like the trailing whitespace is trimmed:

# docker run --rm --name test --log-driver syslog --log-opt tag="{{.ImageName}}/{{.Name}}/{{.ID}}" --log-opt syslog-format=rfc5424  alpine echo ""

# cat -e /var/log/syslog | grep alpine
Apr 10 19:07:09 default-ubuntu-1804 1 2020-04-10T19:07:09Z default-ubuntu-1804 alpine/test/d5592e8d0b5b 12537 alpine/test/d5592e8d0b5b -$

It seems like the td-agent syslog should have the same behavior? I'm open to other suggestions as well. Thanks!

[evandam]

Hey folks, anyone have thoughts on this? I'm not sure what options I have on my end since I'm just sending docker logs to td-agent's syslog input.

[Y-Tian]

+1 running into this issue as well. Do we have any leads on workarounds?

[oldium]

RFC5424 allows empty MSG:

  MSG             = MSG-ANY / MSG-UTF8
  MSG-ANY         = *OCTET ; not starting with BOM

*OCTET is 0 to infinite repetitions. So optional SP MSG can reduce to SP.

[repeatedly]

Fixed by string parser for rfc5424