MySQL Bugs: #33832: NOW()/SYSDATE(): Not as documented within stored routines

Bug #33832	NOW()/SYSDATE(): Not as documented within stored routines
Submitted:	12 Jan 2008 15:14	Modified:	5 Jun 2009 18:06
Reporter:	Paul DuBois	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Stored Routines	Severity:	S3 (Non-critical)
Version:	5.0 and up	OS:	Any
Assigned to:	Paul DuBois	CPU Architecture:	Any

Description:
The manual says this about NOW():

NOW() returns a constant time that indicates the time at which the statement began to execute. (Within a stored routine or trigger, NOW() returns the time at which the routine or triggering statement began to execute.) This differs from the behavior for SYSDATE(), which returns the exact time at which it executes as of MySQL 5.0.13.

And it says this about SYSDATE():

As of MySQL 5.0.13, SYSDATE() returns the time at which it executes. This differs from the behavior for NOW(), which returns a constant time that indicates the time at which the statement began to execute. (Within a stored routine or trigger, NOW() returns the time at which the routine or triggering statement began to execute.)

(See http://dev.mysql.com/doc/refman/5.0/en/date-and-time-functions.html)

I cannot confirm the behavior that within stored routines and triggers, NOW() returns the routine/trigger execution begin time. NOW() appears to return the statement execution begin time, not the routine/trigger execution begin time.

My test case follows.

My question is: Is the documention incorrect, or is this a server bug? If the documentation is incorrect, please indicate that and reassign this report to me. Otherwise, please fix the bug.

Additional question: The reason I investigated this was because I wanted to document whether the behavior mentioned for stored routines and triggers was also true for event (in 5.1 and up). So, whatever the outcome of this bug report, is the behavior of NOW() and SYSDATE() within stored routines and triggers also supposed to be true for events? Thank you.

How to repeat:
Test case (5.0.56, 5.1.23, 6.0.5):

drop procedure if exists p;
delimiter $$
create procedure p()
begin
  select sysdate(), now(), sleep(2), sysdate(), now();
  do sleep(5);
  select sysdate(), now(), sleep(2), sysdate(), now();
end$$
delimiter ;
call p()\G

Result:

*************************** 1. row ***************************
sysdate(): 2008-01-12 09:06:14
    now(): 2008-01-12 09:06:14
 sleep(2): 0
sysdate(): 2008-01-12 09:06:16
    now(): 2008-01-12 09:06:14
*************************** 1. row ***************************
sysdate(): 2008-01-12 09:06:21
    now(): 2008-01-12 09:06:21
 sleep(2): 0
sysdate(): 2008-01-12 09:06:23
    now(): 2008-01-12 09:06:21

SLEEP() does indeed reflect actual function execution time, as documented.

NOW() appears to reflect statement execution time, not routine execution time. (For the latter, I would expect it to return a constant value at all times within the routine.)

Here is a test case for events. The behavior for NOW()/SYSDATE() appears to be similar to that within stored routines/triggers.

drop table if exists t;
create table t (d1 datetime, d2 datetime, s int, d3 datetime, d4 datetime);
drop event if exists e;
delimiter $$
create event e
on schedule at now()
on completion not preserve
do
begin
  insert into t select sysdate(), now(), sleep(2), sysdate(), now();
  do sleep(5);
  insert into t select sysdate(), now(), sleep(2), sysdate(), now();
end$$
delimiter ;
do sleep(10);
select * from t\G

Result (5.1.23, 6.0.5):

*************************** 1. row ***************************
d1: 2008-01-12 09:12:37
d2: 2008-01-12 09:12:37
 s: 0
d3: 2008-01-12 09:12:39
d4: 2008-01-12 09:12:37
*************************** 2. row ***************************
d1: 2008-01-12 09:12:44
d2: 2008-01-12 09:12:44
 s: 0
d3: 2008-01-12 09:12:46
d4: 2008-01-12 09:12:44

Thank you for the bug report.

Workaround: Set a local variable to the value of now() as the first line in the SP and use it throughout the SP to emulate the intended behavior of now().

More research into the current behavior of NOW() and SYSDATE():

NOW() returns the time when the current statement started executing.
SYSDATE() returns the time when it executes.

SLEEP() inside statements affects the result from SYSTIME(), but not NOW().
SLEEP() between statements affects both.

This is true for regular statements, statements inside a stored procedure,
statements inside events and statements inside nested procedures.

Example:
DELIMITER $$;

CREATE PROCEDURE p4(IN p_sys DATETIME, IN p_now DATETIME)
BEGIN
  DO SLEEP(1);
  SELECT SYSDATE() - p_sys AS sys_psys, NOW() - p_now AS now_pnow, SLEEP(1) AS w1, 
         SYSDATE() - p_sys AS sys_psys1, NOW() - p_now AS now_pnow1;
END$$

CALL p4(SYSDATE(), NOW())$$

Result:
sys_psys        now_pnow        w1      sys_psys1       now_pnow1
1.000000        1.000000        0       2.000000        1.000000

However, inside functions, NOW() returns the same time as in the statement 
from which the function was called.

Example:
CREATE FUNCTION f5_sys() RETURNS DATETIME 
BEGIN
  DO SLEEP(1);
  RETURN SYSDATE();
END$$

CREATE FUNCTION f6_now() RETURNS DATETIME 
BEGIN
  DO SLEEP(1);
  RETURN NOW();
END$$

SELECT SYSDATE() - f5_sys() AS sys_fsys, SLEEP(1) AS w1, 
       SYSDATE() - f5_sys() AS sys_fsys1$$
SELECT NOW() - f6_now() AS now_fnow, SLEEP(1) AS w1, 
       NOW() - f6_now() AS now_fnow1$$

Result:
sys_fsys        w1      sys_fsys1
-1.000000       0       -1.000000
now_fnow        w1      now_fnow1
0.000000        0       0.000000

Hello!

Just to clarify.

In stored functions and triggers (and also in stored procedures which are called from stored functions and triggers) NOW() returns time then execution of the top-level statement which invokes function or trigger was started. Such behaviour is required to be able safely replicate such statements in SBR mode.

Stored procedures which are not called from triggers/stored functions are replicated in statement-by-statement fashion. So they don't need NOW() to be constant for the whole duration of routine. Therefore in such procedures NOW() returns time when particular statement in routine has started.

From kostja: This works as intended.

So update documentation to match current behavior.

The documentation is incorrect. The difference between SYSDATE() and NOW() is not for
stored routines and triggers, it is for stored *functions* and triggers. That means there
is no effect for stored *procedures*.

See also Bug#44996.

I guess this has been rectified in the newest release.

The following query works perfect

SELECT SYSDATE(),NOW(), SLEEP(10), NOW(),SYSDATE();

The result is
sysdate()            NOW()                SLEEP(10)  NOW()                sysdate()          
-------------------  -------------------  ---------  -------------------  -------------------
2011-06-02 10:35:12  2011-06-02 10:35:12          0  2011-06-02 10:35:12  2011-06-02 10:35:22