记druid 连接池没满,但超时问题 GetConnectionTimeoutException active 5, maxActive 100问题说明排查思路定位问题重现结论

65 阅读 0 评论 43 点赞

我是靠谱客的博主明理日记本，最近开发中收集的这篇文章主要介绍记druid 连接池没满,但超时问题 GetConnectionTimeoutException active 5, maxActive 100问题说明排查思路定位问题重现结论，觉得挺不错的，现在分享给大家，希望可以做个参考。

概述

记druid 连接池没满,但超时问题
GetConnectionTimeoutException active 5, maxActive 100

问题说明

线上服务突然出现报错，通过日志查找发现是因为服务升级导致压力集中到某个节点上，出现连接获取超时导致的。
从日志中也找到了异常。
异常信息：

com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 6000, active 5, maxActive 100
----
但是从这个异常信息的描述来看，跟常规的线程池满又不一样，通过异常信息来看，线程池没满（active<maxActive），但是获取连接超时，有点无头脑。

正常的应该差不多是这样：

com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 6000, active 100, maxActive 100

-----

排查思路

怀疑1
线程池满超时，可以增加线程池大小。
但是现在线程池没满，缺又出现超时，首先排查数据库是否不正常。
经过排查，数据库没有限制连接数，其它服务、客户端也能正常使用。
排除数据库问题。

怀疑2
整个环境中也只有该服务因为使用量多而出现，并发量少了之后又恢复正常。
排除锁问题(就算出现锁，也应该把线程池占满)

因为是线上环境，无法简单去更换线程池等操作，一下就陷入到僵持。
druid github上类似问题也有很多人出现，早好几年前就有人提了该问题，但直到今天也没有解决答案。

定位

在一个个浏览github上相关问题时，突然发现某一个大神指出来，通过分析源码，该问题属于BUG，是一个提示性BUG。原因解释：
   出现 GetConnectionTimeoutException 就是代表获取线程池超时，线程池满了。
   为什么提示又说线程池没满呢( active 5, maxActive 100 )？
   这是因为异常的日志打印没有放在同步块中，使用的变量没有考虑多线程。
   简单说就是，在打印日志时，变量(active)的值已被修改，所以不是异常发生时的值。
   代码大概如下： DruidDataSource - 1394
---

            if (holder == null) {
            long waitNanos = waitNanosLocal.get();
            StringBuilder buf = new StringBuilder();
            buf.append("wait millis ")//
               .append(waitNanos / (1000 * 1000))//
               .append(", active ").append(activeCount)//
               .append(", maxActive ").append(maxActive)//
               .append(", creating ").append(creatingCount.get())//

;
---