MySQL Bugs: #48816: INSERT query run from an event appears to use GMT time data for NOW

Bug #48816	INSERT query run from an event appears to use GMT time data for NOW
Submitted:	16 Nov 2009 19:59	Modified:	27 Nov 2009 19:17
Reporter:	Timothy Loach	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Stored Routines	Severity:	S3 (Non-critical)
Version:	5.1.11, 5.1.40	OS:	Windows (XP PRO)
Assigned to:		CPU Architecture:	Any
Tags:	Event, event scheduler, GMT, time

Description:
When running the following event the data inserted in the completedTime column appears to be using the GMT time, rather than the system time which the mysql instance is configured to use.  Running the same query outside of the event produces the expected input with completedTime reflecting the system (GMT-5) time.

event definition:
delimiter |

CREATE EVENT JOB_TIMEOUT ON SCHEDULE EVERY 1 MINUTE STARTS NOW() ENABLE DO
BEGIN
  SET @DISABLE_TRIGGER = 1;
  UPDATE stagentjob, job 
  SET agentStatus = 'TIMEOUT', 
      jobStatus = 'COMPLETED', 
      isSuccessful = 0, 
      completedTime = NOW()
    WHERE agentStatus <> 'COMPLETE' AND 
          agentStatus <> 'TIMEOUT' AND
          agentStatus <> 'CANCELLED' AND
          stagentjob.jobId = job.jobId AND
         ((NOT job.targetTime IS NULL AND 
            NOW() > DATE_ADD(job.targetTime, INTERVAL 15 MINUTE)) 
         OR
         (job.targetTime IS NULL AND 
            NOW() > DATE_ADD(job.requestDate, INTERVAL 15 MINUTE)));
  SET @DISABLE_TRIGGER = NULL;
END;
|

The NOW() calls appear to all be using GMT.  Rows are inserted with requestDate = NOW() outside of the event system, and the first run of the event updates the row so that it appears as follows:

jobId, jobType, requestDate, targetTime, completedTime, ScenarioName, jobStatus, isSuccessful
143, 'EXECUTEACTIONPLAN', '2009-11-16 14:32:12', '', '2009-11-16 19:32:41', 'medium-48135', 'COMPLETED', 0

How to repeat:
The following is the schema for the required tables

CREATE  TABLE IF NOT EXISTS `stm`.`Job` (
  `jobId` INT NOT NULL AUTO_INCREMENT,
  `jobType` ENUM('DEPLOY', 'EXECUTE', 'EXECUTEACTIONSCRIPT') NOT NULL ,
  `requestDate` DATETIME NOT NULL ,
  `targetTime` DATETIME NULL ,
  `completedTime` DATETIME NULL ,
  `ScenarioName` VARCHAR(45) NOT NULL ,
  `jobStatus` ENUM('ASSIGNED', 'COMPLETED') NULL ,
  `isSuccessful` TINYINT NOT NULL DEFAULT 1 ,
  PRIMARY KEY (`jobId`, `jobType`) );
CREATE  TABLE IF NOT EXISTS `stm`.`STAgentJob` (
  `agentJobId` INT NOT NULL AUTO_INCREMENT,
  `jobId` INT NOT NULL ,
  `jobType` ENUM('DEPLOY', 'EXECUTE', 'EXECUTEACTIONSCRIPT') NOT NULL ,
  `ip` INT UNSIGNED NOT NULL ,
  `agentStatus` ENUM('READY', 'PICKEDUP', 'COMPLETE', 'TIMEOUT', 'CANCELLED') NULL ,
  PRIMARY KEY (`agentJobId`, `jobType`, `jobId`) ,
  INDEX `fk_STAgentJob_Job1` (`jobId` ASC, `jobType` ASC) ,
  UNIQUE INDEX `unique_ID_IP` (`jobId` ASC, `ip` ASC) ,
  UNIQUE INDEX `unique_ID` (`agentJobId` ASC) ,
  CONSTRAINT `fk_STAgentJob_Job1`
    FOREIGN KEY (`jobId` , `jobType` )
    REFERENCES `stm`.`Job` (`jobId` , `jobType` )
    ON DELETE NO ACTION
    ON UPDATE NO ACTION);

insert a few rows:
INSERT INTO `job` (`jobId`,`jobType`,`requestDate`,`targetTime`,`completedTime`,`ScenarioName`,`jobStatus`,`isSuccessful`) VALUES 
 (1,'DEPLOY','2009-11-13 10:35:26',NULL,NULL,'testLocal-55734','COMPLETED',0),
 (2,'EXECUTE','2009-11-13 10:35:26',NULL,NULL,'testLocal-55734','COMPLETED',0),
 (3,'EXECUTE','2009-11-13 10:35:37',NULL,NULL,'testLocal-55734','COMPLETED',0);

INSERT INTO `stagentjob` (`agentJobId`,`jobId`,`jobType`,`ip`,`agentStatus`) VALUES 
 (1,1,'DEPLOY',3232238181,'READY'),
 (2,2,'EXECUTE',3232238181,'READY'),
 (3,3,'EXECUTE',3232238181,'READY');

Start the event specified in the description on a MySQL instance that uses system time with a GMT offset.  Sometimes it seems to work properly for a while after the event is inserted and the instance is started (a day, maybe), so just set the completedTime column to null and agentStatus to READY to test.

Thank you for the bug report. The version reported 5.1.11 is quite older, could you please try the release 5.1.40 and comment the results. Thanks in advance.

Same behaviour in 5.1.40.

Taking a closer look at the mysql.event table I see that the time_zone field is set to '+00:00'.  When I set it to '-05:00' the correct time is set.  Is it expected behaviour for events to use their own time zone settings rather than @@time_zone?  Is this bug simlpy that event.time_zone isn't being populated properly from the system time at event creation?

(reducing severity since this I now have a work-around)

Please, check @@time_zone value before you create event. Our manual (http://dev.mysql.com/doc/refman/5.1/en/create-event.html) says:

"Times in the ON SCHEDULE clause are interpreted using the current session time_zone value. This becomes the event time zone; that is, the time zone that is used for event scheduling and is in effect within the event as it executes. These times are converted to UTC and stored along with the event time zone in the mysql.event table."

I took that section of the manual to mean that the time that the event triggers at is set in the event table.  In this case the event runs every minute starting when it is created, I could really care less what time zone the scheduler's time is in.  I would not take this statement to mean that any access to the NOW or SYSDATE functions would use the event.time_zone. 

My @@time_zone is set to SYSTEM, and my system time is set to GMT-05:00, so even if the date functions are supposed to use event.time_zone the event.time_zone value is not setting properly when creating an event.

Thank you for the feedback.

I can not repeat described behavior: just created event uses correct value of time_zone:

mysql> select @@time_zone;
+-------------+
| @@time_zone |
+-------------+
| SYSTEM      |
+-------------+
1 row in set (0.04 sec)

mysql> create event ev2 on schedule every 1 minute do select 1;
Query OK, 0 rows affected (0.11 sec)

mysql> select * from mysql.event where name='ev2'\G
*************************** 1. row ***************************
                  db: test
                name: ev2
                body: select 1
             definer: root@localhost
          execute_at: NULL
      interval_value: 1
      interval_field: MINUTE
             created: 2009-11-27 11:47:16
            modified: 2009-11-27 11:47:16
       last_executed: NULL
              starts: 2009-11-27 08:47:16
                ends: NULL
              status: ENABLED
       on_completion: DROP
            sql_mode: 
             comment: 
          originator: 0
           time_zone: SYSTEM
character_set_client: latin1
collation_connection: latin1_swedish_ci
        db_collation: utf8_unicode_ci
           body_utf8: select 1
1 row in set (0.36 sec)

Please try to create event after you are sure session  @@time_zone value is not GMT and if you still have the problem paste output of the session as I did.

I am now unable to reproduce, so closing the ticket.