记阿里Druid数据连接池引发的线上血案

记阿里Druid数据连接池引发的线上血案

前言碎语

事件起因：项目使用了activiti工作流，系统是由老的spring mvc项目改造成的spring boot项目，数据库链接池从dbcp切换到druid，新系统上线后，同事多次系统隔一段时间后数据查询就很慢，基本出不来。由此开始了线上bug排查之路。这个问题从一开始就模糊定位到数据库层面的问题，因为只有和数据相关的操作会很慢，其他服务不受影响，并且在中午休息时没有问题，在下午刚上班后不就出现。

过程一：定位工作流

首先第一反应是看日志：日志一切正常，并没有任何异常信息抛出，然后将日志级别调整到debug，发现了一些问题，中午休息时，用户没有操作的情况下，日志一直在输出jpa的连接信息，最后定位是工作流的异步执行器在轮询，因为在spring boot环境下spring.activiti.async-executor-activate=true默认是true的，如果不需要使用可以设置为false，改完后情况依旧

过程二：定位JPA的OpenEntityManagerInViewInterceptor

使用OpenEntityManagerInViewInterceptor后服务端在接收到一个请求的时候开启EntityManager，在请求结束的时候才去关闭这个EntityManager，所以在用户数多，并发高，操作耗时的情况下会造成数据连接不够用的情况，而我们的业务有这个特征。在spring boot环境中，OpenEntityManagerInViewInterceptor默认是开启的，然而我们使用spring.jpa.open-in-view=false关闭后，问题依旧，不过比之前的间隔时间久一点了

过程三：定位Druid，真正的罪魁祸首

使用top定位到程序pid，然后使用jstack -l 2591 >>dump.out 拿到当前堆栈快照后发现如下

"http-nio-8080-exec-54" daemon prio=10 tid=0x0000000000e61000 nid=0xcc9 waiting on condition [0x00007f4a753d4000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000007a143f230> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
	at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:1732)
	at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1330)
	at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1198)
	at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4619)

所有的请求都被druid的获取连接操作阻塞了，最后看源码如下

因为数据链接没有释放，连接池中无可用连接，导致请求被阻塞了

到这里基本上就是真相了，最后换成spring boot自带的连接池tomcat jdbc后一切正常

后记：

定位到问题后，发现网上很多人遇到了连接泄露的情况，可见druid的官方issue，如https://github.com/alibaba/druid/issues/1160

不过druid也提供了相应的方案，如下

虽然官方说可能是应用自己导致连接未被释放导致连接泄露，但是为什么切换别家的连接池后就毛事都没有呢，元芳，你怎么看呢？