线上故障分析——数据库连接池满了

type

status

date

slug

summary

背景

生产环境收到一则告警通知如下：

可以看到，是数据库连接池满了，无法创建数据库连接了。而我们针对这种场景配置的策略是快速失败，所以会直接报错。

这类异常很容易产生大面积故障，看到之后也是第一时间介入排查。

排查

先查找报错来源，发现只有一台实例有报错（总共有10台）

那么可能是这台实例的问题，并不是代码或者数据库实例的问题。我们又通过当时数据库的负载来验证了这一猜想。（说明一下，整点的升高是由于其他业务，我们这个实例里有很多个库，很多业务共用的）

那么问题一下子就聚焦到10.11.25.176这台机器上了。我们来看看那个点这台机器到底经历了什么？

看了下，这台机器同时段的请求数、消费消息数量均未高于其他机器。所以，排除是请求量大导致的。如果不是请求多，那只能是请求慢了。我们来看看对应时段这台机器上的请求rt：

确实都在18:00:40这个时间点左右，并且rt都还挺高的，我们拿对应的traceId和thread去找一下，看看慢在哪里：

耗时主要在创建数据库连接上，耗时了768ms。我们找了其他耗时长的请求发现都是耗在创建数据库连接上（我们有一个mysql-connector层面的Interceptor，会打印所有建立数据库连接和关闭数据库连接的日志）：

可以看到，2024-03-05 18:00:40,249这个时间点左右，数据库连接池的10个连接几乎在同一个时间关闭，导致池里没有可用的连接。请求进来就只能等待创建连接，而此时创建连接的耗时又非常的长，最终每个请求都要去创建连接，导致瞬间创建了100个连接，数据库连接池一下子就打满了。占满时其实一个可用连接都还没有。

直到 2024-03-05 18:00:41,081 ，终于有一个连接建立成功，然后陆续100个连接都创建成功，服务恢复正常。

池中连接全部在同一时间关闭

那连接同时关闭的原因是什么呢？

好在这个我们二次开发的tomcat-jdbc在每次关闭连接的时候都会打印原因：

可以看到，全部都是因为MAX_AGE_EXPIRED，也就是超过了连接池配置的连接生命周期。我们配置的生命周期是3600s。但是最后2个连接，其实已经远超1小时了，理论上早就应该释放掉了。这个是因为判定连接生命周期是在每次连接归还到连接池的时刻，所以如果这个连接一直没有被取出来使用，它就会一直待在池子里岁月静好。

并且，tomcat-jdbc连接池对于取连接的策略是——越频繁使用的连接越容易被取出（是通过放回连接的时候把连接放在了队首）。这么一来，大大增加了连接超过max age的概率

更进一步，我们又跟踪了一下从应用启动到出现故障之间的所有连接的生命周期日志。这确实是一个潜在的问题：tomcat-jdbc连接池有一个initialSize 参数，用来控制连接池创建时会初始化的连接个数。我们配置的数量为10个。这个时候这10个初始化出来的连接的创建时间几乎是一致的。这就带来了一个致命的问题，它们的失效时间也是一致的。这就有点像缓存届大名鼎鼎的“缓存雪崩”问题——同一时间所有连接都失效了，导致所有请求等待连接创建。

优化

分析出原因之后，优化就比较简单了。我这里采用了2个方法：

连接创建之后，会为它生成一个随机值，这个随机值参与计算连接的最大生命周期。这样就可以把同一时间创建的连接的失效时间错开。

异步任务在检测空闲连接的时候增加生命周期的校验，防止池中存在远远超过最大生命周期的连接。