Communications link failure:连接池和 wait_timeout 的时间竞赛

每天凌晨第一笔请求必失败,重试就好。Aborted_clients 一千八百多,maxLifetime 用的是默认值,wait_timeout 被改成了十分钟。三组超时的先后顺序怎么排。

报表服务有个很规律的毛病:每天凌晨两点出头,第一笔请求必定失败,报 Communications link failure,隔几秒重试就正常。业务方一开始没当回事,因为「点一下重试就好了」;后来是日报任务的调度器不重试,直接标红,运维每天早上先处理一条假告警。

我看了下时间分布,失败几乎全部落在 02:00 到 02:10 之间,白天一条都没有。这个时间特征很有意思——它说明问题不在代码逻辑,而在「空闲了多久」这件事上。

一、先分清是谁断的:服务端还是中间设备

Communications link failure 是个笼统的客户端异常,意思是「写出去的数据读不回来了」。可能的原因至少有三种:MySQL 服务端主动关了连接、中间的防火墙或 NAT 把会话表清了、客户端自己关了但池子以为是活的。

这三种的排查方式完全不同,所以第一步是把「谁先断」定下来。我把 MySQL 的 wait_timeout 和 interactive_timeout 拿出来看:

SHOW VARIABLES LIKE '%timeout%';
-- wait_timeout        600
-- interactive_timeout 600
-- net_read_timeout    30
-- net_write_timeout   60

600 这个值一看就不对。MySQL 的默认是 28800(8 小时),600 是十分钟,明显被人改过。我去问 DBA,答复是上个月为了「回收闲置连接、避免连接数打满」统一调过一批实例,报表库也在里面。

这就解释了时间特征:凌晨两点前后报表服务基本没流量,连接池里的连接空闲十几分钟,被服务端 wait_timeout 踢掉;两点多第一笔请求从池里取出一个已经被对端关掉的连接,写进去,读不回来,抛异常。

再看服务端有没有留下痕迹。SHOW PROCESSLIST 看不到已断的连接,但 Aborted_clients 计数器能间接印证:

SHOW GLOBAL STATUS LIKE 'Aborted%';
-- Aborted_clients   1841
-- Aborted_connects  12

Aborted_clients 一千八百多,Aborted_connects 只有十二。前者是「连接建立后异常断开」,后者是「连都连不上」。这个比例基本可以确定:连接是建立成功的,是后来被一方单方面丢掉的。

二、三组超时的先后顺序

搞清楚是谁断的之后,问题变成「谁应该先断」。这里有三个时间,必须排好序:

超时 位置 我们当时的值 含义
wait_timeout MySQL 服务端 600s 服务端多久回收空闲连接
maxLifetime HikariCP 1800000ms(默认 30 分钟) 池里连接最长存活多久,到点主动淘汰
idleTimeout HikariCP 600000ms(默认 10 分钟) 连接空闲多久被池回收
keepaliveTime HikariCP 0(默认关闭) 多久探活一次

正确的顺序是:maxLifetime 必须小于 wait_timeout,而且要留出余量;idleTimeout 小于 maxLifetime,否则永远不会触发。

我们当时的配置是反的:maxLifetime 用默认的 30 分钟,wait_timeout 被改成了 10 分钟。池子以为连接还能活 30 分钟,服务端 10 分钟就把它收了。中间那 20 分钟,池里的连接全是「尸体」。

idleTimeout 也没起作用。它是 10 分钟,理论上应该在服务端之前把空闲连接回收——但 HikariCP 的 idleTimeout 只对「超出 minimumIdle 的空闲连接」生效。我们的 minimumIdle 配的和 maximumPoolSize 一样大(都是 20),意味着池子里的连接永远是「必须保留」的,idleTimeout 一个都不会回收。

这一点文档里写得清楚,但很容易漏。我当时是看 HikariPool 的 debug 日志才确认的:

logging:
  level:
    com.zaxxer.hikari: DEBUG
    com.zaxxer.hikari.HikariConfig: DEBUG

打开之后能看到 Pool stats (total=20, active=0, idle=20, waiting=0) 这样的行,idle=20 且 total 一直不减,说明没有连接被淘汰。

三、为什么池子里的连接看起来是好的

这里有个容易误判的点:连接被服务端关掉之后,客户端这边是「不知道」的。TCP 连接的对端发了 FIN,如果本地没有读写,内核不会主动告诉应用层。所以池子里的 Connection 对象状态还是 isValid,isClosed() 返回 false。

只有真正写数据的时候,才会发现对端已经走了——第一次写可能成功(进了内核缓冲),第二次读超时或者直接 RST。这就是为什么异常信息里经常带着 The last packet successfully received from the server was 601,234 milliseconds ago。

这句话其实是最好用的线索:它直接告诉了你连接空闲了多久。601 秒,正好卡在 wait_timeout 600 秒之后一点点。看到这个数,基本不用再怀疑别的。

所以「池子里有一堆死连接」这件事,本质是客户端无法感知对端关闭,只能靠主动探活或定期淘汰。指望 isValid() 是不可靠的,除非配置了 validationQuery 并且真的执行了。

四、配置怎么改

改法有两层,缺一不可。

第一层,让 maxLifetime 稳稳地小于 wait_timeout。wait_timeout 是 600 秒,maxLifetime 给到 480 秒(8 分钟),留两分钟余量。这个余量不是随便取的,它要覆盖「连接刚被校验为有效、马上就被服务端回收」的窗口,以及时钟漂移。

第二层,把 minimumIdle 调小,让 idleTimeout 真正生效。我们改成了 minimumIdle: 5,maximumPoolSize: 20,这样低峰期池子会缩到 5 个,空闲连接有机会被回收。

第三层是加 keepaliveTime,让池子定期探活。这个参数是 HikariCP 4.0.0 之后才有的,作用是「每隔这么久发一次心跳,顺便把死连接剔掉」。设成 300 秒(5 分钟),比 maxLifetime 小,比空闲检测周期密。

spring:
  datasource:
    url: jdbc:mysql://10.20.5.31:3306/report?useSSL=false&serverTimezone=Asia/Shanghai
    username: report_rw
    password: ${DB_PASSWORD}
    hikari:
      maximum-pool-size: 20
      minimum-idle: 5            # 低于最大值,idleTimeout 才会生效
      connection-timeout: 3000   # 从池里拿连接最多等 3 秒
      idle-timeout: 300000       # 空闲 5 分钟回收
      max-lifetime: 480000       # 必须小于 MySQL 的 wait_timeout(600s)
      keepalive-time: 300000     # 5 分钟一次心跳探活
      validation-timeout: 2000
      connection-test-query: SELECT 1

改完上线,第二天的凌晨两点没有再报错。为了确认不是「碰巧没触发」,我特意在测试环境把 wait_timeout 调到 60 秒,maxLifetime 调到 50 秒,跑了一夜的定时任务,异常数为 0。

五、validation 的代价

connection-test-query: SELECT 1 每次从池里拿连接都会执行一次。这对报表服务这种 QPS 不高的场景无所谓,但在高并发场景下是实打实的开销:每次 SELECT 1 都是一次网络往返,二十个连接一秒几百次,累积起来能吃掉几个百分点的 CPU。

MySQL 的 JDBC 驱动支持更轻的方式——Connection.isValid() 走的是 ping,不需要真正执行 SQL。HikariCP 在有 connection-test-query 时会优先用它,没有时用 isValid()。所以我后来把那行删了,依赖驱动自己的 ping:

      # connection-test-query 删掉,靠驱动 ping,省一次往返
      validation-timeout: 2000

代价是兼容性:极老的驱动(MySQL Connector/J 5.1.30 之前)isValid() 实现有问题,会误判。我们用的是 8.0.x,没这个顾虑。这个取舍要看你自己的驱动版本,不能照抄。

六、另一个容易一起改错的地方

排查过程中我还发现一个相邻的问题:连接池的参数改了,但 DataSource 之外还有一处也管着连接生命周期——spring.datasource.tomcat 的旧配置残留。

这个项目的 application.yml 里同时存在 spring.datasource.hikari.* 和一段从老项目搬过来的 spring.datasource.tomcat.*。Spring Boot 只会用激活的那个连接池,另一段是死配置。它不影响运行,但会让下一个人以为参数生效了。

这类死配置在迁移项目里很常见。我的做法是把不生效的那段删掉,如果暂时不敢删,就在上面加一行注释写明「当前未生效,连接池为 HikariCP」。留一段看起来像生效其实没生效的配置,比没有配置更危险。

七、防复发

三件事。

一是把「三个超时的关系」写进部署检查项:maxLifetime < wait_timeout × 0.8,idleTimeout < maxLifetime,minimumIdle < maximumPoolSize。这三条里任意一条不成立,都值得在评审时提出来。

二是让连接池状态可见。HikariPool 的 total / active / idle / waiting 四个数打到监控里,waiting 长期大于 0 说明池子不够,idle 恒等于 maximumPoolSize 说明 idleTimeout 没生效。这两个指标比任何日志都直观。

三是在测试环境保留一个「短超时」的配置档。把 wait_timeout 压到 60 秒,跑一夜就能暴露大部分连接生命周期问题,成本极低。我们现在的 CI 每晚跑一次这个档,跑了三周,抓出两个别处的同类问题。

小结

  • Communications link failure 先分清是谁断的,Aborted_clients 远大于 Aborted_connects 说明连接建立成功、后被单方丢弃。
  • 异常里的 last packet successfully received ... milliseconds ago 直接告诉你空闲了多久,对着 wait_timeout 一比就知道答案。
  • maxLifetime 必须小于 wait_timeout 并留余量,默认值 30 分钟在 wait_timeout=600 的实例上必然出问题。
  • minimumIdle 等于 maximumPoolSize 时 idleTimeout 完全失效,这是最常见的配置误用。
  • 客户端感知不到对端关闭,isClosed() 不可信,只能靠 keepaliveTime 或定期淘汰。
  • 迁移项目里残留的 spring.datasource.tomcat.* 死配置要删掉或注明,它会让后来者误判。
查看「数据库与缓存」全部文章 →

同分类文章

查看 0 评论 0

评论

正在加载评论…

留言提交后自动审核:正常内容立即显示,含敏感信息的会转人工复核。