Dashboard and query timestamp range mismatch

[cdhg]

I see that this has been addressed in https://github.com/Graylog2/graylog2-web-interface/issues/979

I am currently experiencing the same issue (dashboard timestamp and search query timestamp skew) on graylog-server-2.0.3-1

All my timezones for the server and users are set to New York.

If I send some messages with a 2015-01-01 at 00:00:00 timestamp, the search reports the timestamp perfectly.

Expected Behavior

I believe the dashboard should report the same ranges as my search results, unless I don't understand something correctly.

Current Behavior

However, dashboards seem to show a skewed time. Although the earliest log I submitted is from Jan 1 2015 at 00:00:00, and the timestamp says so (as reported by Graylog as a "search in all messages" query), the dashboard shows that I have messages starting at Dec 31 at 19:00:00.

Possible Solution

Maybe graylog-server is using UTC time or something like that when creating the dashboards? The machine running the server is also set to the New York timezone, so I don't know where the UTC is being grabbed from.

Steps to Reproduce (for bugs)

1. Set system time to New York, your user to New York
2. Send a syslog with a 2015-01-01 00:00:00 timestamp to a syslog tcp input. Note that this step might require a bit of work because most syslogs don't add a year. For my use case, I sent RFC 5424 syslog using logstash because I needed to ingest old logs while keeping the original timestamps.
3. Do a "search in all messages" in the same input.
4. Look at the messages found table, timestamp will be correct. But dashboard above will report Dec 31.

I hope this helps.

• Graylog Version: 2.0.3-1
• Elasticsearch Version: 2.3
• MongoDB Version: 3.0.12-1
• Operating System: CentOS 6.6
• Browser version: Firefox

[edmundoa]

Hi @cdhg,

Graylog uses internally UTC to manage date times, and expects that your messages contain time zone information if that's not what you want. It looks that may be the problem you are experiencing.

Either way, would you be so kind as to share with us what you see in System -> Overview -> Time configuration? That may indicate if there is a component in your setup using a wrong time configuration.

Thank you.

[cdhg]

Hello, @edmundoa Thanks for the response.

I copypasted my timeconfig from the Overview page:

User gladmin: 2016-08-16 11:48:49 -04:00 Your web browser: 2016-08-16 11:48:49 -04:00 Graylog server: 2016-08-16 11:48:49 -04:00

The timestamps I sent look similar to "2015-09-27T04:00:01.000Z", so it might be that I am sending UTC-flagged stamps!

Update: Yes, I am sending UTC timestamps. But I adjusted them accordingly so that they match the New York time that I have parsed from my syslog files.

As I said before, the weird thing is that my "earliest" (I sent them all at once) message in my search result for the input does have the timestamp that I expect. But the dashboard does not match my search result. Here is what I am seeing, doing a search all, ordered by time (earliest to latest). The timestamp in the result is what I believe I sent, but the dashboard says that I have 50k messages for Dec that are not there. If I make a mistake, shouldn't it be consistent across my search result and the dashboard?

[edmundoa]

Thank you for the detailed answer @cdhg!

I think there are two issues here, the first one I think, is that you are comparing two different things: The histogram resolution is set to "day", meaning that it will group your events or logs by day, and show a single bar for them. The first result you see, is the first day where a log was received, and not the exact time where it was received. Switching the histogram resolution to "minute" should display the right time for the first log entry (although it may take a while to get the results).

The second issue you are experiencing is the one described in #1830. We currently use UTC to create day buckets in the histogram, which means that each bar that you see there is a day in UTC. If you look at the time displayed in the tooltip, is midnight in UTC, which in your local time zone would be 7pm.

Could you please confirm that switching to "minute" resolution displays the correct tooltip value? If that works properly, the issue with the incorrect time will be fixed with #1830.

[cdhg]

@edmundoa Thanks for the help!

I'm a bit confused by your first paragraph (first day is still Jan 1 for me, because there should be no Dec 31 logs at all and all these timestamps are ingested explicitly). But if I understand you correctly, it doesn't matter and yes, you are right! Switching minute resolution does not show any time shift in the histogram unlike the day resolution, so this really seems to be exactly #1830. I completely missed this issue when looking up past ones.

[edmundoa]

@cdhg you are welcome!

Good to read that changing the resolution gives you the expected results. That means we only have one bug to fix, instead of two.

Regarding the confusion, the problem is that time zones are complicated! The day your log was sent is Jan 1 for you, but the days in the graph are aggregated using UTC, and then converted to your local time in the browser. The result of that is that Jan 1 started before in UTC than in New York time, in fact, Jan 1 UTC started when in NY was Dec 31 at 7pm.

I hope that clarifies it a bit.

[cdhg]

@edmundoa

Ah, I see where you are going now. Yes, any of my 24h periods on any different timezone would necessarily use two different days. In this case I only needed some message before 4-5am to go back a UTC day. Thanks!