推荐用sysdatetime()手动打点:每步前声明@step_start datetime2=sysdatetime(),步后记@step_end,用datediff(ms,@step_start,@step_end)算毫秒差;需配try...catch异步写日志表,含proc_name、step_name、duration_ms等字段,并用@debugmode控制开关。

SQL Server 存储过程中用 SYSDATETIME() 打点记录步骤耗时
想看每一步(比如某个 UPDATE、某个 JOIN 查询)实际花了多久,不能只靠外部工具——那些只测到 EXEC 开始和结束,中间黑盒。必须在过程体内手动掐秒表。
关键不是“能不能”,而是“怎么打点才不污染逻辑、不拖慢主流程”。推荐用 SYSDATETIME()(不是 GETDATE()),精度 100 纳秒,开销极低:
- 每个关键步骤前加一行:
DECLARE @step1_start datetime2 = SYSDATETIME(); - 该步骤结束后立刻记结束时间:
DECLARE @step1_end datetime2 = SYSDATETIME(); - 算毫秒差:
DATEDIFF(ms, @step1_start, @step1_end),别用DATEDIFF(ss, ...),会丢精度 - 避免在循环体里反复调用
SYSDATETIME()——哪怕单次开销小,万次叠加也会歪了基准
MySQL 存储过程里用 NOW(3) + TIMESTAMPDIFF() 分段计时
MySQL 没有 SYSDATETIME() 那种高精度函数,NOW(3) 是实际可用的底线(毫秒级)。但注意:NOW() 默认无毫秒,NOW(3) 和 NOW(6) 行为不同,声明变量时必须显式指定精度。
分步计时写法要严格:
- 声明变量必须带精度:
DECLARE v_step1_start DATETIME(3) DEFAULT NOW(3); - 步骤执行完再取一次:
DECLARE v_step1_end DATETIME(3) DEFAULT NOW(3); - 用
TIMESTAMPDIFF(MICROSECOND, v_step1_start, v_step1_end) / 1000得毫秒值;直接减法会截断,不可靠 - 别用
UNIX_TIMESTAMP()——返回整数秒,所有亚秒信息全丢 - 如果步骤可能超 838 小时,别用
TIMEDIFF(),它上限是838:59:59,溢出就归零
把步骤耗时写进日志表,但必须加 TRY...CATCH 和写入开关
只 SELECT 出来看一眼,等于没留痕。真要分析趋势或定位某次慢调用,必须落库。但同步写日志极易拖垮主流程——尤其当 audit_log 表没索引、磁盘慢、或正被其他会话锁住时。
安全写法是:写入动作本身可失败,但绝不影响主逻辑。
- 日志表字段至少含:
proc_name(用OBJECT_NAME(@@PROCID)动态取)、step_name、start_time、duration_ms、status(S/F) - 用输入参数控制是否启用,如
@DebugMode BIT = 0,生产环境默认关 -
INSERT必须包在TRY...CATCH块里,且CATCH中再补一条失败记录:“日志写入失败” - 加
IF @@ERROR = 0判断后再插入,防止因磁盘满等底层错误让整个事务回滚 - 字段内容要截断:比如
params字段限制 512 字符,避免长文本拖慢INSERT
为什么 SET STATISTICS TIME ON 不适合步骤级监控
这个命令确实能快速看到“整个存储过程”的 CPU time 和 elapsed time,但它对“内部步骤”完全无感。它只在 EXEC 返回后输出一次汇总值,中间任何子查询、循环、等待都混在一起。
更麻烦的是生效范围和时机:
- 只能在会话级设置,且必须在
EXEC之前——你没法在过程里动态开关它 - 在存储过程定义体内写
SET STATISTICS TIME ON,SQL Server 直接报错,不支持 -
elapsed time包含网络传输、客户端渲染时间,不是纯服务端耗时,对比优化效果时会失真 - 它不输出时间戳,无法关联其他日志(比如业务操作时间、应用层埋点),查问题时得来回切窗口
真正需要步骤级数据时,手动打点不是“多此一举”,而是唯一可控、可复现、可下钻的方式。精度、位置、容错这三点漏掉任一,日志就从证据变成干扰项。











