记 Druid 连接池配置不当引发的服务卡慢宕机问题

背景

单体服务部署到 Tomcat 之后，运行一段时间，出现系统响应超时的情况。重启服务后正常，一段时间后重新出现。

排查

查看 CPU 信息发现正常，打开 jvisualvm，发现线程数持续上升，且没有下降趋势，此时初步判断系统在某个地方卡住了，请求进来后处理任务的线程都处于等待状态。

在 jvisualvm 中导出线程 Dump，到 fast thread 中进行分析，发现大量线程（80% 以上）处于 WAITING 状态，继续查看堆栈信息，发现大部分线程都阻塞在 DruidDataSource.takeLast 中：

"http-nio-8008-exec-138" #98760 daemon prio=5 os_prio=0 tid=0x0000000042d7f800 nid=0x602c waiting on condition [0x00000000758ac000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000003c15c1328> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:2002)
	at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1539)
	at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1326)
	at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5007)
	at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:680)
	at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:5003)
	at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1304)
	at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1296)
	at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:109)
	...

想到可能是数据库连接池耗尽了。在网上发现有人遇到同样的问题 druid/issues/1160。

解决

为什么会耗尽呢，结合网络上的分析，认为可能是数据库连接在某个地方没释放，也就是发生了泄露，连接一直得不到回收最后慢慢耗尽。于是配置了
removeAbandoned 和 removeAbandonedTimeout，发现无效，而且更严重的是出现了 CPU 飙升的情况，查看日志，估计是回收了流程引擎这类基础组件所用到的连接，导致出现意外的死循环。

考虑到项目上线初期并没有出现该问题，认为可能是随着数据量的增大，报表统计等慢 SQL 占用连接时间变长，加上用户量的上升，请求会变得比以前频繁，在并发较高时，就出现了连接池耗尽的情况。

于是本地启动应用，使用 jmeter 对报表接口连发了 100 个请求，结合 JProfiler 监控系统状态，发现果然线程数持续上升后一直没降下来，其他接口无法正常响应。

查看 druid 配置，发现 max-active、max-wait 未配置，为默认值。max-wait 默认 -1 也就是不超时，max-active 默认为 8。

再定位到 DruidDataSource.takeLast 被调用的位置，发现有如下逻辑：

if (maxWait > 0) {
    holder = pollLast(nanos);
} else {
    holder = takeLast();
}

这是在从阻塞队列中获取 holder，poll 在指定时间内如果获取失败了会直接返回，take 则会持续等待。于是设置了 max-wait 重新测试，发现超时后，线程数降下来了，但是超时时间内，系统还是无法正常响应。

其实最主要是要知道为什么会卡住不释放连接，但还是决定增大 max-active，提升处理并发的能力。重新测试，发现正常，上线后没再出现该问题。

总结

因为没有配置 max-active 和 max-wait，导致在并发数上升后，出现数据库连接池连接耗尽的情况，表现为系统卡住。加上配置后问题解决。

druid:
  max-active: 150
  max-wait: 60000

后记

其实第一次碰到没什么经验，刚开始怀疑是内存泄漏导致 OOM，但是日志和堆 Dump 中未发现问题，后面又怀疑是不是重启应用时缓存未正常处理，最后发现其实都不是。

另外，实际处理时也没有这么清晰的思路，也没有用到多少分析工具，倒是用 Arthas 监控过应用但是没找到问题。

所以处理完问题后，应该及时总结经验，理清思路，方便之后再遇到时及时解决。

参考：

Druid 获取连接超时，导致服务不可用

踩坑 DruidDataSource 导致的服务卡死

Alibaba Druid 数据库连接池 takeLast() AQS 死锁导致程序无响应

Druid 连接泄露记录

相关内容：

Druid-Source-Block 踩坑

工作笔记（一）：Druid 连接池未正确设置参数导致的阻塞问题分析

java 打印堆栈文件 jstack 打印堆栈信息

如何用 Jstack 把 java 进程中的堆栈信息输出到文件

记一次线上 tomcat 服务器运行正常但是无响应问题排查