背景
单体服务部署到 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 监控过应用但是没找到问题。
所以处理完问题后,应该及时总结经验,理清思路,方便之后再遇到时及时解决。
标签:java,宕机,max,druid,Druid,服务卡,DruidDataSource,alibaba,com From: https://www.cnblogs.com/Higurashi-kagome/p/18366718参考:
Alibaba Druid 数据库连接池 takeLast() AQS 死锁导致程序无响应
相关内容:
工作笔记(一):Druid 连接池未正确设置参数导致的阻塞问题分析