应使用CURRENT_TIMESTAMP(3)记录毫秒级调用时间,配合exec_id唯一标识;执行结果需分ROW_COUNT()、OUT参数、SELECT结果集三类处理;日志表选InnoDB并精简索引;耗时通过UNIX_TIMESTAMP手动计算并写入日志。

记录存储过程调用时间:用 CURRENT_TIMESTAMP(3) 捕获毫秒级起点
存储过程本身不自动记录调用时间,必须在入口显式插入时间戳。直接用 CURRENT_TIMESTAMP 只能到秒级,高并发或循环密集场景下容易丢失时序细节。推荐用 CURRENT_TIMESTAMP(3)(毫秒精度),配合唯一标识字段串联整次执行。
- 建表时定义时间字段为
created_at TIMESTAMP(3) DEFAULT CURRENT_TIMESTAMP(3) - 调用前生成一次
exec_id(如UUID()),所有日志行都带上它 - 避免在循环体里反复调用
NOW()—— 它可能返回相同值,尤其在毫秒级循环中
记录执行结果:区分 ROW_COUNT()、OUT 参数与查询结果集
“执行结果”不是单一概念,得按类型分别处理:影响行数、输出参数、SELECT 返回集,三者记录方式完全不同。
- 写操作(INSERT/UPDATE/REPLACE)后立刻查
ROW_COUNT(),它返回实际变更行数,不是返回值本身 -
OUT或INOUT参数需在过程末尾INSERT INTO log_table显式写入,例如:CONCAT('total=', total, '; status=', status) - SELECT 结果集无法直接写入日志表,只能靠客户端捕获;若必须存档,得用临时表 +
INSERT ... SELECT中转
避免日志表拖慢主逻辑:异步写入不可行,但可最小化开销
MySQL 存储过程中没有真正的异步机制,所有 INSERT INTO debug_log 都是同步阻塞的。但可以通过几个小动作降低影响:
- 日志表引擎选
MEMORY(仅限单次调试)或InnoDB(生产环境),避免用MyISAM(表锁严重) - 关闭日志表的索引(除主键外),写入后再重建,否则每条日志都触发索引更新
- 不要在高频循环内每轮都记日志,改用条件记录,比如只记第 1、第 10、最后 1 次:
IF counter IN (1, 10) OR counter = max_loop THEN ...
查看执行耗时:别依赖 SHOW PROFILES,它不稳定且默认关闭
SHOW PROFILES 在多数生产环境被禁用(profiling=OFF),且只保留最近 100 条,无法关联到具体 exec_id。可靠做法是手动测时差。
- 入口处设变量:
SET @start_time = UNIX_TIMESTAMP(UTC_TIMESTAMP(3)); - 出口处计算:
SET @duration_ms = (UNIX_TIMESTAMP(UTC_TIMESTAMP(3)) - @start_time) * 1000; - 把
@duration_ms一并写入日志表的var_values字段,例如:CONCAT('duration=', @duration_ms, 'ms')
真正难的是把日志、耗时、参数、错误状态这四样串成一条完整链路 —— 少一个字段,排查时就得来回翻表、猜上下文。


















