结算确认那次真正拖慢系统的,不是慢 SQL,而是开着事务等票据服务回包
这篇只讲一次结算事故:`POST /settlement/confirm` 先坏掉,库里随后冒出长事务、锁等待和连接池紧张。问题不在于先讲“长事务怎么拆”,而在于先看见有人把远程调用包进了事务。
18:18,结算确认接口 POST /settlement/confirm 的 p95 一下子从 220ms 抬到 3.1s。
这类事故很容易把人带进熟悉套路里:有人去刷慢 SQL 面板,有人开始看 EXPLAIN,还有人会先把“长事务”当成一个偏数据库侧的大类标签,然后准备展开一套分段教学。
但那晚真正有用的,不是先讲长事务应该怎么分析,而是先看见一个更刺眼的现场事实:
有批请求已经开了事务,却在事务里等票据服务回包。
这个事实一旦成立,后面的锁等待、连接池变紧、active sessions 抬高,几乎都会顺着长出来。
先把人压住的,不是慢 SQL 图,而是那几笔一直活着的事务
18:19 左右,DBA 在库里扫到几笔异常活跃事务,截了这样一段:
---TRANSACTION 421441208, ACTIVE 6 sec
mysql tables in use 2, locked 2
5 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id 902145, query id 5488721 app_rw update
update settlement_record
set status = 'CONFIRMED',
invoice_snapshot_id = 'inv_938217',
updated_at = now()
where settlement_id = 'st_673241';
另一边应用日志也不太对劲:
18:19:08.962 INFO invoice-service call slow, traceId=5d70e13fa2ab4c71, costMs=1781
18:19:09.517 WARN tx commit slow, traceId=5d70e13fa2ab4c71, txMs=2456
18:19:09.518 INFO hikari pool stats total=40 active=40 idle=0 waiting=9
这几行信息放在一起,比“慢 SQL 多不多”更值得先看。
因为它们说明:库里确实已经有长事务,而且这些长事务不是纯 SQL 跑得飞起,而是事务开着的时候,应用线程还在等一次外部 RPC。
这条慢请求最扎眼的地方,是开事务之后先去等票据服务
我后来把最典型的一条请求捞出来,traceId=5d70e13fa2ab4c71,按时间摊开以后是这样的:
| 时间点 | 发生的事 |
|---|---|
| 18:19:07.024 | 请求进入 settlement-service |
| 18:19:07.061 | 开事务 |
| 18:19:07.093 | 查结算记录 |
| 18:19:07.166 | 查询返回 |
| 18:19:07.181 | 同步调用 invoice-service 生成票据快照 |
| 18:19:08.962 | RPC 返回,光这一步等了 1.7s |
| 18:19:09.004 | 更新 settlement_record |
| 18:19:09.517 | 提交事务 |
| 18:19:09.560 | 响应返回 |
这条时间线其实已经把结论写得很明白了。
问题不是“数据库里有一条 SQL 为什么这么慢”,而是:为什么事务在 18:19:07.181 就已经开着了,却要等到 18:19:08.962 才继续做后面的更新和提交。
这 1.7 秒里,数据库连接没有释放,事务上下文没有结束,涉及的记录和锁也都悬在半空。只要并发一上来,后面的请求就很容易开始排队。
真正把系统拖住的,是结算事务边界被票据补全逻辑撑坏了
18:15 刚上线过一个“票据补全”改动。
原本的结算确认流程很短:查一次、写一次、提交。上线后变成了:
- 开事务
- 查结算记录
- 同步请求
invoice-service拉附加税务信息 - 把票据快照写入
settlement_record - 提交事务
当晚偏偏又碰上 invoice-service 因为税务字典刷新,RT 从 20ms 涨到了 1.6s 左右。于是这段改动就把原本库外的等待,整个塞进了事务边界里。
所以那次事故里,“长事务”不是一个抽象标签,它指向的是一件非常具体的坏事:
有人拿着数据库连接和事务上下文,在库里等库外服务。
锁等待和连接池紧张,都是后面自然长出来的结果
一旦前面的事务被这样拖长,后面的连锁反应几乎是必然的。
那晚反复出问题的是这条更新:
update settlement_record
set status = ?, invoice_snapshot_id = ?, updated_at = now()
where settlement_id = ?;
它本身并没有慢到离谱。可因为前一批请求都在开着事务等票据服务,settlement_record 上的相关更新和补偿请求就开始往后排。
于是现场才一步步变成:
- 先是结算确认接口 RT 抬头
- 再是库里出现几笔 5 到 6 秒的活动事务
- 然后锁等待开始出现
- Hikari
waiting从 0 涨到 9 - 最后用户开始看到结算确认超时和重试
如果你一开始就把注意力放在“哪条 SQL 最慢”,这些结果层症状会看起来很散;但只要先盯住“谁在事务里等外部返回”,整条事故就会一下子顺起来。
所以那晚我没有先刷 EXPLAIN
不是说 EXPLAIN 没用,而是那一刻它不是第一刀。
因为当时现场已经给了更直接的证据:
- 事务年龄先抬头
- 票据服务调用和事务时长几乎重合
- 更新 SQL 的执行耗时,并没有大到足以单独解释 3 秒接口
- 连接池活跃数贴着上限,说明连接被长期占住
这些信号更像是在说:先别问 SQL 优不优秀,先把事务边界里不该出现的等待拿掉。
真正扭转现场的动作,也不是调 SQL,而是把 RPC 从事务里挪出去
18:23,我们先灰度关闭票据补全逻辑。
18:25,再把这段补全改成事务外查询,主事务里只保留必要的结算状态更新;票据快照改成后置补写。
后面几分钟的变化非常有说服力:
- 18:24 左右,最先掉下来的是事务时长和最老事务年龄
- 接着锁等待和 Hikari
waiting开始回落 - 然后
POST /settlement/confirm的 p95 从 3 秒级掉回 400ms 左右 - 最后用户侧的超时和补偿重试量才陆续恢复
这个顺序很重要。
因为它说明我们切中的,不是某条 SQL 的局部执行问题,而是整条事务等待链的起点。
这篇我想留下的,不是“长事务四段拆解法”
我更想把那晚记成一句简单得多的话:
长事务最危险的时候,往往不是你在数据库里看到它已经很长,而是它刚开始把库外等待一起包进事务的时候。
一旦这么做:
- 锁会被多拿一会儿
- 连接会被多占一会儿
- 后面的更新和重试就会开始排队
- 你最后在监控上看到的,才会是锁等待、连接池紧张和接口整体变慢
所以这篇不想再把读者带去上“长事务先拆四段”的方法课。
那次结算事故真正值得记住的,是更具体的一幕:settlement-service 明明已经开了事务,却在里面等 invoice-service 的 1.7 秒回包。后面的所有坏事,几乎都是从那 1.7 秒里长出来的。
也正因为如此,那晚最正确的第一步不是先查慢 SQL,而是先把那段不该放进事务里的等待拿出去。