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

icinga-migration · 2012-10-25T10:07:55Z

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.

The text was updated successfully, but these errors were encountered:

icinga-migration · 2012-10-25T11:54:19Z

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

mysql> show create table icinga_programstatus;

icinga-migration · 2012-10-25T12:22:24Z

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 · 2012-10-25T12:34:20Z

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 · 2012-11-01T19:40:42Z

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 · 2012-11-08T15:58:37Z

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 · 2012-11-08T16:25:56Z

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 · 2012-11-09T08:50:15Z

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 · 2012-11-09T16:51:47Z

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 · 2012-11-11T11:50:43Z

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

Mine is:
Server version: 5.0.67 SUSE MySQL RPM

icinga-migration · 2012-11-14T14:12:45Z

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 · 2012-11-14T14:57:59Z

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 · 2012-11-14T15:02:52Z

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

I'm running this on two sles11.

icinga-migration · 2012-11-16T07:17:04Z

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 · 2012-11-19T12:59:53Z

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 · 2012-11-25T23:29:39Z

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

(unknown custom field) changed from 5 to 5

icinga-migration · 2012-11-25T23:44:33Z

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 · 2012-11-28T14:52:08Z

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 · 2012-11-28T15:11:06Z

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 · 2014-12-08T14:37:55Z

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 closed this as completed Nov 28, 2012

icinga-migration added bug IDOUtils labels Jan 17, 2017

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

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Nov 1, 2012

icinga-migration commented Nov 8, 2012

icinga-migration commented Nov 8, 2012

icinga-migration commented Nov 9, 2012

icinga-migration commented Nov 9, 2012

icinga-migration commented Nov 11, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 16, 2012

icinga-migration commented Nov 19, 2012

icinga-migration commented Nov 25, 2012

icinga-migration commented Nov 25, 2012

icinga-migration commented Nov 28, 2012

icinga-migration commented Nov 28, 2012

icinga-migration commented Dec 8, 2014

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

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

Comments

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Oct 25, 2012

icinga-migration commented Nov 1, 2012

icinga-migration commented Nov 8, 2012

icinga-migration commented Nov 8, 2012

icinga-migration commented Nov 9, 2012

icinga-migration commented Nov 9, 2012

icinga-migration commented Nov 11, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 14, 2012

icinga-migration commented Nov 16, 2012

icinga-migration commented Nov 19, 2012

icinga-migration commented Nov 25, 2012

icinga-migration commented Nov 25, 2012

icinga-migration commented Nov 28, 2012

icinga-migration commented Nov 28, 2012

icinga-migration commented Dec 8, 2014