连接池被打满的那个下午
周三下午两点十分,监控群里第一次出现超时告警。不是全站,只有下单接口,错误率从 0.1% 慢慢爬到 7%,响应时间 P99 从 180ms 涨到 12 秒。奇怪的是,CPU 只有 30%,数据库负载也很平静。
我们花了大概四十分钟才定位到根因,中间走了一段很典型的弯路。这里把过程写下来,因为真正值得记的不是那个参数,而是"为什么一开始没人往那个方向想"。
第一反应:慢 SQL
超时 + 数据库,条件反射就是查慢查询。DBA 拉了最近半小时的慢日志,没有新面孔,执行计划也没变。应用侧看链路追踪,耗时几乎全部堆在"获取连接"这一步,真正的 SQL 执行只要几毫秒。
这条线索其实已经很明确了:getConnection() 卡住,说明池子空了。但当时我们没往这边想,因为池子配了 50 个连接,而平时活跃连接数常年在 5 到 8 之间。一个用了两年没动过的参数,很难第一时间怀疑到它头上。
后来翻应用日志才看到,从两点零五分开始,HikariPool-1 - Connection is not available, request timed out after 30000ms 已经刷了几千行。告警配的是 ERROR 级别的异常计数,而这条被归到了 WARN,于是它安静地刷了五分钟才有人注意到。
第一个教训:告警阈值按"错误率"配,会漏掉"请求还没开始执行就卡住"的那一类故障。连接池耗尽时,业务异常反而变少了——请求都排队去了,连抛异常的机会都没有。
连接被谁拿走了
池子空了只有两种可能:借得太多,或者还得太慢。当时的 QPS 比平时还低一些,所以是后者。
用 jstack 抓了三次线程栈,看到大量线程停在同一个位置:一个 RestTemplate 的调用上。这段代码在事务方法里,逻辑是这样的:
@Transactional
public Order createOrder(CreateOrderReq req) {
ConnectionHolder ch = getCurrentConnection(); // 事务开启,连接已借出
Order order = orderMapper.insert(req); // 几毫秒
couponClient.verify(req.getCouponId()); // 同步 HTTP,超时设的 10s
orderMapper.updateStatus(order.getId(), PAID);
return order;
}
平时券服务响应 20ms,连接借出 30ms 就还回去了。那天下午券服务在做发布,接口偶发 8 秒才返回。于是每个请求都把数据库连接攥在手上 8 秒,池子里 50 个坑位在几秒内被占满,后面的请求全部排队等 30 秒超时。
慢的不是数据库,是一个跟数据库毫无关系的下游。
第二个教训:连接是全局共享资源,持有时间不该由链路上最慢的那个远程调用决定。事务范围内做同步 RPC,等于把外部系统的抖动直接换算成自家数据库的连接池压力。
为什么监控看着"一切正常"
这里有个挺有意思的错觉。数据库侧的活跃连接数确实涨到了 50,但 50 个连接里绝大多数什么都没干,只是被线程攥着。所以数据库 CPU、IO、慢查询全部平稳,看起来健康得不得了。
真正该看的指标是"连接持有时间分布"和"等待连接的线程数",这两个我们当时都没采。后来补上了:
// 借出时打点,归还时记录持有毫秒数
long t0 = System.nanoTime();
try (Connection c = dataSource.getConnection()) {
doWork(c);
} finally {
holdTimer.record(System.nanoTime() - t0, TimeUnit.NANOSECONDS);
}
有了 P99 持有时间之后,这类问题基本能在第一次抖动时就暴露出来。另外把 connectionTimeout 从 30 秒调到 3 秒——与其让请求排三十秒队然后一起超时,不如快速失败,把压力挡在前面。
修复不止是"把超时改小"
当天做的回滚很简单:券服务发布回滚,池子立刻恢复。但真正改的东西在后面两周:
把 RPC 挪出事务。 先校验券、再开事务写库。如果确实需要"校验结果和写库一致",用本地消息表或者最终一致,而不是把远程调用包在 @Transactional 里。这一条改动之后,连接持有时间 P99 从 40ms 降到 12ms。
给每个下游单独设超时和隔离。 之前所有 RestTemplate 共用一个 10 秒读超时,配置写在公共类里,没人记得它存在。改成按依赖方配置,并且给券服务单独一个 8 线程的舱壁,慢下来时只影响这一路。
池大小不再拍脑袋。 原来的 50 是两年前压测完顺手写的。按 连接数 ≈ 核心数 × 2 + 有效磁盘数 估算,4 核 SSD 的机器给 10 就够;后来压测验证,10 个连接反而比 50 个吞吐更高——连接少,数据库上下文切换也少。大池子在这里只是把故障延后了几秒,同时让排队更长。
补一条针对 WARN 的告警。 Connection is not available 连续出现就报警,不等错误率。
复盘时最该记住的一句
事后有人问:既然券服务发布是诱因,为什么不先怪发布?
因为发布是每周都有的事,系统本来就该扛住一次下游变慢。真正的问题是我们让一个外部调用的耗时,通过事务一路传导到了数据库连接这种最底层、最稀缺的资源上。故障从来不是某个组件坏了,而是两个组件之间那条没被设计过的耦合被激活了。
排查时还有个小的心理陷阱值得提一句:我们盯着"今天改了什么",而那天应用侧什么都没发。于是大家下意识排除了"我们自己的问题",把时间花在等 DBA 出报告上。其实配置也是代码,两年前写的那行 maximumPoolSize=50 和今天提交的代码一样,都会在某个特定条件下失效。
如果再遇到一次"CPU 不高、数据库很闲、接口却大面积超时",我会第一件事去看连接池的等待队列,而不是慢日志。这四十分钟算是买了个顺序。
- 点赞
- 收藏
- 关注作者
评论(0)