Filebeat with syslog input loses millisecond precision

Elastic Stack Beats
1

Hello,

I have filebeat 7.12.0 on Debian 10 with two log inputs and one syslog input all going to the same index in an elasticsearch output. For the log inputs, I'm seeing @timestamp values in the index with millisecond precision, but for the syslog inputs, I'm only seeing second precision.

Now, in my syslog configuration (/etc/rsyslog.conf), I've disabled the traditional output, which increases the timestamp precision:

# Use traditional timestamp format.
# To enable high precision timestamps, comment out the following line.
# $ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

I saw the evidence of this change in (for example) /var/log/daemon.log, where the timestamp data went from seconds to microseconds:

Aug 17 16:42:53 ip-10-0-104-247 dhclient[439]: XMT: Solicit on ens5, interval 108140ms.
Aug 17 16:44:41 ip-10-0-104-247 dhclient[439]: XMT: Solicit on ens5, interval 120620ms.
2021-08-17T16:57:29.069120+00:00 ip-10-0-104-247 systemd[1]: Stopping System Logging Service...
2021-08-17T16:57:29.073800+00:00 ip-10-0-104-247 systemd[1]: rsyslog.service: Succeeded.

So I know the input has at least millisecond precision. Once I was satisfied with that, then I redirected the daemon and mail facilities to local UDP port 9000 in the syslog config:

# daemon.*			-/var/log/daemon.log
daemon.*			@127.0.0.1:9000
# mail.*			-/var/log/mail.log
mail.*				@127.0.0.1:9000

...and configured filebeat (/etc/filebeat/filebeat.yml) to pick up this input:

filebeat.inputs:
    - type: log
      ...
    - type: log
      ...
    - type: syslog
      format: auto
      protocol.udp:
          host: "localhost:9000"

I'm able to see hits from both the log and syslog inputs in the index with this query:

GET /my-index/_search?_source_includes=@timestamp,input.type,syslog.facility_label

Here's a hit with a "log" input.type that has millisecond precision:

      {
        ...
        "_source" : {
          "input" : {
            "type" : "log"
          },
          "@timestamp" : "2021-08-17T01:07:18.128Z"
        }
      },

...and a hit with "syslog" input.type that has second precision:

      {
        ...
        "_source" : {
          "input" : {
            "type" : "syslog"
          },
          "@timestamp" : "2021-08-17T01:07:31.000Z",
          "syslog" : {
            "facility_label" : "mail"
          }
        }
      },

At first, I suspected my ingest pipeline configuration, but when I turn on debug for my filebeat log (/var/log/filebeat/filebeat), the processor debug is showing that the precision is already lost before we send it to the elasticsearch endpoint:

2021-08-17T18:19:04.698Z	DEBUG	[processors]	processing/processors.go:203	Publish event: {
  "@timestamp": "2021-08-17T18:19:04.000Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "_doc",
    "version": "7.12.0",
    "truncated": false
  },
  ...

I don't have any processors defined in my filebeat config, and the documentation for the "syslog" input doesn't seem to mention anything that would influence the time format, except maybe the "format" property, and I've tried all three available options.

Is this a problem with the syslog input module? Or do I need to employ some processor to overcome this?

2

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.