Java

数据库 CPU 正常但 active sessions 很高那次,我是怎么把会话堆积拆回等待链的?

一次库存中心事故里,数据库 CPU 只有三成多,active sessions 却一路冲高。真正有用的不是盯着 CPU 争论数据库忙不忙,而是把 active sessions 拆成锁等待、事务年龄、连接归还和回退后的回落顺序。

  • MySQL
  • Active Sessions
  • 锁等待
  • 长事务
  • 性能排查
12 分钟阅读

19:27,库存中心的几个接口一起开始发抖。

最先吵起来的不是慢 SQL,而是一张很让人别扭的图:

  • 数据库 CPU 只有 34%
  • 可 active sessions 从 23 跳到了 79
  • 应用侧获取连接时间、接口 RT 也一起变差

这种场景特别容易陷进一句空争论:数据库 CPU 不高,那 active sessions 高是不是也没那么重要?

我现在基本不会这么看。因为 active sessions 真正难的地方,从来不是“它高不高”,而是 它里面堆着的到底是执行,还是等待。

那晚后来能收住,就是因为我没停在“数据库忙不忙”这层,而是把这批会话重新拆回了一条等待链。

我先判断:这些会话是在跑,还是在等?

19:25 到 19:31 这 6 分钟里,数据库和应用侧的关键指标是这样:

指标19:2519:30
MySQL CPU27%34%
平均 DB RT26ms41ms
active sessions2379
lock wait sessions024
oldest transaction age180ms7.2s
Hikari 获取连接 p9510ms590ms

这张表本身已经很说明问题。

如果 active sessions 主要是执行型堆积,通常 CPU、I/O 或稳定慢 SQL 会更扎眼;可这次最夸张的是 lock wait sessionsoldest transaction age。所以我很快就把方向收到了:会话不是主要在跑,而是在等。

traceId 也能看到,请求慢不是慢在执行量,而是慢在排队等前一个事务出库

我抓了一条典型慢请求:traceId=98be6d3f10ef49c2

时间点事件
19:29:11.004请求进入 stock-center
19:29:11.037拿到连接
19:29:11.061执行 update stock_reserve ...
19:29:12.484SQL 返回
19:29:12.612提交事务
19:29:12.659返回响应

单看这条请求,好像就是更新语句慢了 1.4 秒。但再往数据库里看,同一时间点它其实是在等前面的事务释放锁,而不是自己真的在疯狂执行 1.4 秒。

也就是说,这次 active sessions 变高,不是“很多 SQL 都在很努力地跑”,而是“很多会话出不来”。

把会话堆积钉死的,是这批热点库存键和长事务

反复出现的问题都在这张表上:

update stock_reserve
set reserved_qty = reserved_qty + ?,
    updated_at = now()
where sku_id = ? and warehouse_id = ?;

19:24 刚好上线了一批“活动库存预热”任务,也在并发改同一组热点 sku_id + warehouse_id。而且那批任务的写法是:

  1. 先查活动规则
  2. 开事务
  3. 同步调价格中心拿促销快照
  4. 再更新 stock_reserve
  5. 最后写预热审计日志

价格中心 RT 抬到 800ms 左右以后,这批事务全都被拖长。于是等待链就长成了这样:

  • 预热任务长事务先占住热点库存行
  • 在线预占、释放、校准请求都开始等锁
  • active sessions 被一层层挂高
  • 连接归还变慢
  • 应用侧获取连接 p95 跟着抬头

所以那张“CPU 不高但 active sessions 很高”的图,背后并不神秘,它只是把一条等待链浓缩成了一个数字。

为什么我没有先按“慢 SQL 执行型问题”去追

因为那晚有三件事都不支持这个方向。

CPU 不配合

34% 的 CPU 当然不是没负载,但也远远没到能解释 79 个 active sessions 都在拼命执行的程度。

慢日志不够集中

慢日志有增长,但没有一批稳定跑到 2、3 秒的 SQL。更多是大量 1 秒左右的更新,长相更像“被等出来”的慢,而不是“自己算出来”的慢。

锁等待和事务年龄太抢眼

lock wait sessions 从 0 到 24,oldest transaction age 到 7.2s,这已经足够说明问题主要在等待链,而不是纯执行层。

回退动作之后,回落顺序也证明 active sessions 只是结果层

19:32,我们先暂停“活动库存预热”任务;19:34,再把价格中心快照查询挪出事务,只保留必要的库存更新。

后面几分钟里,指标的回落顺序很有说服力:

时间先回落的指标后回落的指标
19:33oldest transaction age、lock wait sessions-
19:34active sessions、Hikari 获取连接 p95-
19:35库存预占接口 p95订单确认 RT
19:36用户超时和重试量基本恢复

这条顺序说明,active sessions 本身不是起点。最先掉下来的,是前面的事务年龄和锁等待;然后才是 active sessions 这层结果。

所以后来我再看 active sessions,会先拆这几层

  1. 它更像执行型堆积,还是等待型堆积?
  2. lock waittransaction age 有没有一起抬头?
  3. active sessions 高之前,是不是先有长事务或热点写冲突?
  4. 动作之后,最先回落的是等待源,还是 active sessions 自己?

把这几层拆开,active sessions 就不会再只是一个吓人的数字。

那晚真正的结论其实很简单:数据库 CPU 正常,不代表数据库方向没事;这次 active sessions 高,是因为一批热点库存事务和事务内慢下游把会话挂在等待链上了。

你只盯 CPU,会觉得它们不矛盾;你把等待链摊开以后,反而会觉得它们本来就该同时出现。