Having issues with syslog parsing. error="invalid strptime format - `%b %d %H:%M:%S'"

4,100 views
Skip to first unread message

Christian Hedegaard

unread,
Dec 19, 2013, 7:41:13 PM12/19/13
to flu...@googlegroups.com

 

Hey all. I’ve been working on getting fluentd and kibana in to replace our Graylog2 system.

 

I’ve got a series of clients who send syslog messages via rsyslog to localhost on 5140 where fluentd is listening with the syslog plugin. Then fluentd is configured to forward everything to a central fluentd server. The central server also puts everything into elasticsearch using the elasticsearch plugin.

 

All of that works. Except that the data is not formatted properly, and there are tons of errors in the logs about “error="invalid strptime format - `%b %d %H:%M:%S'"”

 

Here is the output log from the client machines:

 

Client

######

2013-12-20 00:30:38 +0000 [info]: starting fluentd-0.10.41

2013-12-20 00:30:38 +0000 [info]: reading config file path="/etc/td-agent/td-agent.conf"

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-mixin-config-placeholders' version '0.2.3'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.4'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-flume' version '0.1.1'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-mongo' version '0.7.1'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.3.1'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-s3' version '0.3.5'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-scribe' version '0.10.10'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-td' version '0.10.17'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-td-monitoring' version '0.1.0'

2013-12-20 00:30:38 +0000 [info]: gem 'fluent-plugin-webhdfs' version '0.2.1'

2013-12-20 00:30:38 +0000 [info]: gem 'fluentd' version '0.10.41'

2013-12-20 00:30:38 +0000 [info]: using configuration file: <ROOT>

  <match **>

    type forward

    flush_interval 60s

    <server>

      host 10.210.0.7

      port 24224

    </server>

  </match>

  <source>

    type syslog

    port 5140

    bind 127.0.0.1

    tag syslog

  </source>

  <match debug.**>

    type stdout

  </match>

  <source>

    type debug_agent

    bind 127.0.0.1

    port 24230

  </source>

</ROOT>

2013-12-20 00:30:38 +0000 [info]: adding source type="syslog"

2013-12-20 00:30:38 +0000 [info]: adding source type="debug_agent"

2013-12-20 00:30:38 +0000 [info]: adding match pattern="**" type="forward"

2013-12-20 00:30:38 +0000 [info]: adding forwarding server '10.210.0.7:24224' host="10.210.0.7" port=24224 weight=60

2013-12-20 00:30:38 +0000 [info]: adding match pattern="debug.**" type="stdout"

2013-12-20 00:30:38 +0000 [info]: listening dRuby uri="druby://127.0.0.1:24230" object="Engine"

 

 

Central server:

Server

######

 

2013-12-20 00:32:01 +0000 [info]: starting fluentd-0.10.41

2013-12-20 00:32:01 +0000 [info]: reading config file path="/etc/td-agent/td-agent.conf"

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-mixin-config-placeholders' version '0.2.3'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.4'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-elasticsearch' version '0.2.0'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-flume' version '0.1.1'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-mongo' version '0.7.1'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.3.1'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-s3' version '0.3.5'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-scribe' version '0.10.10'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-td' version '0.10.17'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-td-monitoring' version '0.1.0'

2013-12-20 00:32:01 +0000 [info]: gem 'fluent-plugin-webhdfs' version '0.2.1'

2013-12-20 00:32:01 +0000 [info]: gem 'fluentd' version '0.10.41'

2013-12-20 00:32:01 +0000 [info]: using configuration file: <ROOT>

  <source>

    type forward

    port 24224

  </source>

  <source>

    type http

    port 8888

  </source>

  <match **>

    type elasticsearch

    logstash_format true

    logstash_prefix syslog

    index_name syslog

    type_name syslog

    flush_interval 3

    host es_host

    port 9200

  </match>

  <match **>

    type forward

    flush_interval 60s

    <server>

      host 10.210.0.7

      port 24224

    </server>

  </match>

  <source>

    type syslog

    port 5140

    bind 127.0.0.1

    tag syslog

  </source>

  <match debug.**>

    type stdout

  </match>

  <source>

    type debug_agent

    bind 127.0.0.1

    port 24230

  </source>

</ROOT>

2013-12-20 00:32:01 +0000 [info]: adding source type="forward"

2013-12-20 00:32:01 +0000 [info]: adding source type="http"

2013-12-20 00:32:01 +0000 [info]: adding source type="syslog"

2013-12-20 00:32:01 +0000 [info]: adding source type="debug_agent"

2013-12-20 00:32:01 +0000 [info]: adding match pattern="**" type="elasticsearch"

2013-12-20 00:32:01 +0000 [info]: adding match pattern="**" type="forward"

2013-12-20 00:32:01 +0000 [info]: adding forwarding server '10.210.0.7:24224' host="10.210.0.7" port=24224 weight=60

2013-12-20 00:32:01 +0000 [info]: adding match pattern="debug.**" type="stdout"

2013-12-20 00:32:01 +0000 [info]: listening fluent socket on 0.0.0.0:24224

2013-12-20 00:32:01 +0000 [info]: listening dRuby uri="druby://127.0.0.1:24230" object="Engine"

 

Rsyslog config on every host:

*.* @127.0.0.1:5140 #udp forwarding

*.* @10.210.0.7 #udp forwarding

 

The logs all appear to be going into elasticsearch, except there is an error field for each one that includes that “invalid strptime format - `%b %d %H:%M:%S'”, and the message isn’t parse correctly when it’s put into elasticsearch. Instead of breaking out things like the hostname and process id to separate fields, the entire message is in the message field, including timestamp hostname, etc.

 

Any help would be greatly appreciated!! Thanks!!

kiyoto

unread,
Dec 20, 2013, 2:08:04 AM12/20/13
to flu...@googlegroups.com, chede...@red5studios.com
Hi Christian,

That error shows up when the incoming timestamp format is different than syslog's default format "%b %d %H:%M:%S".

There are a couple of possibilities:

Case 1: your syslogd is configured to have a timestamp format different than the standard one.

Solution: you can either change syslogd's timestamp format to the standard one or can change in_syslog to accept your format. For the latter solution, you can add two lines "format syslog" and "time_format YOUR_TIME_FORMAT_HERE" like this

<source>
  type syslog
  format syslog
  time_format YOUR_TIME_FORMAT_HERE
 ...

Case 2: Only some of your time format different than %b %d %H:%M:%S, i.e., you are getting some data correctly into Elasticsearch.

Solution: if this is the case, you should get to the bottom of why you are getting multiple time formats from syslogd first. You can always write a filter to filter out incorrectly formatted timestamps, too.

Let us know if you have more questions.

Dionysus

unread,
Jul 10, 2014, 5:49:10 PM7/10/14
to flu...@googlegroups.com, chede...@red5studios.com
Hello,

I'm having the exact same issue and struggling to figure it out.

I am collecting logs from a Cisco Meraki AP via syslog output to td-agent. This means I cannot modify how the time is being formatted at the source. I am not clear how to format it using the time_format option exactly.



For troubleshooting, I am just sending the input to stdout

<source>
  type syslog
  format syslog
  port 5140
  bind 0.0.0.0
  tag syslog.udp
</source>

<match syslog.*>
    type stdout
</match>

Example log with error:

2014-07-09 12:27:18 +0000 [warn]: "<134>1 0.0 MR34 flows allow src=192.168.0.7 dst=173.194.34.150 mac=74:E1:B6:8E:55:6F protocol=tcp sport=52735 dport=443" error="invalid strptime format - `%b %d %H:%M:%S'"
2014-07-09 12:27:18 +0000 [warn]: "<134>1 0.0 MR34 urls src=192.168.0.7:52735 dst=173.194.34.150:443 mac=74:E1:B6:8E:55:6F request: UNKNOWN https://mail.google.com/..." error="invalid strptime format - `%b %d %H:%M:%S'"


Any help would be appreciated. 

Thanks,
Dionysus

Kiyoto Tamura

unread,
Jul 10, 2014, 5:58:33 PM7/10/14
to flu...@googlegroups.com
Hi.

Can you try running "fluentd --version" and report the output to me?

Thanks,

Kiyoto


--
You received this message because you are subscribed to the Google Groups "Fluentd Google Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fluentd+u...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--
Check out Fluentd, the open source data collector for high-volume data streams

Dionysus

unread,
Jul 10, 2014, 6:03:44 PM7/10/14
to flu...@googlegroups.com

ubuntu@ip-172-31-22-180:/$ fluentd --version

fluentd: command not found

ubuntu@ip-172-31-22-180:/$ td-agent --version

td-agent 0.10.50

Kiyoto Tamura

unread,
Jul 10, 2014, 6:15:37 PM7/10/14
to flu...@googlegroups.com
Thanks. This happens because "format syslog" tries to match the usual syslog message format, which is not what Cisco Meraki AP is sending.

Option 1

Configure Fluentd's in_syslog with "format none" as opposed to "format syslog". This captures data as a text blob.

Option 2

If you have the spec for Meraki AP syslog format, you can write a regexp for the "format" field. If you need help here, I am more than happy to help (as long as you can point me to the format spec)

Kiyoto

Cory Guynn

unread,
Jul 11, 2014, 7:29:39 AM7/11/14
to flu...@googlegroups.com
Hi Kiyoto,

Thank you very much for your help. The "format none" fixed the error message. I will attempt to parse the data from there to make it easier to manage. 

ubuntu@ip-172-31-22-180:~$ sudo tail /var/log/td-agent/td-agent.log

2014-07-11 11:12:01 +0000 syslog.udp.local0.info: {"message":"1 0.0 MR34 flows allow src=192.168.0.19 dst=192.168.0.1 mac=1C:AB:A7:2B:C8:05 protocol=icmp type=\u0003"}

2014-07-11 11:12:08 +0000 syslog.udp.local0.info: {"message":"1 0.0 MR34 flows allow src=192.168.0.4 dst=192.168.0.1 mac=10:40:F3:E3:10:01 protocol=icmp type=\u0003"}


I couldn't find any spec on the Meraki syslog, but they do have this KB article that explains the types of data they will send. 

https://kb.meraki.com/knowledge_base/syslog-server-overview-and-configuration


Again, thanks for your help. That saved me a ton of time.

- Dionysus







--
You received this message because you are subscribed to a topic in the Google Groups "Fluentd Google Group" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/fluentd/k0HU1Dkbazs/unsubscribe.
To unsubscribe from this group and all its topics, send an email to fluentd+u...@googlegroups.com.

ruan....@nesi.org.nz

unread,
Nov 27, 2016, 6:35:33 PM11/27/16
to Fluentd Google Group, chede...@red5studios.com
Hi Kiyoto,

if I understand correctly then old syslog implementations based on the 2001 BSD syslog format RFC 3146 uses the '%b %d %H:%M:%S' syntax.
The newer 2009 RFC 5424 generally supersedes that in newer implementations and use standard internet timestamp formats as per RFC 3339 e,g, 1985-04-12T23:20:50.52Z

Does syslog only support the old format, and can you consider adding the new format?

I love fluentd :-)
Thank you
Ruan

Mr. Fiber

unread,
Dec 9, 2016, 7:06:38 AM12/9/16
to Fluentd Google Group
syslog parser supports time_format parameter,
so you can parse any time format.

--
You received this message because you are subscribed to the Google Groups "Fluentd Google Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fluentd+unsubscribe@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages