timezones confusing

[Brad Rhodes]

Read all the issues that have been fixed.  Read the Timezone source code.  Have done tons of diligence to try and figure this out.  But just cannot seem to get my head around a  timezone issue.

Remote system is run by partner company.  They are obtuse, unable to modify their systems and deathly afraid of installing software because of security.  So a decision was made to forward their logs using rsyslog, and then we would parse and format those logs on a fluentd we have in front of our elasticsearch cluster.  

Their system is in PST timezone.  And sending the data over rfc3164 format.

<190>May 14 16:55:34 xxxxxx tracker  ....

There is no + or - in the date time field.  There is a later date time field that has 2017-05-14T23:55:28.955+0000, here the timezone is incorrectly stated as +0000, when the machine is running in PST.  But none of that matters, it is the first date time field that is used by Fluentd. 

The machine running the fluentd process is running in UTC.  So it, of course converts the message, and forwards to elasticsearch, representing the PST time as UTC.  

We are using version 14.12 (google-fluentd), and we are using the syslog input and the elasticsearch output.  We are using the stdout and file outputs for testing our timezone changes as well.

So far in this configuration adding a timezone field to syslog input, elasticsearch output or stdout output does nothing.  It is like the field is getting ignored.  I have set it to wild values, valid values, invalid values, it does nothing.

Using localtime true or localtime false, also does nothing.

Using utc anywhere, results in a confusing error that localtime is already being used, and you cannot specify utc. 

Why does timezone field not work?

Any better ways to debug this problem?  

Changing timezone for the entire process seems incorrect.   We have a number of people pushing logs to this process.  I guess I could split these off to their own port and create a new process, but that is a lot of systemd stuff that I am trying to avoid.

<source>

  @type syslog

  tag system

  port 5140

  timezone -07:00

</source>

<match *>

   @type copy

   <store>

     @type elasticsearch

     logstash_format true

     host localhost

     port 9200

     logstash_prefix quincy-brad

     index_name quincy-brad

#     localtime true

#     utc true

#     timezone -0700

     flush_interval 5s #for testing

   </store>

   <store>

#     localtime true

#     utc true

#     timezone -07:00

     @type stdout

#     format json

   </store>

</match>

[Brad Rhodes]

Ok solved this myself.  This solution should be good for general handling of Timezone issues in fluentd log messages.

### test code
### generates a stream of messages that contain a date time
<source>
  type exec
  run_interval 3s
  format json
  command echo '{"message":"hello,2013-03-03 12:00:13 "}'
  tag first
</source>
### test code
### Use the above message Date Time text as the 'time' of the fluentd record.
###   this uses a 'feature' of the parser that allows you to overwrite a records
<match first>
  @type parser
  key_name message
  time_key my_time
  time_format %Y-%m-%d %H:%M:%S
# time_zone +0700
  format /^(?<some_field>[^,]*),(?<my_time>.*)/
  tag third
</match>


#  The actualy move of the timezone.
#    We create an aadtional record in the log message.  This will be text version of the fixed up timestamp.
#    TZInfo is needed and is typically already brought by elasticsearch plugin.
#    This code does not need Rails or ActiveSupport.  Those seemed super heavy for such a simple manipulation.
#    This code assumes foriegn machine is sending localtime (PDT), with +0000 as the timezone specifier.  The local
#    fluentd box is running in UTC.
<filter third>
  @type record_transformer
  enable_ruby true
  log_level debug
  <record>
    fixed_time ${tz=TZInfo::Timezone.get("America/Los_Angeles");utc_time=tz.utc_to_local(time);utc_time.strftime("%Y-%m-%d %H:%M:%S %z")}
  </record>
</filter>
#uncomment the following if you want the record_transformer is doing.
#<match third>
#   @type stdout
#</match>


# Now we can use the parser to put that time field in as our log messages time.
<match  third>
  @type parser
  key_name fixed_time
  timezone +0700
  time_format %Y-%m-%d %H:%M:%S %z
  format /^(?<time2>.*)/
  time_key  time2
  tag fourth
  log_level debug
</match>
<match fourth>
#  localtime true
#  timezone +0700
  @type stdout
</match>

 

[Brad Rhodes]

And I think this one is quite a bit cleaner, and easier to understand.

### test code
### generates a stream of messages that contain a date time
<source>
  type exec
  run_interval 3s

  format json
  command echo '{"message":"hello,foo,2017-05-16 08:00:13"}'
  tag first
</source>

### test code
### Use the above message Date Time text as the 'time' of the fluentd record.
###   this uses a 'feature' of the parser that allows you to overwrite a records
<match first>
  @type parser
  key_name message
  time_key my_time
  time_format %Y-%m-%d %H:%M:%S

  format /^(?<some_field>[^,]*),(?<anohter_field>[^,]*),(?<my_time>.*)/
  tag second
</match>
#<match second>
#  @type record_modifier
#  foo "bar"
#  tag seconda
#</match>
#<match second>

#  @type stdout
#</match>

#  The actualy move of the timezone.
#    We create an aadtional record in the log message.  This will be text version of the fixed up timestamp.
#    TZInfo is needed and is typically already brought by elasticsearch plugin.
#    This code does not need Rails or ActiveSupport.  Those seemed super heavy for such a simple manipulation.
#    This code assumes foriegn machine is sending localtime (PDT), with +0000 as the timezone specifier.  The local
#    fluentd box is running in UTC.

<filter second>
  @type record_transformer
  enable_ruby true
  @log_level debug
  <record>
    fixed_time ${tz=TZInfo::Timezone.get("America/Los_Angeles");newtime=tz.local_to_utc(time, true);newtime.to_i.to_s}
  </record>
</filter>
<filter second>
  @type record_transformer
  @log_level debug
  renew_time_key fixed_time
</filter>

#uncomment the following if you want the record_transformer is doing.

#<match second>

#   @type stdout
#</

match>

# Now we can use the parser to put that time field in as our log messages time.

#<match  second>
#  @type parser
#  key_name fixed_time
#  time_format %Y-%m-%d %H:%M:%S %z
#  format /(?<some>.*),(?<time2>[^,]+)/
#  time_key  time2
#  tag third
#  log_level debug
#</match>
<match second>