生产故障排查

连接池配了 40,为什么线上还是 10 个

配置文件里那一行是对的,数字也是对的,只有名字错了。而错了的名字不会报错。

01

配置写了 40,运行时是 10 —— 两个名字不是同一个

配置项的字段名和框架实际认的字段名对不上。对不上的那组 key 没有警告、没有异常、没有日志,直接被丢掉,连接池用了组件默认值 10。

02

改对名字也不等于问题消失

扩到 40 后,整点仍然出现「40 个连接全部占用、50 多个线程排队」的采样。池上限决定最多能同时开几个,不决定突发打进来时已经有几个。

03

所以我没有写「优化完成」

灰度只证明了配置生效。排队有没有下降,要看相同负载、相同口径下的对比;再往下还有连接轮换和长时间持有两层,都还没解决。

01告警里的三个数字

告警长这样,一个服务,三行,格式完全一样:

基础设施服务 / 实例 A / mysql
同池出现排队且获取连接最久 ≥1 秒
每 30 秒检查,有排队比例 5.7851%,峰值 189 个,达到 1% 且峰值 10 个的条件

基础设施服务 / 实例 B / mysql
每 30 秒检查,有排队比例 4.9587%,峰值 134 个

基础设施服务 / 实例 C / mysql
每 30 秒检查,有排队比例 7.4380%,峰值 190 个

换算一下:按 30 秒采样,一天 2880 个点,7.4% 意味着有 200 多个采样点上,线程正在排队拿连接——不是偶发,是长期状态。

三个实例同时中招,同一个池名,同一条规则。第一个反应通常是「这个服务支撑不住,扩机器或者扩池」。但在动任何参数之前,先采集了一天的基线,把「平时到底长什么样」钉住:

24 小时生产基线(30 秒采样,每实例 2881 个点)
实例 有排队的采样占比 等待线程峰值 获取连接最长
实例 A3.8528%1892.170 秒
实例 B4.5470%2481.340 秒
实例 C1.9785%1261.096 秒
实例 D2.8462%1480.825 秒
四个实例 24 小时内有排队采样的比例 1% 告警线 实例 A 3.85% · 峰值 189 实例 B 4.55% · 248 实例 C 1.98% · 126 实例 D 2.85% · 148
四个实例没有一个是干净的。取值越靠右越差;虚线是 1% 的告警线,四根柱子全部越过了它。

更值得注意的是一行不起眼的指标:每个实例每天新建约 1.46 万个连接。一天 86400 秒,平均每 6 秒建一个连接。连接池存在的意义是复用,一天建 1.4 万个,说明池根本没在复用——它在不停地换。

这两件事叠在一起,才把方向指到了配置本身:一个「以为配了 40」的池,和一个「每分钟洗一次牌」的池,是两种不同的病。那么第一个问题很朴素:这个池现在到底有几个连接?

02问运行中的池,别问配置文件

拿到配置文件的时候,它写得很清楚:

spring:
  datasource:
    dynamic:
      hikari:
        minimum-idle: 5
        maximum-pool-size: 40     # 就是这一行
        max-lifetime: 60000
        keepalive-time: 60000

40。看上去没有任何问题。而且这个值如果生效,就不该出现 190 个线程抢连接——40 个连接被打满的代价,和 10 个连接被打满,不是一回事。

所以我做了一件很基础、但经常被跳过的事:不看配置文件,直接读进程里那个对象。 连接池自己会汇报运行值,HikariCP 通过 Actuator 暴露了这组指标:

# 在 pod 里执行
curl -s http://localhost:8080/actuator/prometheus \
  | grep -E '^hikaricp_connections_(max|min|active|idle|pending)\{'

返回的第一眼就结束了争论:

hikaricp_connections_max{...,pool="mysql",}     10.0
hikaricp_connections_min{...,pool="mysql",}     10.0
hikaricp_connections_active{...,pool="mysql",}  10.0
hikaricp_connections_idle{...,pool="mysql",}     0.0
hikaricp_connections_pending{...,pool="mysql",}  190.0

配置写的是 40 / 5,运行时是 10 / 10。而且 min 也变成了 10——两个参数一起失效,一起回到了组件的默认值。这不是「配置没推上去」的表现:配置没推上去不会这么整齐,它更像是有人根本没读这份配置。

这一步为什么必须做

MySQL 服务器侧的连接数不能代替它。当时能查到的数据库是只读副本,连接数 130/4096,看起来极其宽裕——但那是副本,不是应用连的主库,也不是连接池的视角。能回答「池配了多大」的只有池自己。

03名字写错了,没人报错

回看那行配置。maximum-pool-size,这是 HikariCP 自己的属性名,也是 Spring Boot 官方文档里写的那个名字。但它被放在 spring.datasource.dynamic.hikari 下面——这个层级不属于原生 Spring Boot 数据源,而属于多数据源组件,由它自己的配置类去接收。

而这个组件的 3.5.1 版本,字段名是另一个:

配置里写的 这个组件认的 结果
maximum-pool-sizemax-pool-size未绑定 → 默认 10
minimum-idlemin-idle未绑定 → 默认 10
max-lifetimemax-lifetime同名,生效了

注意第三行。同为这个层级下的配置,max-lifetime: 60000 因为名字恰好一致,真的生效了。这就是整件事最阴的地方:一份配置里一半生效一半不生效,而生效的那一半还在制造另一类问题(后面第 06 节)。

为什么没人报错

Spring 的配置绑定走的是宽松绑定:max-pool-size、maxPoolSize、MAX_POOL_SIZE 都指向同一个字段。听起来很宽容,但它宽容的方向只有一个——认识的名字尽量都认,不认识的名字安静地放下。绑定器不会因为多了一个它不认识的 key 就失败,除非专门开启「未知属性即报错」。

所以整个链路是这样断的,断点上没有任何告警:

配置值在绑定环节被丢弃,池回落到默认值 配置里写的 maximum-pool-size 40 ✕ 不匹配 绑定器的字段 maxPoolSize 一直没有人给它赋值 空着 池的实际参数 max = 10 组件默认值 整条链路上没有异常、没有警告、没有日志 —— 只有结果和期望不一样。
值不是被改掉了,是在第二次转手时没人接手。最终落在池里的,是组件自己的默认值。

这类问题最难的地方不在修复,在发现。它没有异常栈,没有错误日志,服务健康检查全绿,接口成功率正常——唯一的症状是「慢」和「排队」,而这两样最容易被归因成流量大、机器少。

别急着推广结论

看到这份配置是共享的,第一反应会是「所有用这份配置的服务都中招了」。这个推论当时就写错了,后来把范围收了回来:已确认的只有这一个服务。其他服务可能走原生 spring.datasource.hikari(那里 minimum-idle 才是对的),可能组件版本不同,也可能被自己的配置覆盖。要逐个核对它们各自用什么方式创建池。

04从 10/10 到 40/5

修复本身只有两行。测试环境先改:

spring:
  datasource:
    dynamic:
      hikari:
-       minimum-idle: 5
-       maximum-pool-size: 40
+       min-idle: 5
+       max-pool-size: 40

但改完不能只看配置中心里显示的是什么。「配置已发布」和「池已生效」是两件事——配置更新不保证已经在运行的池重建,有些场景要重启 Pod 才看得到。所以验证方式还是第 02 节那条命令:

hikaricp_connections_max{...,pool="mysql",}      40.0
hikaricp_connections_min{...,pool="mysql",}       5.0
hikaricp_connections_idle{...,pool="mysql",}      5.0
hikaricp_connections_active{...,pool="mysql",}    0.0
hikaricp_connections_pending{...,pool="mysql",}   0.0

10/10 → 40/5。绑定问题确认解决:新加的两个 key 真的被读进去了。

顺带说一句,空闲时只有 5 个连接是正常的——min-idle: 5 就是这个意思,负载上来才往 40 长。看到 idle=5 就以为「又没生效」,是另一个常见的误判。

到这里为止,只证明了一件事

配置生效了。排队会不会减少,此时还不知道。 测试环境没有真实负载,验证不了这一层——这也是后面最需要克制的地方。

05扩到 40,整点还是报警

生产按灰度先放一个实例。新实例约 15:46 启动,全程 max=40, min=5,连接获取超时计数为 0。然后一个新告警来了:

有排队比例 16.6667%,峰值 46 个,达到 1% 且峰值 10 个的条件
按启动后的实际运行时间检查

16.67%,比分改之前还高。第一个想法必然是「白改了」。但告警自己给了线索:按启动后的实际运行时间检查。实例才起来二十几分钟,采样点基数很小,一个采样点有排队就是 1/43 ≈ 2.33%,几个点就是两位数百分比——这个比例不能和跑了 24 小时的基线并排看。

于是去翻那二十分钟里的原始采样。整点前后四个点,把故事讲完了:

扩池后的实例,16:00 前后四帧(北京时间)
时间 已创建连接 使用中 等待线程
16:00:00940
16:00:15353561
16:00:30404050
16:00:453900
16:00 前后连接建立与线程等待的时间线 0 20 40 60 连接数 / 线程数 已创建 使用中 等待线程 61 个线程在等 40 个全占满 等待清零 16:00:00 16:00:15 16:00:30 16:00:45
15 秒里连接从 9 个冲到 35 个,再冲到 40 个上限;等待线程随之回到 0。排队的是「长出来的速度」,不是「上限不够」。

四帧读出三件事:

一、突发来的时候,池里只有 9 个连接。 min-idle=5,空闲时池就停在这个数,突发需要现场建连。max-lifetime 又把老连接频繁淘汰掉,池里存不住常备连接。这一轮建连耗时的滚动最大值是 2.04 秒——在这 2 秒里,请求只能排队,而排队就是告警看到的那个数字。

二、上限 40 也不是安全线。 16:00:30 那一帧,40 个连接全部使用中,还有 50 个线程在等。瞬时需求超过 40。整点任务一起触发的时候,「已经扩到 40 了」并不能保证不排队。

三、45 秒后等待清零,但连接没回来。 active=0,已创建=39,说明负载一过立刻释放,没有泄漏。这是好消息:问题不是「借了不还」,是「来的时候不够快」。

告警数字不能直接对比

16.6667% 来自刚启动的实例,分母是二十几分钟的采样;基线里的 3.85% 是 24 小时、2881 个点。同一个 30 秒采样窗口里重新数是 1/43 ≈ 2.33%。拿两个不同口径的百分比说「变差了」,是评测里最常见的错误。

06池下面还有两层

把池调大,只是把「同时能进几个人」放宽。下面这两层不解决,扩池就是往一个漏的桶里加水。

第一层:连接每分钟被换掉一轮

max-lifetime: 60000 生效了(第 03 节第三行)。它的意思是:任何一条连接活满 60 秒就被淘汰重建。四个实例一小时各新建 601–609 个连接,一天约 1.46 万个——对 10 个连接的池来说,等于每分钟把池洗一次。

这直接解释了 16:00:45 那一帧:40 降到 8,累计新建只增加了 1。不是连接被用完,是大量连接到了寿命自己退场。而每次退场都要新建,新建要握手——就是前面那 2.04 秒。

另外还有一个不显眼但需要核对的点:keepalive-time 和 max-lifetime 都设成 60000,不满足「保活间隔必须小于生命周期」的要求,启动日志里通常会有对应警告。这类警告值得单独捞出来看一遍。

第二层:有连接被借了很久才还

排队期间还有一个变化:一分钟平均连接持有时间,从窗口起点的约 0.7–0.8 毫秒升到 5 毫秒,另一个服务从约 0.5 毫秒升到 10 毫秒。同时段里出现了单条连接持有 123.9 秒 和 51.0 秒 的记录。

顺着查,落在一次任务表的锁等待上:

Lock wait timeout exceeded; try restarting transaction

时间点与该实例 51 秒的连接持有记录接近,但不能就此认定它解释了全部排队。能确认的只是:这条链路上确实存在会让连接长期不归还的操作,而扩池不消除它——行锁争用和连接池大小是两个维度的事,把池从 10 加到 40,只是让更多线程一起等同一把锁。

还有一处不均衡

四个实例之间,小时平均借连接次数相差约 2.55 倍。这是借连接次数,不等于 HTTP QPS,说明流量分配、消费者分区或后台任务分配本身就不均匀。这种情况下去扩每个实例的池,等于给最闲的那个也加预算。

07我没说「优化完成」

这次能给出的结论,比想象中窄:

结论 状态 依据
属性名不匹配导致池回落到 10/10 已确认 改名前 10/10,改名后 40/5,唯一变量
60 秒生命周期造成高频轮换 已确认 601–609 个/小时/实例,与现象吻合
扩池后整点仍会短时排队 已确认 16:00:30 采样:40/40,50 个等待
排队比例整体下降 未验证 需同负载、同口径、满 24 小时对比
锁等待是否为排队的独立成因 待验证 时间接近,但未建立因果

要判断「有没有改善」,至少得满足:相近负载、相同时间窗口、相同 30 秒采样口径。只看「还在报警」或「不报警了」,都会被负载波动骗过去——低峰时段当然不排队,那不是优化的功劳。

上线前必须先算的一笔账

这次只灰度了一个实例,所以没出事。如果四个实例同时从 10 扩到 40:

4 × (40 − 10) = +120 个连接

这 120 个连接是打到主库上的。当时手上唯一能查的数据库连接数是 130/4096,但那是只读副本——它不能证明主库有扩池余量,也不能排除主库上的阻塞源。用副本的余量去决定主库的参数,是一个很危险的替换。

所以扩池的节奏是:单实例 → 观察 → 再放一个。而不是改完全部重启。

08可以搬走的检查顺序

下次遇到「配置明明这么写,线上却不是这么跑」,按这个顺序走,比先怀疑流量快得多。

  1. 先读运行值,再读配置 连接池问 hikaricp_connections_max/min,线程池问执行器的核心/最大线程数。配置中心里显示的值是「意图」,进程里的对象才是「事实」。这一步只要一条 curl。
  2. 配置项和它所在的层级,要一起看 同一个名字,放在 spring.datasource.hikari 下是对的,放在多数据源组件的 dynamic.hikari 下就不一定是。层级决定由谁去读,名字决定读不读得到。
  3. 确认容器里实际跑的是哪个版本 属性名随版本变。直接看 JAR:unzip -l app.jar | grep -E 'dynamic-datasource|HikariCP'。别用 pom 里的版本号猜,镜像里的才是真的。
  4. 把「配置已发布」和「池已生效」分开验证 配置更新不保证运行中的池重建。改完必须回到第 1 步,否则你验证的只是配置中心。
  5. 关注默认值,尤其是「两个参数一起变」 多个相关参数同时回到默认,是绑定失败的典型指纹:它不像一次调优,更像一次「没人接手」。
  6. 扩池之前,先算总连接预算并确认打到的是主库 实例数 × (新上限 − 旧上限)。同时核对这个数是被加到主库还是只读副本上——这两者的余量不能互换。
一句话

配置错了,通常会有异常把你叫醒;配置的名字错了,只会安静地变成默认值,然后用「反应慢」的形式出现在告警里。

文中实例、服务与指标均已脱敏,数值取自当次采样窗口;不同口径(采样间隔、运行时长、分母)的比例不可直接比较。

本次只做了只读排查与单实例灰度。连接轮换、锁等待、实例间流量不均三项仍在处理中,尚无结论。