一个批量任务在凌晨把订单表锁了四十分钟,第二天早上才被发现。技术原因其实不复杂:事务开得太大、没有分批、也没有设置超时。真正难的是后面那两周——为什么没有人收到告警、为什么回滚预案是过期的、为什么这个脚本当初没走评审。这篇写得比较长,因为当时确实被吓到了。

一、第二天早上是怎么发现的

2024 年 11 月 12 日早上八点四十,业务群里有人说订单列表打不开。我第一反应是前端发版了,问了一圈说没有。等我自己打开页面,看到的是接口一直转圈,不是报错——报错反而好查,转圈说明请求在等。

查的过程其实很快,因为现象很干脆:所有涉及订单表的读写全部卡住,其他表正常。登上数据库跑 sp_who2,一个 UPDATE 语句的状态是 SUSPENDED 不对,是正在执行,后面挂了一百多个 LCK_M_X 等待。看 sys.dm_exec_requests 里的 start_time,是凌晨 2:00 开始的,跑了 40 分钟,2:40 结束。也就是说事故在四十分钟后自己恢复了,我们只是没看见。

这个"自己恢复了"让我当时很不是滋味。故障持续时间不算长,影响面也有限——凌晨两点到两点四十,只有几家夜班门店在录单,一共 60 多笔单子延迟,没有数据丢失。但如果我们没有监控、没有人告警,那这次没出大事纯粹是运气。

二、技术原因

出问题的任务叫 OrderStatusArchive,Quartz.NET 调度,每天凌晨 2:00 跑一次,把三天前还停留在"待确认"状态的订单批量置为"已关闭"。代码是 2021 年一位已经离职的同事写的,用 Dapper,核心就这几行:

using var conn = new SqlConnection(cs);
conn.Open();
using var tx = conn.BeginTransaction();   // 全程一个大事务

var affected = conn.Execute(@"
    UPDATE dbo.Orders
       SET Status = 9, UpdatedAt = GETDATE()
     WHERE CreatedAt < @deadline AND Status = 3",
    new { deadline }, tx, commandTimeout: 0);   // 0 = 不超时

tx.Commit();

四个问题叠在一起,缺一个都不会出这么大的事:

  • 没有分批。那天要更新的行数是 41 万行,一次 UPDATE 全部干完。平时这个任务只跑几万行,11 月 11 日之后有一批历史单子被重新打开,行数直接涨了一个数量级。
  • 显式事务包住整条语句,锁要持有到提交。在 READ COMMITTED 下,语句级的共享锁语句结束就放,但显式事务里的写锁(X 锁)是一直攥到 COMMIT 的。所以这 41 万行的锁,从 2:00 一直攥到 2:40。
  • 锁升级。SQL Server 在单个语句对同一对象持有的行锁或页锁超过大约 5 000 个时,会尝试把锁升级成表锁,升级成功之后整张 dbo.Orders 被独占,所有读写全堵。我们在 11 月 11 日刚对这张表做过一次数据整理,统计信息还没更新,优化器估的行数偏小,实际扫描范围远超预期,锁升级就这么触发了。事后看 sys.dm_db_index_operational_stats 里的 index_lock_promotion_count 确实涨了 1。
  • 命令超时设成 0。这是最要命的一条。commandTimeout: 0 表示不限时,所以这个任务不会在 30 秒后被掐断,它会一直跑、一直攥着锁。这个 0 是当初为了解决"任务偶尔超时失败"加上去的,属于典型的把告警当成问题解决。

还有一个放大因素:dbo.Orders 上有一个 AFTER UPDATE 触发器往 OrderStatusLog 写变更记录,是逐行触发的,41 万行就是 41 万次插入,而且这些插入都在同一个事务里。这一块占了 40 分钟里的大头,我后来单独测过,去掉触发器之后同一批数据只要 50 多秒。

(补充一句自己踩的坑:我一开始判断是索引问题,因为 WHERE CreatedAt < @deadline AND Status = 3 走的是 IX_Orders_CreatedAt 的索引扫描加回表。后来加了 (Status, CreatedAt) 的复合索引,耗时确实降了,但降到 6 秒而不是 40 分钟——真正的时间大头是触发器,索引只是次要因素。我第一版结论写错了,在复盘会上被老陈当场指出来。)

三、为什么第二天才发现

这是我最想记的一部分,因为技术那块花两小时就改完了,监控这块我们改了三周。

当时我们的监控只有服务器层:CPU、内存、磁盘、SQL Server 服务是否存活,用 Zabbix,阈值都很宽松,CPU 超过 90% 持续五分钟才告警。而这次事故期间数据库 CPU 一点都不高——大家都在等锁,不是在算。所以监控全程绿。

缺的东西列出来很扎眼:没有长事务告警,没有阻塞告警,没有慢查询采集,没有任务执行时长打点,也没有任何业务指标(比如"最近十分钟订单写入量")。这个任务本身也没日志,代码里只有一行 Log.Info("done"),还是执行完才打,中途卡住什么都不会留下。sqlserver 上我们甚至没装 sp_WhoIsActive,全靠出事之后人肉登上去看。

换句话说,我们唯一的"告警"是第二天早上业务群里的一句"订单列表打不开"。从故障发生到被人知道,隔了六个小时。

四、为什么批量任务放在凌晨

这个问题复盘会上没人提,是我自己事后补上的。答案很朴素:2019 年系统上线的时候定的,理由是白天数据库压力大,批量操作放凌晨。这个理由当时成立,但 2024 年已经不成立了——2023 年我们上了夜班门店的录单,凌晨两点到现在都有真实写入,"凌晨没人用"这个假设至少过期一年了,而任务的执行时间从来没有人复核过。

更值得记的是:这个假设从来没有被写下来过。它存在于"当时那个人觉得",人走了,假设留下来了,而且没人知道那是个假设。

五、那两周,以及我当时的心态

说实话,事故当天我的第一反应不是排查,是翻 git 记录。我想确认最后改这个脚本的人是不是我。查出来是 2023 年 8 月我改的,改的内容是把 Execute 外面包了一层事务——原来是没有事务的,我加上的,理由是"保证要么全改要么不改"。看到这条记录我心里一沉,然后是一种很别扭的放松:至少确认了是我,不用去猜。

我得承认这个过程不太体面。事故面前第一反应是自保,而且"加事务"这件事在当时看完全合理,我只是没有想过事务开多大、锁攥多久。

复盘会上我说的是"主要责任在我,这个脚本最后是我改的"。会上有同事提到排期的问题——那阵子我们三个人手上压了六个需求,没人有空做代码评审,这个脚本从 2021 年就一直在跑,从没被评审过。我同意这部分是团队的问题,但我不想把它当成我的免责理由:加事务的决定是我做的,我把一个本来只锁几秒的操作变成了锁 40 分钟,这个因果很清楚。

业务侧对我们的处理我挺感激的:没有追责,只要求给出改进项和完成时间。这也是我愿意把细节写出来的原因。

六、事后改了什么

下面是实际做完的六条,都注了完成时间,其中三条我一开始没想到,是别人提的:

  • 代码(11 月 13 日)。按主键范围分批,每批 2 000 行,每批一个事务;commandTimeout 改成 120 秒;触发器用 OUTPUT 子句改成批量写入 OrderStatusLog。改完实测 41 万行耗时 8 秒,最长单批持锁 0.4 秒。
  • 索引(11 月 14 日)。IX_Orders_Status_CreatedAt,并给那次数据整理之后忘记更新的表做了一次 UPDATE STATISTICS。这条对事故不是决定性的,但顺手做了。
  • 长事务与阻塞告警(11 月 20 日)。一个 SQL Server Agent 作业,每分钟查一次 sys.dm_tran_database_transactionssys.dm_os_waiting_tasks,事务超过 60 秒或阻塞超过 10 秒就发企业微信机器人。阈值是拍的,跑了两个月之后把阻塞阈值调到 5 秒。
  • 任务执行时长打点(11 月 22 日)。所有 Quartz 任务统一在 IJobInterceptor 里记开始时间、结束时间、影响行数,超过预期时长 3 倍就告警。没有这个,下次任务变慢我们一样看不见。
  • 批量脚本评审清单(12 月 3 日)。凡是一次性影响超过 1 万行的脚本,必须在预发环境用同量级数据跑一遍,并且提交时附带三样东西:预计影响行数、分批策略、回滚步骤。这条是老陈提的,我原来是想定"所有脚本都要评审",他反对,理由是要求太高最后就没人执行了。他是对的。
  • 回滚预案重新验证(12 月 10 日)。我们发现原来的回滚文档里写的是"truncate 掉 OrderStatusLog 重建",但那张表 2023 年之后加了外键,脚本早就跑不通了。文档一直挂在 wiki 上,没人验证过。现在改成每季度演练一次,演练记录也归档。

还有一条我们讨论过但没做:把 Orders 表的数据按时间分区。讨论结果是现在的数据量(800 万行)还远远不到需要分区的程度,做了反而增加维护成本。这条我到现在也不确定对不对——数据量再翻一倍的时候,可能又要重新讨论一遍。

七、现在回头看

这次事故里我学到的东西,排名第一的不是锁升级,是"任务跑完了我以为就没事了"。我以前对定时任务的态度是:能跑就行,跑完没报错就行。现在我写任何一个周期性任务都会先问三个问题:它最长会占用资源多久、它卡住的时候谁会知道、它失败了一半会留下什么。

第二个是监控的层次。服务器活着不等于服务正常,服务正常不等于业务正常。我们原来的监控全在最底层,等它报警的时候,业务早就炸完了。现在加的这几条告警也还很粗糙,但至少覆盖了"数据库在等"这一层。

最后一条我没什么把握:我觉得事故复盘里最有价值的部分,是最难写出来、也最容易被删掉的那部分——人的判断和当时的心理。技术原因写清楚只要两小时,而"我为什么加那个事务""我为什么第一反应是翻 git"这些才是下次能拦住我的东西。所以这篇我故意写得长一点,也故意没有删掉那些不太好看的地方。