[dev.icinga.com #13607] Displayed times messed up in Icinga Web 2.4.0 w/ PostgreSQL

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/13607

Created by mj84 on 2016-12-15 10:30:20 +00:00

Assignee: (none)
Status: New
Target Version: 2.4.1
Last Update: 2017-01-13 08:59:42 +00:00 (in Redmine)

---

Hello,

after upgrading my Icinga Web 2 installation to 2.4.0, I've experienced an issue regarding the displayed times, such as state duration and the time of the next check.
My Browser timezone is set to Europe/Berlin, same goes for PHP and the user options in Icinga Web 2.

However, when I issue the "check now" command to any of my hosts or services, I can see the following:

Last check 60m 4s ago
Next check at 12:28 (my default check interval is 5 min, so it always displays the current time + 65 minutes)

So for some reason, all these times are off by an hour into the future.
I suspect that this might be a JavaScript related issue, since when I reschedule a check, I can see a correct timestamp in Icinga2's logfile.

Regards,
Markus

Changesets

2017-01-12 15:05:29 +00:00 by mfriedrich 9148099

Fix local timestamp for PostgreSQL queries

This fixes the "monitoring health" view indicating that Icinga 2
isn't updating the database, even if status_update_time uptodate.

refs #13607

---

Relations:

• relates #13617
• duplicates #13607

[icinga-migration]

Updated by mj84 on 2016-12-15 10:33:10 +00:00

I'm sorry, this does NOT belong to JavaScript, the times off by an hour are also in the data being loaded from the server

[icinga-migration]

Updated by elippmann on 2016-12-15 10:34:44 +00:00

Hi,

Which time zone is configured in your preferences?

Best regards,
Eric

[icinga-migration]

Updated by elippmann on 2016-12-15 10:35:39 +00:00

Sorry, I missed your second sentence!

[icinga-migration]

Updated by elippmann on 2016-12-15 10:36:23 +00:00

Which database backend and which Icinga 2 version are you using?

[icinga-migration]

Updated by mj84 on 2016-12-15 10:47:28 +00:00

I am using PostgreSQL as backend with Icinga 2.6.0

[icinga-migration]

Updated by elippmann on 2016-12-15 10:49:28 +00:00

Do you have a cookie named icingaweb2-tzo? If so, please post its content.

[icinga-migration]

Updated by elippmann on 2016-12-15 10:50:10 +00:00

• Duplicated set to 13611

[icinga-migration]

Updated by mj84 on 2016-12-15 10:53:00 +00:00

I have this cookie:
icingaweb2-tzo=3600-0; path=/

[icinga-migration]

Updated by elippmann on 2016-12-15 11:00:08 +00:00

@mj84 What do you mean w/ "the times off by an hour are also in the data being loaded from the server" ?

[icinga-migration]

Updated by elippmann on 2016-12-15 11:01:57 +00:00

Could you guys please add &format=json to the URL of a detail view where the timestamps are wrong and post the output please.

[icinga-migration]

Updated by mj84 on 2016-12-15 11:08:35 +00:00

This is the requested JSON:
{"status":"success","data":{"instance_name":"default","host_attempt":"1\/5","host_icon_image":"","host_icon_image_alt":"","host_acknowledged":0,"host_active_checks_enabled":1,"host_address":"127.0.0.1","host_address6":"","host_alias":"MyHost","host_display_name":"MyHost","host_handled":0,"host_in_downtime":0,"host_is_flapping":0,"host_last_state_change":1481789664,"host_name":"MyHost","host_notifications_enabled":1,"host_passive_checks_enabled":1,"host_state":0,"host_state_type":1,"service_icon_image":"","service_icon_image_alt":"","service_acknowledged":0,"service_acknowledgement_type":0,"service_action_url":"\/pnp4nagios\/index.php\/graph?host=$host.name$&srv=$service.name$","service_active_checks_enabled":1,"service_active_checks_enabled_changed":0,"service_attempt":"1\/3","service_check_command":"snmp-aruba-aps","service_check_execution_time":"31.997885","service_check_latency":"0.493834","service_check_source":"satellite-a","service_check_timeperiod":null,"service_current_notification_number":0,"service_description":"ARUBA Access Points","service_display_name":"ARUBA Access Points","service_event_handler_enabled":1,"service_event_handler_enabled_changed":0,"service_flap_detection_enabled":1,"service_flap_detection_enabled_changed":0,"service_handled":0,"service_in_downtime":0,"service_is_flapping":1,"service_is_reachable":1,"service_last_check":1481803399,"service_last_notification":3600,"service_last_state_change":1481803151,"service_long_output":"","service_next_check":1481803698,"service_next_update":"1481804031","service_notes":"","service_notes_url":"","service_notifications_enabled":1,"service_notifications_enabled_changed":0,"service_obsessing":0,"service_obsessing_changed":0,"service_output":"check_aruba_ap OK - 23 access points are up, 0 are down.","service_passive_checks_enabled":1,"service_passive_checks_enabled_changed":0,"service_percent_state_change":"49","service_perfdata":"down_aps=0;5;8 up_aps=23 unprovisioned_aps=0","service_process_perfdata":1,"service_state":0,"service_state_type":1,"contacts":{"my-contact-1":"Helpdesk","my-contact-2":"Customer"},"contact_groups":[],"vars":{"aruba_crit":"8","aruba_warn":"5","notification":{"delay":0,"interval":600},"snmp_community":"public"},"servicegroups":[]}}

I can see that the timestamps which are off by an hour are already included in the HTML when refreshing a view:
<span class="relative-time time-ago" title="2016-12-15 13:03:19">59m 54s ago</span>

[icinga-migration]

Updated by elippmann on 2016-12-15 11:24:30 +00:00

Thanks for the output. Did you run the schema upgrade? You can verify this by running

SELECT * FROM icinga_dbversion

It should yield 1.14.2 in the version field.

The timestamp in the database seems wrong.

[icinga-migration]

Updated by mj84 on 2016-12-15 11:29:34 +00:00

icinga2idopgsql=# SELECT * FROM icinga_dbversion; dbversion_id | name | version | create_time | modify_time --------------+----------+---------+----------------------------+---------------------------- 1 | idoutils | 1.14.2 | 2015-02-11 12:20:30.601812 | 2016-12-15 09:11:13.698825
seems fine to me, the schema upgrade ran this morning during the apt upgrade process

[icinga-migration]

Updated by elippmann on 2016-12-15 11:50:05 +00:00

Could you please run another query. Replace host_name and service_description w/ your names.

SELECT * FROM icinga_servicestatus s INNER JOIN icinga_objects o ON s.service_object_id = o.object_id WHERE o.objecttype_id = 2 AND o.name1 = host_name AND o.name2 = service_description

[icinga-migration]

Updated by mj84 on 2016-12-15 12:05:23 +00:00

The timestamps in the DB look fine to me:

@ servicestatus_id | instance_id | service_object_id | status_update_time | output | long_output | perfdata | check_source | current_state | has_been_checked | should_be_scheduled | current_check_attempt | max_check_attempts | last_check | next_check | check_type | last_state_change | last_hard_state_change | last_hard_state | last_time_ok | last_time_warning | last_time_unknown | last_time_critical | state_type | last_notification | next_notification | no_more_notifications | notifications_enabled | problem_has_been_acknowledged | acknowledgement_type | current_notification_number | passive_checks_enabled | active_checks_enabled | event_handler_enabled | flap_detection_enabled | is_flapping | percent_state_change | latency | execution_time | scheduled_downtime_depth | failure_prediction_enabled | process_performance_data | obsess_over_service | modified_service_attributes | event_handler | check_command | normal_check_interval | retry_check_interval | check_timeperiod_object_id | is_reachable | endpoint_object_id | original_attributes | object_id | instance_id | objecttype_id | name1 | name2 | is_active
-----------------*------------------------------~~--------------------*---------------------------------------------------------------------~~---------------------------------------------*---------------------------~~-----------------*------------------------------------------~~-------------------*----------------------------------------~~-----------*-------------------------------------------~~----------------*----------------------------------------~~--------------------*-------------------------------~~--------------------*--------------------+----------------------*----------------------------------------------------~~---------------------*---------------------------------------------------~~----------------------*---------------------------------------------~~------------*------------------------------~~---------------*----------------------------------------------------~~-------------------------*------------------------------------------------~~--------------*-------------------------------------~~---------------------*----------------------------------------~~-------------------*------------------------------~~------------+---------------------~~--------------------+----------
5825 | 1 | 15305 | 2016-12-15 12:58:17 | check_aruba_ap OK - 23 access points are up, 0 are down. | | down_aps=0;5;8 up_aps=23 unprovisioned_aps=0 | satellite-a | 0 | 1 | 1 | 1 | 3 | 2016-12-15 12:58:17 | 2016-12-15 13:02:12 | 0 | 2016-12-15 12:58:17 | 2016-12-15 12:58:17 | 0 | 2016-12-15 12:58:17 | 1970-01-01 01:00:00 | 2016-12-15 12:57:17 | 1970-01-01 01:00:00 | 1 | 1970-01-01 01:00:00 | 2016-12-15 10:46:35 | 0 | 1 | 0 | 0 | 0 | 1 | 1 | 1 | 1 | 1 | 47 | 0.000673 | 1.897254 | 0 | 0 | 1 | 0 | 0 | | snmp-aruba-aps | 5 | 1 | 0 | 1 | 3 | null | 15305 | 1 | 2 | MyHost | ARUBA Access Points | 1
(1 row)@

[icinga-migration]

Updated by elippmann on 2016-12-15 13:44:15 +00:00

Could you please run the following command in PostgreSQL and retest w/ check now.

ALTER DATABASE icinga2 SET timezone TO 'UTC';

[icinga-migration]

Updated by mj84 on 2016-12-15 14:14:13 +00:00

This did not change anything for me.
What did work, is changing the timezone in postgresql.conf to UTC

[icinga-migration]

Updated by elippmann on 2016-12-15 15:11:50 +00:00

• Relates set to 13617

[icinga-migration]

Updated by mfriedrich on 2017-01-12 15:07:14 +00:00

• Subject changed from Displayed times messed up in Icinga Web 2.4.0 to Displayed times messed up in Icinga Web 2.4.0 w/ PostgreSQL
• Category changed from JavaScript to Monitoring
• Target Version set to 2.4.1

This problem requires 2 fixes:

• Icinga 2 v2.6.1 with timestamps written in UTC - see #13617

This solves the majority of timestamp representation in the Icinga Web 2 views.

The second fix requires a patch in Icinga Web 2.

• IdoQuery replaces NOW () with localtimestamp. This is wrong since the returned timestamp respects the time zone. You'll explicitly need "NOW() AT TIME ZONE 'UTC'" similar to the inserted values.

This solves the problem that the Monitoring Health view tells you that the data is outdated. "is_currently_running" is evaluated as such. The query can be extracted from http://localhost/icingaweb2/monitoring/health/info?format=sql

icinga=# select case when (unix_timestamp(status_update_time) +60 > unix_timestamp(localtimestamp)) then 1 else 0 end from icinga_programstatus;
 case
------
    0
(1 row)

icinga=# select case when (unix_timestamp(status_update_time) +60 > unix_timestamp(Now() AT TIME ZONE 'UTC')) then 1 else 0 end from icinga_programstatus;
 case
------
    1
(1 row)

@eric
Assigning to 2.4.1 so that you don't forget to review the pushed fix branch :)

[icinga-migration]

Updated by elippmann on 2017-01-13 08:59:42 +00:00

Thanks for the information and proper fix Michael.