赶紧的，用户已经打电话来投诉线上出问题了

Posted 2021-03-20 tonyy

出bug了

如标题所示，用户资金获取失败，线上某个服务通过dubbo调用接口都返回异常。
赶紧连上服务器看日志，进去一看吓到了。

 Cause: java.sql.SQLException: connection holder is null
; uncategorized SQLException for SQL []; 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:84)
        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:73)
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:371)
        at com.sun.proxy.$Proxy23.selectOne(Unknown Source)

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:75)
        at org.apache.ibatis.executor.statement.BaseStatementHandler.prepare(BaseStatementHandler.java:85)
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.prepare(RoutingStatementHandler.java:57)
        at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:73)
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:59)
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:267)
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:137)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:96)
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:77)
        at sun.reflect.GeneratedMethodAccessor223.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)


Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3143)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3597)
        ... 86 more

分析问题

全部是数据库的连接获取不到，技术栈说明下。我们是dubbo远程调用，数据库连接池是druid，数据库用的是mysql。
登录mysql 服务器 show full processlist 命令查，未发现异常。再查看mysql超时设置。
客户那边一直再催问题，没办法先重启这个台服务看看。先重启了一台机器发现好了，难道重启之后释放掉了？

万能大法，重启起效了？不行得找到根本到原因不然下一次肯定还有报这种错误。
查看Druid 的配置文件

<bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource"
        init-method="init" destroy-method="close" >
    

        <!-- 配置获取连接等待超时的时间 -->
        <property name="maxWait" value="60000" />

        <!-- 配置间隔多久才进行一次检测，检测需要关闭的空闲连接，单位是毫秒 -->
        <property name="timeBetweenEvictionRunsMillis" value="60000" />
        <!-- 配置一个连接在池中最小生存的时间，单位是毫秒 -->
        <property name="minEvictableIdleTimeMillis" value="300000" />

        <property name="validationQuery" value="select now()" />
        <property name="testWhileIdle" value="true" />
        <property name="testOnBorrow" value="false" />
        <property name="testOnReturn" value="false" />
        <property name="removeAbandoned" value="true" />
        <property name="removeAbandonedTimeout" value="1800" />
        <property name="logAbandoned" value="true" />
    </bean>

removeAbandonedTimeout 这个配置是1800秒30分钟。由于我们是整站拆分了多个服务，每个服务还有多个节点。
都连接的同一个数据库实例，数据库的连接数都是固定的。应该是removeAbandonedTimeout ，超时时间设置的问题。
当一个连接用法，不是立马释放，生产环境配置的是30分钟，当多个服务同时取拿数据库的连接释放的时间都是30分钟。
再有数据库请求过来连接拿不到，连接池就会爆掉，以下代码是释放不需要的连接。

public int removeAbandoned() {
        int removeCount = 0;

        long currrentNanos = System.nanoTime();

        List<DruidPooledConnection> abandonedList = new ArrayList<DruidPooledConnection>();

        activeConnectionLock.lock();
        try {
            Iterator<DruidPooledConnection> iter = activeConnections.keySet().iterator();

            for (; iter.hasNext();) {
                DruidPooledConnection pooledConnection = iter.next();

                if (pooledConnection.isRunning()) {
                    continue;
                }

                long timeMillis = (currrentNanos - pooledConnection.getConnectedTimeNano()) / (1000 * 1000);

                if (timeMillis >= removeAbandonedTimeoutMillis) {
                    iter.remove();
                    pooledConnection.setTraceEnable(false);
                    abandonedList.add(pooledConnection);
                }
            }
        } finally {
            activeConnectionLock.unlock();
        }

总结

此次关于数据库都连接池的问题，暂时先改了超时的时间。观察了下还没发现再有此错误，等后续问题记录下来分享。
欢迎大家扫一扫，认识不一样的我。??