[alibaba/druid]Oracle10g 使用Driud连接池后,会时不时出现java.sql.SQLException: connection holder is null错误的疑似BUG

2023-12-09 193 views
3

最近在系统长时间运行后,如果在Oracle后台,KILL了一个Session之后,由于系统还是在频繁使用连接,我把timeBetweenEvictionRunsMillis设置为10秒,但是好像还是不会把这种失效的链接从连接池中清除掉。还是会继续让业务调用,造成经常出现connection holder is null的错误,同时ExceptionSorter好像也没有把这种报错的连接抛弃掉,请问这个是否是druid的BUG?还是说我的配置哪里有问题呢?配置和错误信息如下: 配置如下:

<Resource name="jdbc/XXXXX" auth="Container" factory="com.alibaba.druid.pool.DruidDataSourceFactory" type="javax.sql.DataSource" driverClassName="oracle.jdbc.driver.OracleDriver" url="jdbc:oracle:thin:@X.X.X.X:1521:orcl" username="USERNAME" password="PASSWORD" initialSize="20" minIdle="0" maxActive="100" maxWait="1000" removeabandoned="false" removeabandonedtimeout="18000" validationQuery="select 1 from dual" testWhileIdle="true" testOnBorrow="false" testOnReturn="false" timeBetweenEvictionRunsMillis="10000" poolPreparedStatements="true" maxOpenPreparedStatements="100" filters="stat,log4j" />`

错误信息如下: SQL [SELECT CO1,CO2,CO3,CO4,CO5 FROM TABLE1 WHERE KEY1='111' order by CO1]; SQL state [null]; error code [0]; connection holder is null; nested exception is java.sql.SQLException: connection holder is null at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:83) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:406) at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:455) at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:463) at org.springframework.jdbc.core.JdbcTemplate.queryForList(JdbcTemplate.java:494) ........ Caused by: java.sql.SQLException: ORA-00028: your session has been killed

    at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:331)
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:288)
    at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:745)
    at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:216)
    at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:966)
    at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:1062)
    at oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:850)
    at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1134)
    at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3339)
    at oracle.jdbc.driver.OraclePreparedStatement.execute(OraclePreparedStatement.java:3445)
    at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3051)
    at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:440)
    at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3049)
    at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:440)
    at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3049)
    at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.execute(PreparedStatementProxyImpl.java:167)
    at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:494)
  ... 40 more

回答

0

收到,你能提供一下用的druid版本信息么?好让我尽快做验证。

4

@wenshao druid版本信息为1.1.4。 经过了这两天的验证,主要还是我在Oracle数据库中KILL了Session后,好像KILL掉的连接还是会存在连接池中, 造成后续调用出现error code [0]; connection holder is null。然后就出错了。 我把driverClassName改成了oracle.jdbc.OracleDriver也存在同样的问题。 我个人觉得好像他还是不会检查连接是否有效,怀疑是返回的error code为0的问题,而且好像也没有走com.alibaba.druid.pool.vendor.OracleExceptionSorter这个里面。 我今天准备把testOnBorrow和testOnReturn都改为true试试,看能否解决此问题。 谢谢您的关注!

PS:我这里使用的是在tomcat中配置的JNDI,然后在spring中配置的org.springframework.jndi.JndiObjectFactoryBean的dataSource,然后使用dataSource配置的JdbcTemplate。由于系统架构遗留问题,系统中使用了JdbcTemplate和InitialContext.lookup("jdbc/XXXXX")的两种连接方式。

3

我也遇到了这个问题,使用的版本是 1.1.2 mysql-connector-java 的版本是 5.1.41 mysql 版本

mysql --version
mysql  Ver 14.14 Distrib 5.5.57, for debian-linux-gnu (x86_64) using readline 6.3

不过我的数据库是 mysql 我在本地也可以复现

我是 clojure 环境下 而且从 mysql 的日志中,我也没有看到 select 'x' 的语句

(defonce stat-filter
  (doto (StatFilter.)
    (.setSlowSqlMillis (int-env :mysql-slow-mills 1000))
    (.setLogSlowSql true)))

(doto (DruidDataSource.)
                   (.setUrl (format "jdbc:mysql:%s"
                                    (env :db-subname "//127.0.0.1:3306/uluru")))
                   (.setUsername (env :db-username "root"))
                   (.setPassword (env :db-password "xxx"))
                   (.setKeepAlive true)
                   (.setInitialSize 10)
                   (.setMinIdle 10)
                   (.setMaxActive (max
                                   (quot
                                    (config/server-threads)
                                    2)
                                   150))
                   (.setMaxWait 60000) ;; 配置获取连接等待超时的时间
                   (.setValidationQueryTimeout 1)
                   (.setProxyFilters [stat-filter])
                   (.setTimeBetweenEvictionRunsMillis 30000) ;; 间隔多久才进行一次检测,检测需要关闭的空闲连接
                   (.setMinEvictableIdleTimeMillis 30000) ;; 一个连接在池中最小生存的时间,30s
                   (.setTimeBetweenLogStatsMillis 300000) ;; 每隔 5 分钟输出日志
                   (.setValidationQuery "SELECT 'x'")
                   (.setTestWhileIdle true)
                   (.setTestOnBorrow false)
                   (.setTestOnReturn false)
                   (.setPoolPreparedStatements false))

my.conf

wait_timeout=60
interactive_timeout=60

会报错

[ERROR] 10-17 15:46:53,660 [DruidDataSource] - discard connection
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 85,885 milliseconds ago.  The last packet sent successfully to the server was 25,877 milliseconds ago.

的确是超过了 60s 但是貌似检测并没有生效。然后链接被 mysql 收回,连接池依然使用了这个已经被收回的链接,就有了这个异常。

9

@TinyYang 我测试的结果是,1.1.2 的版本 testOnBorrow 和 testOnReturn 也是无效的,并没有看到 select 'x' 的查询语句

5

@wenshao 温少,我这两天debug跟踪,发现了一些情况,OracleExceptionSorter是可以起作用的,但是我查出来现在出现问题的是在这个位置com.alibaba.druid.pool.DruidPooledConnection的347行 ` public PreparedStatement prepareStatement(String sql) throws SQLException { checkState();

    PreparedStatementHolder stmtHolder = null;
    PreparedStatementKey key = new PreparedStatementKey(sql, getCatalog(), MethodType.M1);

    boolean poolPreparedStatements = holder.isPoolPreparedStatements();

    if (poolPreparedStatements) {
        stmtHolder = holder.getStatementPool().get(key);
    }

    if (stmtHolder == null) {
        try {
            stmtHolder = new PreparedStatementHolder(key, conn.prepareStatement(sql));
            holder.getDataSource().incrementPreparedStatementCount();
        } catch (SQLException ex) {
            handleException(ex);
        }
    }

    initStatement(stmtHolder);

    DruidPooledPreparedStatement rtnVal = new DruidPooledPreparedStatement(this, stmtHolder);

    holder.addTrace(rtnVal);

    return rtnVal;
}

public void checkState() throws SQLException {
    final boolean asyncCloseEnabled;
    if (holder != null) {
        asyncCloseEnabled = holder.getDataSource().isAsyncCloseConnectionEnable();
    } else {
        asyncCloseEnabled = false;
    }

    if (asyncCloseEnabled) {
        lock.lock();
        try {
            checkStateInternal();
        } finally {
            lock.unlock();
        }
    } else {
        checkStateInternal();
    }
}

private void checkStateInternal() throws SQLException {
    if (holder == null) {
        if (disableError != null) {
            throw new SQLException("connection holder is null", disableError);
        } else {
            throw new SQLException("connection holder is null");
        }
    }

    if (closed) {
        if (disableError != null) {
            throw new SQLException("connection closed", disableError);
        } else {
            throw new SQLException("connection closed");
        }
    }

    if (disable) {
        if (disableError != null) {
            throw new SQLException("connection disabled", disableError);
        } else {
            throw new SQLException("connection disabled");
        }
    }
}

`

JdbcTemplate在请求数据库访问的时候,调用了prepareStatement,然后首先进入的是checkState()这个方法,问题就是出在,当holder为空时,直接就会到checkStateInternal中抛出异常,而此时是没有到handleException(ex)中的,这个handleException(ex);里面才是OracleExceptionSorter处理的地方。

丢失连接后,肯定是走了pooledConnection.disable(t);这个方法,不然holder不会置为空,因此现在问题就是在于为什么已经disable的holder后续还是会被调用到,导致在进入checkState()方法时就报错了。由于holder怎么调用获取的调度算法我这里还没时间研究,因此希望能给温少提供一点方向和思路,这个问题已经困扰我们很久了,谢谢!

@paomian mysql我现在接触得不多,不过感觉你的问题可能和我的差不多,可能也是出在同一个地方。

8

@TinyYang 具体的代码我没有仔细看,目前使用了暴力增加 mysql 的链接空闲过期时间来缓解这个问题,基本奏效。还是等官方的解释吧。

7

@TinyYang 感觉是因为JdbcTemplate持有了一个连接已经关闭的PreparedStatement

0

@wenshao 温少,感谢您的反馈!但是这样就有点问题了,spring的JdbcTemplate是自动释放连接的啊。我的spring的配置如下: 这是datasource: `

java:comp/env/jdbc/XXXXX ` 这是JdbcTemplate: ![image](https://user-images.githubusercontent.com/7531434/31756299-dffec2f4-b4d5-11e7-905b-e85f028303c8.png) 业务系统中是这样调用JdbcTemplate的: ![image](https://user-images.githubusercontent.com/7531434/31756324-0aea41fa-b4d6-11e7-9883-7beeeca4f7d7.png) 这样的设置,应该都是正常的啊,JdbcTemplate都会自动关闭,因为如果JdbcTemplate持有了一个连接已经关闭的PreparedStatement的话,应该会系统直接崩溃不能运行,但是只是偶尔会出现连接丢失,就好像连接池里面20个连接,其中一个连接丢失了,就只会随机在用到那个丢失连接的时候,就会出错。现在我个人觉得好像就是在调用连接池的连接的时候,引用到了无效的那个连接。 再次感谢您的反馈与帮助!
9

@TinyYang 能否微信找我直接快速交流 wenshaojin

9

@TinyYang 我通过kill session没有模拟出你的问题,能否帮忙构造一个场景帮我重现问题

3

@wenshao 嗨,wenshao,今天从dbcp切换到druid数据库连接池,在测试过程中,同样抛出了connection holder is null的错误。看了你之前给的解决方案,关闭removeAbandoned配置,可以解决问题。但是不太明白的是,druid有对这个配置做什么处理吗?同样这个配置,在dbcp下是正常的,还请wenshao给些思路,谢谢 使用的是最新的版本1.1.5

7

申请连接长时间不适用被关闭了,所以导致connection holder is null错误,removeAbandoned一般用于故障诊断时才打开,你为什么需要使用这个选项?

2

这个配置的目的是防止连接泄漏,所以中项目中配置了这一项

6

@wenshao 温少,我也遇到了这样的问题,出现的场景是,数据库升级重启之后,一直在报这个错。能帮忙分析下吗?

SQL: SELECT * FROM customer_log WHERE corp_id = ?
### Cause: java.sql.SQLException: connection holder is null
; uncategorized SQLException; SQL state [null]; error code [0]; connection holder is null; nested exception is java.sql.SQLException: connection holder is null
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:89)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:75)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:447)
    at com.sun.proxy.$Proxy137.selectOne(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:167)
    at com.baomidou.mybatisplus.core.override.PageMapperMethod.execute(PageMapperMethod.java:101)
    at com.baomidou.mybatisplus.core.override.PageMapperProxy.invoke(PageMapperProxy.java:64)
    at com.sun.proxy.$Proxy142.selectOne(Unknown Source)
    at com.*.dy.customer.service.impl.LeadPullServiceImpl.doPullCorpLead(LeadPullServiceImpl.java:148)
    at com.*.dy.customer.service.impl.LeadPullServiceImpl.pullCorpLead(LeadPullServiceImpl.java:122)
    at com.souche.dy.customer.service.impl.LeadPullServiceImpl.asyncCheckAndPullCorpLead(LeadPullServiceImpl.java:105)
    at sun.reflect.GeneratedMethodAccessor794.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: connection holder is null
    at com.alibaba.druid.pool.DruidPooledConnection.checkStateInternal(DruidPooledConnection.java:1155)
    at com.alibaba.druid.pool.DruidPooledConnection.checkState(DruidPooledConnection.java:1148)
    at com.alibaba.druid.pool.DruidPooledConnection.prepareStatement(DruidPooledConnection.java:336)
    at org.apache.ibatis.executor.statement.PreparedStatementHandler.instantiateStatement(PreparedStatementHandler.java:87)
    at org.apache.ibatis.executor.statement.BaseStatementHandler.prepare(BaseStatementHandler.java:88)
    at org.apache.ibatis.executor.statement.RoutingStatementHandler.prepare(RoutingStatementHandler.java:59)
    at sun.reflect.GeneratedMethodAccessor237.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:49)
    at com.baomidou.mybatisplus.extension.plugins.PaginationInterceptor.intercept(PaginationInterceptor.java:158)
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
    at com.sun.proxy.$Proxy174.prepare(Unknown Source)
    at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:85)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:326)
    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$original$q06qQ9xF(DefaultSqlSession.java:170)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList$original$q06qQ9xF$accessor$MO1fv01r(DefaultSqlSession.java)
    at org.apache.ibatis.session.defaults.DefaultSqlSession$auxiliary$61vsHqE0.call(Unknown Source)
    at com.souche.tracer.plugins.enhance.enhance.instance.InstanceMethodEnhancer.intercept(InstanceMethodEnhancer.java:62)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:154)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne$original$q06qQ9xF(DefaultSqlSession.java:90)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne$original$q06qQ9xF$accessor$MO1fv01r(DefaultSqlSession.java)
    at org.apache.ibatis.session.defaults.DefaultSqlSession$auxiliary$qBP6TbQT.call(Unknown Source)
    at com.souche.tracer.plugins.enhance.enhance.instance.InstanceMethodEnhancer.intercept(InstanceMethodEnhancer.java:62)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java)
    at sun.reflect.GeneratedMethodAccessor390.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)
    ... 20 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure