abandon connection, owner thread: xxxx, connected at : 1606897800625, open stackTrace

 

问题现象：

使用Druid的数据库连接池，在进行一个查询SQL的时候，抛出了异常：

[2017-10-20 01:40:59.269 ERROR com.alibaba.druid.pool.DruidDataSource:2189] abandon connection, owner thread: schedulerDuty_Worker-2, connected at : 1508434843057, open stackTrace
        at java.lang.Thread.getStackTrace(Thread.java:1552)
        at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1068)
        at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4544)
        at com.alibaba.druid.filter.stat.StatFilter.dataSource_getConnection(StatFilter.java:662)
        at com.alibaba.druid.filter.FilterChainImpl.dataSource_connect(FilterChainImpl.java:4540)
        at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:992)
        at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:984)
        at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:103)
        at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
        at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
        at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:84)
        at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:70)
        at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
        at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
        at sun.reflect.GeneratedMethodAccessor696.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:434)
        at com.sun.proxy.$Proxy61.selectOne(Unknown Source)
        at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:167)
        at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)
        at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
        at com.sun.proxy.$Proxy83.isStatisticExist(Unknown Source)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
ownerThread current state is RUNNABLE, current stackTrace
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:145)
          at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:145)
        at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:114)
        at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
        at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:274)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1661)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:512)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:374)
        at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:366)
        at com.alibaba.druid.filter.FilterChainImpl.statement_execute(FilterChainImpl.java:2489)
        at com.alibaba.druid.filter.FilterAdapter.statement_execute(FilterAdapter.java:2451)
        at com.alibaba.druid.filter.FilterEventAdapter.statement_execute(FilterEventAdapter.java:188)
        at com.alibaba.druid.filter.FilterChainImpl.statement_execute(FilterChainImpl.java:2487)
        at com.alibaba.druid.proxy.jdbc.StatementProxyImpl.execute(StatementProxyImpl.java:137)
        at com.alibaba.druid.pool.DruidPooledStatement.execute(DruidPooledStatement.java:416)
        at org.apache.ibatis.executor.statement.SimpleStatementHandler.query(SimpleStatementHandler.java:73)
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
        at sun.reflect.GeneratedMethodAccessor696.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:434)
        at com.sun.proxy.$Proxy61.selectOne(Unknown Source)
        at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:167)
        at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:82)
        at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
        at com.sun.proxy.$Proxy83.isExist(Unknown Source)

 

从报错信息中可以提取到，是Druid连接池执行SQL，获取Statement失败，导致的问题

问题分析：

根据异常的第一行，可以得知报错来自于DruidDataSource这个类，根据报错的信息，可以看出是因为执行SQL时获取不到Connection连接，然后去看一下Druid的配置中，有三个配置可以关注一下：

配置	默认值	说明
removeAbandoned	false	是否强制关闭连接时长大于removeAbandonedTimeoutMillis的连接
removeAbandonedTimeoutMillis	300 * 1000	一个连接从被连接到被关闭之间的最大生命周期
logAbandoned	false	强制关闭连接时是否记录日志

再去查看我们的配置，removeAbandoned是true，代表的意思是 是否关闭连接时长大于一定时长的连接，问题可能是出在这里，去看源代码：

public class DestroyTask implements Runnable {
        public DestroyTask() {
        }

        public void run() {
            DruidDataSource.this.shrink(true);
            if(DruidDataSource.this.isRemoveAbandoned()) {
                DruidDataSource.this.removeAbandoned();
            }
        }
}

发现调用removeAbandoned的位置在这里，这里是一个线程，在连接池初始化的时候会启动一个调度，在定时的时间频度去执行，可以看出这里的判断条件是如果开启了配置，就去执行removeAbandoned()这个方法，来看一下这个方法里面有什么： 

public int removeAbandoned() {
    int removeCount = 0;
    long currrentNanos = System.nanoTime();
    ArrayList abandonedList = new ArrayList();
    Map var5 = this.activeConnections;
    synchronized(this.activeConnections) {
        Iterator pooledConnection = this.activeConnections.keySet().iterator();

        while(pooledConnection.hasNext()) {
             DruidPooledConnection buf = (DruidPooledConnection)pooledConnection.next();
             if(!buf.isRunning()) {
                long trace = (currrentNanos - buf.getConnectedTimeNano()) / 1000000L;
                  if(trace >= this.removeAbandonedTimeoutMillis) {
                      pooledConnection.remove();
                      buf.setTraceEnable(false);
                      abandonedList.add(buf);
                  }
             }
        }
    }

.................

}

这里给出了一部分的代码实现，可以看到问题的原因可能就是出现在这里了，这里进行了一个判断，循环遍历连接池中的连接，如果存活，就判断是否超过了配置的removeAbandonedTimeoutMillis（单位是毫秒，配置里面需要配置秒，有转换），如果超过了时间，我就干死你！

解决方案

问题原因已经找到，那么解决的办法就是将removeAbandoned这个配置设置为false或者不设置（默认就是false），或者将removeAbandonedTimeoutMillis这个时间配置调大：

<!--配置成三十分钟-->
<property name="removeAbandonedTimeout" value="1800" />

 配置文件

#
#Mon Nov 23 16:54:46 CST 2020
druid.timeBetweenEvictionRunsMillis=60000
druid.minEvictableIdleTimeMillis=300000
druid.removeAbandoned=true
jdbc.password={DES}9qs4Ja9p0Aw/j6pwJuAWfQ\=\=
jdbc.url=jdbc\:oracle\:thin\:@136.6.129.40\:1521\:orcl
druid.minIdle=10
hibernate.show_sql=false
jdbc.username={DES}Ek1hKybhVT9YmXT0qg8mkQ\=\=
jdbc.driver=oracle.jdbc.driver.OracleDriver
druid.maxIdle=15
druid.testWhileIdle=true
druid.maxWait=60000
hibernate.hbm2ddl.auto=none
druid.validationQuery=SELECT 'x' FROM DUAL
# 1、把这里修改false
druid.logAbandoned=true
# 2、这里的值调大 我这里调成了4个小时
druid.removeAbandonedTimeout=14400
druid.initialSize=1
druid.filters=stat
druid.testOnBorrow=false
druid.testOnReturn=false
druid.maxActive=200
druid.maxOpenPreparedStatements=20
hibernate.dialect=org.hibernate.dialect.Oracle10gDialect

再观察，就不会出现报错的情况了，问题解决~

说明：

 https://github.com/alibaba/druid/wiki/%E8%BF%9E%E6%8E%A5%E6%B3%84%E6%BC%8F%E7%9B%91%E6%B5%8B

转发:

http://www.voidcn.com/article/p-rzcimxtf-bqo.html