Skip to content
This repository has been archived by the owner. It is now read-only.

[dev.icinga.com #3399] FROM_UNIXTIME(NULL) does not work with MySQL 5.0.x #1146

Closed
icinga-migration opened this issue Oct 25, 2012 · 19 comments

Comments

Projects
None yet
1 participant
@icinga-migration
Copy link
Member

commented Oct 25, 2012

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

Created by gingernator007 on 2012-10-25 10:07:55 +00:00

Assignee: crfriend
Status: Resolved (closed on 2012-11-28 15:11:06 +00:00)
Target Version: 1.8.2
Last Update: 2014-12-08 14:37:55 +00:00 (in Redmine)

Icinga Version: 1.10.0
OS Version: any

After upgrading Icinga from 1.5.2 -> 1.8.0, IDOUTILS began outputting errors when trying to update the mysql db. I updated the schema incrementally as the instructions specified and shut down the Icinga service before doing so. Due to this Icinga Web can't pull the status of any of my hosts or services. Have I upgraded this incorrectly?

ido2db: Error: database query failed for 'INSERT INTO icinga_programstatus (instance_id, status_update_time, program_start_time, is_currently_running, process_id, daemon_mode, last_command_check, last_log_rotation, notifications_enabled, active_service_checks_enabled, passive_service_checks_enabled, active_host_checks_enabled, passive_host_checks_enabled, event_handlers_enabled, flap_detection_enabled, failure_prediction_enabled, process_performance_data, obsess_over_hosts, obsess_over_services, modified_host_attributes, modified_service_attributes, global_host_event_handler, global_service_event_handler, disable_notif_expire_time) VALUES (1, FROM_UNIXTIME(1350996440), FROM_UNIXTIME(1350995903), '1', 26056, 1, FROM_UNIXTIME(1350996439), FROM_UNIXTIME(NULL), 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, '', '', FROM_UNIXTIME(NULL))' - '1048: Column 'last_log_rotation' cannot be null'

Changesets

2012-11-28 14:53:21 +00:00 by mfriedrich 1042107

idoutils: fix FROM_UNIXTIME(NULL) does not work with MySQL 5.0.x refs #3399 refs #3466

basically, we treated the inner 0L as NULL, as otherwise out-of-range
warnings would be expected. since this workaround does not work with
with mysql 5.0.x we must learn it the hard way, replacing 0L directly
with the null timestamp like NULL in mysql >= 5.1.x would automatically
create on schema insert - 0000-00-00 00:00:00

kudos to Carl for the patch and fix.
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Oct 25, 2012

Updated by mfriedrich on 2012-10-25 11:54:19 +00:00

mysql> show create table icinga_programstatus;
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Oct 25, 2012

Updated by gingernator007 on 2012-10-25 12:22:24 +00:00

Thanks for the response, I've had to roll back the update due to this being our Production system, any ideas why this happened and how I can prevent it for the next attempt?

Looking back at the syslog, we have many other errors along the same lines...

ido2db: Error: database query failed for 'INSERT INTO icinga_systemcommands (instance_id, start_time, start_time_usec, end_time, e nd_time_usec, command_line, timeout, early_timeout, execution_time, return_code, output, long_output) VALUES (1, FROM_UNIXTIME(1350991944), 11462, FROM_UNIX TIME(NULL), 0, '/bin/mv /usr/local/pnp4nagios/var/service-perfdata /usr/local/pnp4nagios/var/spool/service-perfdata\.1350991944', 5, 0, 0.000000, 0, '', '') ' - '1048: Column 'end_time' cannot be null'

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Oct 25, 2012

Updated by mfriedrich on 2012-10-25 12:34:20 +00:00

without the backend schema it will be hard to determine how it had been looking when the error occured. got a test vm, where you can put the prod clone, and re-create the error?

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 1, 2012

Updated by newmanium on 2012-11-01 19:40:42 +00:00

I think I just encountered this same bug on my fresh 1.8 Icinga install. It looks timestamp fields are created NOT NULL by default in MySQL (at least 5.0+ from what I can tell). However, the CREATE statements in the schema sql script look like this:

CREATE TABLE IF NOT EXISTS icinga_servicestatus ( servicestatus_id bigint(20) unsigned NOT NULL AUTO_INCREMENT, instance_id bigint unsigned default 0, service_object_id bigint unsigned default 0, status_update_time timestamp default '0000-00-00 00:00:00', output TEXT character set latin1 default '', long_output TEXT default '', perfdata TEXT character set latin1 default '', current_state smallint default 0, has_been_checked smallint default 0, should_be_scheduled smallint default 0, current_check_attempt smallint default 0, max_check_attempts smallint default 0, last_check timestamp default '0000-00-00 00:00:00', next_check timestamp default '0000-00-00 00:00:00', check_type smallint default 0, last_state_change timestamp default '0000-00-00 00:00:00', last_hard_state_change timestamp default '0000-00-00 00:00:00', last_hard_state smallint default 0, last_time_ok timestamp default '0000-00-00 00:00:00', last_time_warning timestamp default '0000-00-00 00:00:00', last_time_unknown timestamp default '0000-00-00 00:00:00', last_time_critical timestamp default '0000-00-00 00:00:00', state_type smallint default 0, last_notification timestamp default '0000-00-00 00:00:00', next_notification timestamp default '0000-00-00 00:00:00', no_more_notifications smallint default 0, notifications_enabled smallint default 0, problem_has_been_acknowledged smallint default 0, acknowledgement_type smallint default 0, current_notification_number smallint default 0, passive_checks_enabled smallint default 0, active_checks_enabled smallint default 0, event_handler_enabled smallint default 0, flap_detection_enabled smallint default 0, is_flapping smallint default 0, percent_state_change double default '0', latency double default '0', execution_time double default '0', scheduled_downtime_depth smallint default 0, failure_prediction_enabled smallint default 0, process_performance_data smallint default 0, obsess_over_service smallint default 0, modified_service_attributes int default 0, event_handler TEXT character set latin1 default '', check_command TEXT character set latin1 default '', normal_check_interval double default '0', retry_check_interval double default '0', check_timeperiod_object_id bigint unsigned default 0, PRIMARY KEY (servicestatus_id), UNIQUE KEY object_id (service_object_id) ) ENGINE=InnoDB COMMENT='Current service status information';

Note that "NULL" is not specified in any of the timestamp columns, and they would therefore default to "NOT NULL" as per the MySQL documentation:
http://dev.mysql.com/doc/refman/5.0/en/timestamp-initialization.html

When I started up icinga with the idoutils module, I started getting a spamming of errors like this in my /var/log/messages:

Nov 1 13:58:44 cernhiemon01 ido2db: Error: database query failed for 'INSERT INTO icinga_programstatus (instance_id, status_update_time, program_start_time, is_currently_running, process_id, daemon_mode, last_command_check, last_log_rotation, notifications_enabled, active_service_checks_enabled, passive_service_checks_enabled, active_host_checks_enabled, passive_host_checks_enabled, event_handlers_enabled, flap_detection_enabled, failure_prediction_enabled, process_performance_data, obsess_over_hosts, obsess_over_services, modified_host_attributes, modified_service_attributes, global_host_event_handler, global_service_event_handler, disable_notif_expire_time) VALUES (1, FROM_UNIXTIME(1351796306), FROM_UNIXTIME(1351796306), '1', 15200, 1, FROM_UNIXTIME(1351796306), FROM_UNIXTIME(NULL), 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, 0, '', '', FROM_UNIXTIME(NULL))' - '1048: Column 'last_log_rotation' cannot be null'

So, this bugfix may be as simple as adding the word "NULL" to all the schema creation and update statements for timestamp columns. I set all my timestamp columns that were erroring in /var/log/messages to allow null values and things seem to be working fine meow.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 8, 2012

Updated by iso on 2012-11-08 15:58:37 +00:00

Same for me today at a 1.7.2 upgrade to 1.8.1. Ugrading the mysql schema by

mysql -u root -p icinga < mysql\-upgrade\-1.7.0.sql

gave errors, continued with

mysql -u root -p icinga < mysql\-upgrade\-1.8.0.sql

which run without a comment. I now have a lot of
Nov 8 16:58:00 j700s031 ido2db: Error: database query failed for 'INSERT INTO icinga_programstatus (instance_id, status_update_time, program_start_time, is_currently_running, process_id, daemon_mode, last_command_check, last_log_rotation, notifications_enabled, active_service_checks_enabled, passive_service_checks_enabled, active_host_checks_enabled, passive_host_checks_enabled, event_handlers_enabled, flap_detection_enabled, failure_prediction_enabled, process_performance_data, obsess_over_hosts, obsess_over_services, modified_host_attributes, modified_service_attributes, global_host_event_handler, global_service_event_handler, disable_notif_expire_time) VALUES (1, FROM_UNIXTIME(1352390280), FROM_UNIXTIME(1352389157), '1', 29294, 1, FROM_UNIXTIME(1352390280), FROM_UNIXTIME(NULL), 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, '', '', FROM_UNIXTIME(NULL))' - '1048: Column 'last_log_rotation' cannot be null'

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 8, 2012

Updated by mfriedrich on 2012-11-08 16:25:56 +00:00

iso wrote:

Same for me today at a 1.7.2 upgrade to 1.8.1. Ugrading the mysql schema by

mysql -u root -p icinga < mysql\-upgrade\-1.7.0.sql

that script is not necessary to be run. you should have run that already when installing/upgrading to 1.7.x

gave errors,

which errors exactly?

mysql -u root -p icinga < mysql\-upgrade\-1.8.0.sql

which run without a comment. I now have a lot of
Nov 8 16:58:00 j700s031 ido2db: Error: database query failed for 'INSERT INTO icinga_programstatus (instance_id, status_update_time, program_start_time, is_currently_running, process_id, daemon_mode, last_command_check, last_log_rotation, notifications_enabled, active_service_checks_enabled, passive_service_checks_enabled, active_host_checks_enabled, passive_host_checks_enabled, event_handlers_enabled, flap_detection_enabled, failure_prediction_enabled, process_performance_data, obsess_over_hosts, obsess_over_services, modified_host_attributes, modified_service_attributes, global_host_event_handler, global_service_event_handler, disable_notif_expire_time) VALUES (1, FROM_UNIXTIME(1352390280), FROM_UNIXTIME(1352389157), '1', 29294, 1, FROM_UNIXTIME(1352390280), FROM_UNIXTIME(NULL), 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, '', '', FROM_UNIXTIME(NULL))' - '1048: Column 'last_log_rotation' cannot be null'

mysql> show create table icinga_programstatus;
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 9, 2012

Updated by iso on 2012-11-09 08:50:15 +00:00

Cannot remember the errors and the output is gone. I was a bit confused because I knew that I had to update the db scheme incrementally. Upgrading from 1.7.2 to 1.8.1 I was not sure about the 1.7.0 and 1.8.0 files.

@
mysql> show create table icinga_programstatus;

---------------------------------------------------------------+
| Table | Create Table |

-------------
| icinga_programstatus | CREATE TABLE `icinga_programstatus` (
`programstatus_id` bigint(20) unsigned NOT NULL auto_increment,
`instance_id` bigint(20) unsigned default '0',
`status_update_time` timestamp NOT NULL default '0000-00-00 00:00:00',
`program_start_time` timestamp NOT NULL default '0000-00-00 00:00:00',
`program_end_time` timestamp NOT NULL default '0000-00-00 00:00:00',
`is_currently_running` smallint(6) default '0',
`process_id` bigint(20) unsigned default '0',
`daemon_mode` smallint(6) default '0',
`last_command_check` timestamp NOT NULL default '0000-00-00 00:00:00',
`last_log_rotation` timestamp NOT NULL default '0000-00-00 00:00:00',
`notifications_enabled` smallint(6) default '0',
`active_service_checks_enabled` smallint(6) default '0',
`passive_service_checks_enabled` smallint(6) default '0',
`active_host_checks_enabled` smallint(6) default '0',
`passive_host_checks_enabled` smallint(6) default '0',
`event_handlers_enabled` smallint(6) default '0',
`flap_detection_enabled` smallint(6) default '0',
`failure_prediction_enabled` smallint(6) default '0',
`process_performance_data` smallint(6) default '0',
`obsess_over_hosts` smallint(6) default '0',
`obsess_over_services` smallint(6) default '0',
`modified_host_attributes` int(11) default '0',
`modified_service_attributes` int(11) default '0',
`global_host_event_handler` text,
`global_service_event_handler` text,
`disable_notif_expire_time` timestamp NOT NULL default '0000-00-00 00:00:00',
PRIMARY KEY (`programstatus_id`),
UNIQUE KEY `instance_id` (`instance_id`),
KEY `programstatus_i_id_idx` (`instance_id`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1 COMMENT='Current program status information' |

-------
1 row in set (0.00 sec)

mysql>
@

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 9, 2012

Updated by mfriedrich on 2012-11-09 16:51:47 +00:00

  • (unknown custom field) changed from 1 to 5

so, the mysql version where this problem occurs, is only 5.0.x right? i cannot reproduce that on debian with 5.1.x

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 11, 2012

Updated by iso on 2012-11-11 11:50:43 +00:00

Mine is:
Server version: 5.0.67 SUSE MySQL RPM

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 14, 2012

Updated by iso on 2012-11-14 14:12:45 +00:00

I can reproduce this on a fresh installation. Syslog started to fill up as I activated the idoutils module confiuration. Without it I had all functionality I need, but no ido2db error logging.

I think that means I don't need idoutils and mysql? Weird...

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 14, 2012

Updated by mfriedrich on 2012-11-14 14:57:59 +00:00

idomod/ido2db is a requirement when using the database backend, which is a requirement for -web or -reports e.g.

deactivating the neb module (idomod) will break the communication of between core and ido2db, and therefore leaving ido2db idle doing nothing.

seems i need to get a centos 5.x virtualbox image somewhere in order to reproduce that.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 14, 2012

Updated by iso on 2012-11-14 15:02:52 +00:00

I'm running this on two sles11.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 16, 2012

Updated by aledermueller on 2012-11-16 07:17:04 +00:00

I think it is not a bug in the query or db schema, but rather in mysql. The mysql docs say:

"In addition, you can initialize or update any TIMESTAMP column to the current date and time by assigning it a NULL value, unless it has been defined with the NULL attribute to permit NULL values." [1]

FROM_UNIXTIME(NULL) gives back the value NULL and last_log_rotation is defined with 'not null', hence it should get a current time stamp.

We had the same problem on sles11 and with an update of mysql everything worked fine.

[1] http://dev.mysql.com/doc/refman/5.0/en/timestamp-initialization.html

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 19, 2012

Updated by gingernator007 on 2012-11-19 12:59:53 +00:00

Just to update this, we're running mysql 5.0.77.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 25, 2012

Updated by mfriedrich on 2012-11-25 23:29:39 +00:00

  • (unknown custom field) changed from 5 to 5
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 25, 2012

Updated by mfriedrich on 2012-11-25 23:44:33 +00:00

el5 is likely to die with the 5.0.x tree and will never provide any upgraded packages. though, i did not see such errors with my rhel 5.8 mysql 5.0.77 in the past. any chance that you check if there's a newer package revision available, maybe fixing the mentioned bug?

https://www.centos.org/modules/newbb/viewtopic.php?topic\_id=22682

other than that, from what i've seen in the community, mysql 5.5 scales even better than 5.1 (ofc with some dba love too).

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 28, 2012

Updated by mfriedrich on 2012-11-28 14:52:08 +00:00

  • Subject changed from 1 to FROM_UNIXTIME(NULL) does not work with MySQL 5.0.x
  • Category set to 24
  • Status changed from New to Assigned
  • Assigned to set to crfriend
  • Target Version set to 1.8.2

hm. Carl found an interesting one, which can be taken as reference to this issue - see #3466

So relating to that one, it's not a matter of upgrade cycles from 1.5.2 to 1.8.x, but only the FROM_UNIXTIME(NULL) change introduced in 1.8.0/1.8.1 which can be fixed by explicitely setting the null'ed timestamp then.

I expect #3466 resolving this issue as well, as it's merely a duplicate then.

@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Nov 28, 2012

Updated by mfriedrich on 2012-11-28 15:11:06 +00:00

  • Status changed from Assigned to Resolved
  • Done % changed from 0 to 100
@icinga-migration

This comment has been minimized.

Copy link
Member Author

commented Dec 8, 2014

Updated by mfriedrich on 2014-12-08 14:37:55 +00:00

  • Project changed from 18 to Core, Classic UI, IDOUtils
  • Category changed from 24 to IDOUtils
  • Icinga Version changed from 1 to 1
  • OS Version set to any

@icinga-migration icinga-migration added this to the 1.8.2 milestone Jan 17, 2017

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.