Describe the bug
Fluentd can report incorrect timestamps when taking input timestamps in UTC with no explicit timezone and then the local timezone changes.
To Reproduce
Start with a system configured with local time as UTC. Take this fluentd config that tails a log file which always logs timestamps in UTC but without an explicit timezone identifier, and then start fluentd.
<source>
@type tail
path /var/log/something.log
pos_file /some/path/to/fluentd/something.pos
tag UTCIssue
read_from_head true
path_key log_path
<parse>
@type multiline
time_key timestamp
time_format %F %T,%L
localtime false
format_firstline /\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}/
format1 /^(?<timestamp>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}) (?<message>.*)/
</parse>
</source>
Then, change the local timezone to, say, America/New_York. Log messages that are parsed after the timezone is changed will show up 5 hours "in the future".
Expected behavior
The timestamps continue to be emitted correctly.
Your Environment
- Fluentd or td-agent version: 1.7.0 -- I realize this is an older version, but I believe this bug is still present on master (see below).
- Operating system: Amazon Linux 2018.03
- Kernel version: 4.14.154-99.181.amzn1.x86_64
Your Configuration
See above
Your Error Log
None
Additional context
I think the problem stems from
|
offset_diff = case |
|
when format_with_timezone then nil |
|
when timezone then |
|
offset = Fluent::Timezone.utc_offset(timezone) |
|
if offset.respond_to?(:call) |
|
->(t) { Time.now.localtime.utc_offset - offset.call(t) } |
|
else |
|
Time.now.localtime.utc_offset - offset |
|
end |
|
when localtime then 0 |
|
else Time.now.localtime.utc_offset # utc |
|
end |
In this case, when fluentd starts up and parses the config, offset_diff is statically calculated as 0. When the timezone is changed to America/New_York, then when the parse method is called, Ruby's Time.strptime will parse a time string like 2020-01-30 08:00:00,000 as being in EDT rather than UTC, but because offset_diff is still 0, it won't be corrected and so fluentd will treat this as 2020-01-30 13:00:00 UTC, which is wrong.
Just based on looking at the code, I also think that there will be a similar issue when DST starts and ends.
Describe the bug
Fluentd can report incorrect timestamps when taking input timestamps in UTC with no explicit timezone and then the local timezone changes.
To Reproduce
Start with a system configured with local time as UTC. Take this fluentd config that tails a log file which always logs timestamps in UTC but without an explicit timezone identifier, and then start fluentd.
Then, change the local timezone to, say, America/New_York. Log messages that are parsed after the timezone is changed will show up 5 hours "in the future".
Expected behavior
The timestamps continue to be emitted correctly.
Your Environment
Your Configuration
See above
Your Error Log
None
Additional context
I think the problem stems from
fluentd/lib/fluent/time.rb
Lines 221 to 232 in bfdc269
In this case, when fluentd starts up and parses the config,
offset_diffis statically calculated as 0. When the timezone is changed to America/New_York, then when theparsemethod is called, Ruby'sTime.strptimewill parse a time string like2020-01-30 08:00:00,000as being in EDT rather than UTC, but becauseoffset_diffis still 0, it won't be corrected and so fluentd will treat this as 2020-01-30 13:00:00 UTC, which is wrong.Just based on looking at the code, I also think that there will be a similar issue when DST starts and ends.