MySQL存储函数执行日志起止时间一致问题求助

问题根源 #

MySQL 5.7的存储函数默认处于语句级一致性读上下文，NOW()这类时间函数会返回整个语句启动时的时间，而非实时时间。哪怕函数里有SLEEP(5)这类延迟操作，NOW()的值在整个函数执行周期内不会更新，导致插入的开始时间和更新的结束时间完全相同。

可行的解决办法 #

1. 用SYSDATE()替代NOW() #

SYSDATE()是实时获取系统当前时间，每次调用都会返回最新值，完美适配日志记录需求。修改后的函数示例：

DELIMITER //
CREATE FUNCTION log_execution() RETURNS INT
BEGIN
    INSERT INTO log_execution(start_time) VALUES(SYSDATE());
    SET @log_id = 1364894;
    
    SLEEP(5); -- 模拟耗时任务
    
    UPDATE log_execution SET end_time = SYSDATE() WHERE id = @log_id;
    RETURN 1;
END //
DELIMITER ;

2. 手动实时获取时间（备选方案） #

如果因某些限制不能使用SYSDATE()，可以通过查询的方式获取实时时间并赋值给变量，再用变量完成插入/更新操作：

DELIMITER //
CREATE FUNCTION log_execution() RETURNS INT
BEGIN
    DECLARE start_dt DATETIME;
    DECLARE end_dt DATETIME;
    
    SELECT SYSDATE() INTO start_dt FROM DUAL;
    INSERT INTO log_execution(start_time) VALUES(start_dt);
    SET @log_id = 1364894;
    
    SLEEP(5);
    
    SELECT SYSDATE() INTO end_dt FROM DUAL;
    UPDATE log_execution SET end_time = end_dt WHERE id = @log_id;
    RETURN 1;
END //
DELIMITER ;

3. 排查事务自动提交状态 #

如果函数是在事务中执行，确保autocommit参数开启（执行SET autocommit = 1;）。事务内的一致性读会导致时间函数值固定，关闭事务或者开启自动提交可以避免该问题。

验证方式 #

调用函数后执行以下查询，检查时间差是否符合预期：

SELECT id, start_time, end_time, TIMESTAMPDIFF(SECOND, start_time, end_time) AS execution_duration 
FROM log_execution;

内容的提问来源于stack exchange，提问作者Dezem