Wrong timestamp after updating from 6.1.1 to 6.1.5

[wilvh]

Hi,

We have updated Graylog from version 6.1.1 to 6.1.5.
Since then, it seems that the timestamp with which messages are recorded is wrong.
Let me explain. With version 6.1.1, messages received were saved with a UTC timestamp (Graylog server time is in UTC, and root_timezone in server.conf is also in UTC)
We had set our user profiles to display messages in our local time zone (Paris). Everything was correct.

Since the installation of version 6.1.5, without changing the Graylog server settings, messages are recorded in Graylog in our time zone (Paris). Messages are then displayed in the graphical interface with one hour too many. It’s true that you can change the time zone in the user profile, but this isn’t logical and so the messages before updating are displayed with the wrong time zone.

The line “root_timezone = UTC” is commented dans le fichier server.conf but normally this is the default value.

Attached are several screenshots: a message in version 6.1.1 (with user profile set to UTC), a message in 6.1.5 (with user profile set to UTC), the time configuration on the Graylog server and the configuration in server.conf.
Messages come from the same source server.

How can we get back to pre-update behavior? That is, logs recorded in UTC and the user profile determining the display time?

Thank you for your help.

Have a nice day

• OS Information: Debian 12
• Package Version: 6.1.5

[patrickmann]

Syslog inputs: Trim newlines for Fortigate messages by danotorrey · Pull Request #20788 · Graylog2/graylog2-server · GitHub is the only change that was made to the syslog input between 6.1.1 and 6.1.5. We try hard not to change behaviour in the minor releases.

Are you running an extractor or pipeline on those messages?
What is the default timezone configured in the syslog input?

[wilvh]

Thank you for your help.

We’ve got one pipeline on these messages. This pipeline only extracts IPv4 address form message with grok pattern %{IPV4} and this pipeline already existed in version 6.1.1.
The default timezone for our syslog input is “Not configured” (we haven’t made any changes on this side). Should we change this value ?

[patrickmann]

Your log messages don’t have a syslog timestamp at the beginning (after the pri field). So GL assigns the received time as timestamp.

If you don’t want that to be UTC, I think you will need to set the root_timezone config.

If you want to use the timestamp from the informational part of the syslog message, you will need to parse it out and assign it to the timestamp field in a pipeline rule.

[wilvh]

With version 6.1.1, these same logs were recorded with a UTC timestamp, and this worked well for us.
Now the timestamps are in local time, even though we haven’t changed the configuration. This means that Graylog assigns a local time to messages instead of UTC. How can we get Graylog to assign UTC time to incoming messages (we’re not interested in the timestamp contained in our message)?

[patrickmann]

What does your input definition look like?

It works fine for me:

• using default root_timezone (commented out in .conf)
• and these input settings:

allow_override_date:
 true
bind_address:
 0.0.0.0
charset_name:
 UTF-8
expand_structured_data:
 false
force_rdns:
 false
number_worker_threads:
 12
override_source:
 <empty>
port:
 5514
recv_buffer_size:
 262144
store_full_message:
 false
timezone:
 NotSet

[wilvh]

Here is my configuration :

allow_override_date: true
bind_address: 0.0.0.0
charset_name: UTF-8
expand_structured_data: false
force_rdns: false
number_worker_threads: 4
override_source: <empty>
port: 514
recv_buffer_size: 262144
store_full_message: false
timezone: NotSet

And root_timezone is commented out in .conf

If I set timezone to “Paris” (which is my local time) in my user profile, timestamps show a future time! (example: 16:00 in the afternoon when it is 15:00 in local time)

[patrickmann]

The Syslog UDP decoder sets the message timestamp to the receive timestamp, when it cannot find a valid timestamp in the UDP message. In your example, both are the 13:57:45.000 so that is as expected. Raw receive timestamp is UTC. Is there any chance the log source is now sending UTC instead of Paris time?

[wilvh]

How can I check whether the Graylog timestamp was determined by the timestamp contained in the message or by the reception datetime ?
As you can see in the screenshot attached, sometimes the Graylog Timestamp is not equal as the timestamp contained in the message so I think that the Graylog timestamp is determined by the reception time and not extracted from message.(unless there is a timestamp rounding done by Graylog)

[patrickmann]

GL doesn’t round timestamps.
The raw receive time is saved in gl2_receive_timestamp. So you can also compare that to the timestamp field.

[wilvh]

In the screenshot attached, I’ve displayed the gl2_receive_timestamp
As you can see, the original message was sent at “10:36:48.905” (local time - Paris), was received (gl2_receive_timestamp) at “09:36:49.063” (UTC and one second delay) and timestamp is “10:36:49.000 (local time)”.

It seems that timestamp time was extracted from gl2_receive_timestamp and not from message content.
So why is the timestamp displayed in local time when my user profile is in UTC?

[patrickmann]

Date parsing is complex - hard to pin down where your timezone is exactly being set by code reading alone. Clearly though, message timestamp is in Paris TZ, while the raw message timestamp is in UTC.

I would just go ahead and update the Syslog input to have timezone etc/UTC and allow_override_date=true. That should do the trick.

[wilvh]

It turns out that our source application (HAProxy) was sending logs in rfc3164 format, which does not include a time zone. We changed the HAProxy configuration to rfc5424, which does include a time zone.

/etc/haproxy/haproxy.cfg

log syslogserver:514 format rfc5424 local0

In parallel, we modified the syslog UDP input to add our default local time zone.

Many thanks to @patrickmann for his help in solving the problem.