Apache Druid连接回收引发的血案

问题

线上执行大批量定时任务，发现SQL执行失败的报错：

CommunicationsException, druid version 1.1.10, 
jdbcUrl : jdbc:mysql://xxx?useUnicode=true&characterEncoding=UTF-8&zeroDateTimeBehavior=convertToNull,testWhileIdle true, idle millis 658108, minIdle 2, poolingCount 1,timeBetweenEvictionRunsMillis 60000, lastValidIdleMillis 658108, driver com.mysql.jdbc.Driver, exceptionSorter com.alibaba.druid.pool.vendor.MySqlExceptionSorter

com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failureThe last packet successfully received from the server was 658,107 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.at sun.reflect.GeneratedConstructorAccessor60.newInstance(Unknown Source)at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)at java.lang.reflect.Constructor.newInstance(Constructor.java:423)at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:981)at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3465)at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365)at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805)at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962)at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3188)at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterEventAdapter.java:465)at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3185)at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.executeQuery(PreparedStatementProxyImpl.java:181)at com.alibaba.druid.pool.DruidPooledPreparedStatement.executeQuery(DruidPooledPreparedStatement.java:228)at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57)at org.hibernate.loader.Loader.getResultSet(Loader.java:2304)

追查

从错误日志看来，是连接MySQL超时，但是这个超时时间感觉有点离谱，查看了一下执行的SQL，是非常简单的SQL，理论上不可能造成超时。
联系DBA，看看MySQL的日志能否发现什么蛛丝马迹。

原因

经过DBA排查，确认是MySQL的空闲连接清理参数配置，MySQL的interactive_timeout参数指定了连接空闲多久后会被回收掉，缺省配置为600秒。
在这里插入图片描述

问题初步定位，是因为数据库连接池Druid持有的数据库连接，已经被MySQL回收，此时有SQL执行时，已经被回收掉的连接再此被分配，就会导致这个报错。
那么问题来了，为什么数据库连接池没有感知到这个连接已经被回收了呢？

连接池是怎么判断一条连接是Idle状态的？

带着疑问，翻找Druid文档，发现两个配置：

minEvictableIdleTimeMillis：最小空闲时间，默认30分钟，如果连接池中非运行中的连接数大于minIdle，并且那部分连接的非运行时间大于minEvictableIdleTimeMillis，则连接池会将那部分连接设置成Idle状态并关闭；也就是说如果一条连接30分钟都没有使用到，并且这种连接的数量超过了minIdle，则这些连接就会被关闭了。
maxEvictableIdleTimeMillis：最大空闲时间，默认7小时，如果minIdle设置得比较大，连接池中的空闲连接数一直没有超过minIdle，这时那些空闲连接是不是一直不用关闭？当然不是，如果连接太久没用，数据库也会把它关闭，这时如果连接池不把这条连接关闭，系统就会拿到一条已经被数据库关闭的连接。为了避免这种情况，Druid会判断池中的连接如果非运行时间大于maxEvictableIdleTimeMillis，也会强行把它关闭，而不用判断空闲连接数是否小于minIdle。

原来Druid是根据这两个配置来确认什么时候回收空闲的连接，为了验证是否如此，看一下源码中如何使用这两个配置。

我们使用的Druid版本是1.1.10。

com.alibaba.druid.pool.DruidDataSource

    public class DestroyTask implements Runnable {@Overridepublic void run() {shrink(true, keepAlive);if (isRemoveAbandoned()) {removeAbandoned();}}}

追踪源码，定位到DruidDataSource，*DestroyTask shrink()*负责释放连接：

public void shrink(boolean checkTime, boolean keepAlive) {try {lock.lockInterruptibly();} catch (InterruptedException e) {return;}int evictCount = 0;int keepAliveCount = 0;try {if (!inited) {return;}final int checkCount = poolingCount - minIdle;final long currentTimeMillis = System.currentTimeMillis();for (int i = 0; i < poolingCount; ++i) {DruidConnectionHolder connection = connections[i];if (checkTime) {if (phyTimeoutMillis > 0) {long phyConnectTimeMillis = currentTimeMillis - connection.connectTimeMillis;if (phyConnectTimeMillis > phyTimeoutMillis) {evictConnections[evictCount++] = connection;continue;}}long idleMillis = currentTimeMillis - connection.lastActiveTimeMillis;if (idleMillis < minEvictableIdleTimeMillis) {break;}if (checkTime && i < checkCount) {evictConnections[evictCount++] = connection;} else if (idleMillis > maxEvictableIdleTimeMillis) {evictConnections[evictCount++] = connection;} else if (keepAlive) {keepAliveConnections[keepAliveCount++] = connection;}} else {if (i < checkCount) {evictConnections[evictCount++] = connection;} else {break;}}}.........}

在*shrink()*方法中我们找到了minEvictableIdleTimeMillis和maxEvictableIdleTimeMillis，等等，好像哪里不对？

		if (idleMillis < minEvictableIdleTimeMillis) {break;}if (checkTime && i < checkCount) {evictConnections[evictCount++] = connection;} else if (idleMillis > maxEvictableIdleTimeMillis) {evictConnections[evictCount++] = connection;} else if (keepAlive) {keepAliveConnections[keepAliveCount++] = connection;}