原创

ERROR [com.alibaba.druid.pool.DruidDataSource] - abandon connection

版权声明:本文为博主原创文章,遵循 CC 4.0 BY-SA 版权协议,转载请附上原文出处链接和本声明。
本文链接:https://fangzhang.blog.csdn.net/article/details/79007432

摘要

本文描述了如何解决一个Druid connection 泄露的问题,因为过程有些曲折,就详细记录下解决步骤与思路,如果对你有所帮助与启发,请留言

#项目结构#
MyBatis+TDDL

问题

https://github.com/FS1360472174/javaweb/issues/58

ERROR [com.alibaba.druid.pool.DruidDataSource] - abandon connection, owner thread: qtp1267032364
-14, connected at : 1515409987672, open stackTrace
at java.lang.Thread.getStackTrace(Thread.java:1556)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1068)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:994)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:984)
at com.taobao.tddl.atom.jdbc.TDataSourceWrapper.getConnectionByTargetDataSource(TDataSourceWrapper.java:322)
at com.taobao.tddl.atom.jdbc.TDataSourceWrapper.getConnection0(TDataSourceWrapper.java:284)
at com.taobao.tddl.atom.jdbc.TDataSourceWrapper.getConnection(TDataSourceWrapper.java:255)
at com.taobao.tddl.atom.jdbc.TDataSourceWrapper.getConnection(TDataSourceWrapper.java:222)
at com.taobao.tddl.atom.AbstractTAtomDataSource.getConnection(AbstractTAtomDataSource.java:27)
at com.taobao.tddl.group.jdbc.DataSourceWrapper.getConnection(DataSourceWrapper.java:120)
at com.taobao.tddl.group.jdbc.TGroupConnection.createNewConnection(TGroupConnection.java:191)
at com.taobao.tddl.group.jdbc.TGroupConnection$1.tryOnDataSource(TGroupConnection.java:453)
at com.taobao.tddl.group.jdbc.TGroupConnection$1.tryOnDataSource(TGroupConnection.java:443)
at com.taobao.tddl.group.dbselector.AbstractDBSelector.tryOnDataSourceHolderWithIndex(AbstractDBSelector.java:19

at com.taobao.tddl.group.dbselector.AbstractDBSelector.tryExecute(AbstractDBSelector.java:315)
at com.taobao.tddl.group.jdbc.TGroupConnection.prepareCall(TGroupConnection.java:492)
at com.taobao.tddl.group.jdbc.TGroupConnection.prepareCall(TGroupConnection.java:520)
at com.taobao.tddl.group.jdbc.TGroupConnection.prepareCall(TGroupConnection.java:74)
at com.taobao.tddl.matrix.jdbc.TConnection.prepareCall(TConnection.java:515)
at com.taobao.tddl.matrix.jdbc.TConnection.prepareCall(TConnection.java:483)
14980,1-8 99%
at com.taobao.tddl.group.jdbc.TGroupConnection.prepareCall(TGroupConnection.java:74)
at com.taobao.tddl.matrix.jdbc.TConnection.prepareCall(TConnection.java:515)
at com.taobao.tddl.matrix.jdbc.TConnection.prepareCall(TConnection.java:483)

在线上排查其他问题时,看到日志中有这个ERROR,而且很频繁。
根据abandon connection,得知这是一个数据库连接池问题,废弃的连接处理。

解决步骤

  • 首先搜了下druid 官网 FAQ
    https://github.com/alibaba/druid/wiki/常见问题
    发现是druid有对连接泄露进行监控处理

    https://github.com/alibaba/druid/wiki/连接泄漏监测
    https://github.com/alibaba/druid/issues/872
    我这边没有配对监控,直接是从日志中看到的,有相应的线程栈信息,可以方便排查。

    public DruidPooledConnection getConnectionDirect(long maxWaitMillis) throws SQLException {
            int notFullTimeoutRetryCnt = 0;
    
            DruidPooledConnection poolableConnection;
            while(true) {
                while(true) {
                    try {
               
                    Connection realConnection = poolableConnection.getConnection();
                    this.discardConnection(realConnection);
                } else {
                    Connection realConnection = poolableConnection.getConnection();
                    if(realConnection.isClosed()) {
                        this.discardConnection((Connection)null);
                    } else {
                        if(!this.isTestWhileIdle()) {
                            break;
                        }
    
                        long currentTimeMillis = System.currentTimeMillis();
                        long lastActiveTimeMillis = poolableConnection.getConnectionHolder().getLastActiveTimeMillis();
                        long idleMillis = currentTimeMillis - lastActiveTimeMillis;
                        long timeBetweenEvictionRunsMillis = this.getTimeBetweenEvictionRunsMillis();
                        if(timeBetweenEvictionRunsMillis <= 0L) {
                            timeBetweenEvictionRunsMillis = 60000L;
                        }
    
                        if(idleMillis < timeBetweenEvictionRunsMillis) {
                            break;
                        }
    
                        this.discardConnection(realConnection);
                    }
                }
            }
    
            if(this.isRemoveAbandoned()) {
                StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();
                poolableConnection.setConnectStackTrace(stackTrace);
                poolableConnection.setConnectedTimeNano();
                poolableConnection.setTraceEnable(true);
                Map var21 = this.activeConnections;
                synchronized(this.activeConnections) {
                    this.activeConnections.put(poolableConnection, PRESENT);
                }
            }
    
            if(!this.isDefaultAutoCommit()) {
                poolableConnection.setAutoCommit(false);
            }
    
            return poolableConnection;
        }
    
  • 这个连接泄露不会导致OOM,因为druid会去主动detroy这些未关闭的连接,也就是上面日志中的错误信息

  • 现在知道是有数据库连接未关闭,但是代码中并没有去管理数据库连接池,都是交给了Spring去管理的呢,而且不是每个数据库操作都会有问题,而是特定的数据库操作有问题

  • 开启debug日志

2018-01-23 21:08:35,760 DEBUG [org.springframework.data.redis.core.RedisConnectionUtils] - Opening RedisConnection
2018-01-23 21:08:35,761 DEBUG [org.springframework.data.redis.core.RedisConnectionUtils] - Closing Redis Connection
2018-01-23 21:08:35,762 DEBUG [org.mybatis.spring.SqlSessionUtils] - Creating a new SqlSession
2018-01-23 21:08:35,762 DEBUG [org.mybatis.spring.SqlSessionUtils] - SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5ba28a19] was not registered for synchronization because synchronization is not active
2018-01-23 21:08:35,765 DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] - Fetching JDBC Connection from DataSource
2018-01-23 21:08:35,765 DEBUG [org.mybatis.spring.transaction.SpringManagedTransaction] - JDBC Connection [com.taobao.tddl.matrix.jdbc.TConnection@24f6de0] will not be managed by Spring
2018-01-23 21:08:35,766 DEBUG [com.taobao.tddl.group.jdbc.TGroupConnection] -  [TDDL] dataSourceIndex=GroupIndex [index=0, failRetry=false], tddl version: 5.1.7
2018-01-23 21:08:35,810 DEBUG [org.mybatis.spring.SqlSessionUtils] - Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@5ba28a19]
2018-01-23 21:08:35,810 DEBUG [org.springframework.jdbc.datasource.DataSourceUtils] - Returning JDBC Connection to DataSource

这里接可以看出阿里的开源软件距离工业级还有距离,Spring的可以清楚的看到连接释放与返回,而Druid并没有

  • 因为这个是和特定的SQL有关系,所有看下具体的这个SQL操作

     @Options(statementType = StatementType.CALLABLE)
        @Insert("<script> " +  
                "</script>")
     int saveDemo(Demo demo);
    

    这个是之前人留下的,这种写法目前在项目组不是很常见了,没有实现代码与SQL语句分离,不是很提倡。
    这边的StatementType为Callable,看起来比奇怪,一般CallableStatement由于数据库存储过程的操作,显然这个语句不是这么调用存储过程。不知道前任为什么这么写,所以首先干掉了这个StatementType.CALLABLE参数。

  • 结果果然出错了,调用的时候报错,一个好笑的错误,没有使用auto generate id,却调用了。

    这个应该是MySQL 5.7 driver的一个bug,前任为了避免这个问题,使用CallableStatement绕过去了

    Caused by: Generated keys not requested. You need to specify Statement.RETURN_GENERATED_KEYS to Statement.executeUpdate() or Connection.prepareStatement().
    at com.taobao.tddl.repo.mysql.handler.PutMyHandlerCommon.handle(PutMyHandlerCommon.java:52)
    at com.taobao.tddl.executor.AbstractGroupExecutor.executeInner(AbstractGroupExecutor.java:59)
    at com.taobao.tddl.executor.AbstractGroupExecutor.execByExecPlanNode(AbstractGroupExecutor.java:40)
    at com.taobao.tddl.executor.TopologyExecutor.execByExecPlanNode(TopologyExecutor.java:59)
    at com.taobao.tddl.executor.MatrixExecutor.execByExecPlanNode(MatrixExecutor.java:282)
    
  • 所以先改成xml方式验证下,xml默认是PreparedStatement,然后看下是否还能发生错误

发现没有了,所以问题的原因就是CallableStatement造成的

#探索-druid连接管理#
虽然问题解决了,但是还是不知道druid是如何管理连接的,所以需要深入一点

  • mybatis
    首先项目中用到了Mybatis,Mybatis + jdbc的操作流程如下
    一个数据库操作取连接是在具体的sql执行时才去取的
    这里写图片描述

  • 引入 Spring-jdbc
    进行transaction 管理

    <bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
        <property name="dataSource" ref="dataSource"/>
    </bean>

    <tx:annotation-driven transaction-manager="transactionManager"/>

这时候连接池管理交给了SpringManagedTransaction

org.mybatis.spring.transaction.SpringManagedTransaction

    private Statement prepareStatement(StatementHandler handler, Log statementLog) throws SQLException {
        Connection connection = this.getConnection(statementLog);
        Statement stmt = handler.prepare(connection, this.transaction.getTimeout());
        handler.parameterize(stmt);
        return stmt;
    }

  • TDDL

TDDL是因为分库分表引入的,它本身依赖druid来做连接池管理
获取连接

在执行的时候TPreparedStatment,
重新包装了SQL,PreparedStatment
AutoCommitTransaction管理一个连接
getConnection,这时候Connection
获取的是TGroupConnection中createNewConnection

关闭连接
SqlSessionUtils.closeSqlSession
TConnection.close()
TConnectionWrapper.close()
DruidPooledConnection.close()
DruidPooledConnection.syncClose()
DruidPooledConnection.recycle() // 这个方法里面实际关闭了了druid的连接

public DruidPooledConnection getConnectionDirect(long maxWaitMillis) throws SQLException {
        int notFullTimeoutRetryCnt = 0;

        DruidPooledConnection poolableConnection;
        ...
        if(this.isRemoveAbandoned()) {
            StackTraceElement[] stackTrace = Thread.currentThread().getStackTrace();
            poolableConnection.setConnectStackTrace(stackTrace);
            poolableConnection.setConnectedTimeNano();
            poolableConnection.setTraceEnable(true);
            Map var21 = this.activeConnections;
            synchronized(this.activeConnections) {
                // 将一个活跃connection
                this.activeConnections.put(poolableConnection, PRESENT);
            }
        }

        if(!this.isDefaultAutoCommit()) {
            poolableConnection.setAutoCommit(false);
        }

        return poolableConnection;
    }

remove abandoned

  public int removeAbandoned() {
        int removeCount = 0;
        long currrentNanos = System.nanoTime();
        List<DruidPooledConnection> abandonedList = new ArrayList();
        // activeConnections这个类变量存储了未关闭的连接
        Map var5 = this.activeConnections;
        synchronized(this.activeConnections) {
            // 获取这边的值
            Iterator iter = this.activeConnections.keySet().iterator();

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

        if(abandonedList.size() > 0) {
            Iterator var14 = abandonedList.iterator();
            while(true) {
                DruidPooledConnection pooledConnection;
                do {
                    while(true) {
                        if(!var14.hasNext()) {
                            return removeCount;
                        }

                        pooledConnection = (DruidPooledConnection)var14.next();
                        synchronized(pooledConnection) {
                            if(!pooledConnection.isDisable()) {
                                break;
                            }
                        }
                    }

                    JdbcUtils.close(pooledConnection);
                    pooledConnection.abandond();
                    ++this.removeAbandonedCount;
                    ++removeCount;
                } while(!this.isLogAbandoned());

                StringBuilder buf = new StringBuilder();
                buf.append("abandon connection, owner thread: ");
                LOG.error(buf.toString());
            }
        } else {
            return removeCount;
        }
    }


可以看到修正的sql操作是有关闭的,但是CallableStatement没有,所以有未关闭的连接
这里写图片描述

欢迎加入Java互联网技术交流群 392669336,和方丈交流各类java问题
Java互联网技术
关注【方丈的寺院】,第一时间收到文章的更新,与方丈一起开始技术修行之路
在这里插入图片描述

#参考#
http://blog.csdn.net/luanlouis/article/details/40422941

http://blog.csdn.net/luanlouis/article/details/37671851

https://www.jianshu.com/p/ec40a82cae28

http://blog.csdn.net/u013476542/article/details/53256610

文章最后发布于: 2018-01-28 20:38:45
展开阅读全文

没有更多推荐了,返回首页

©️2019 CSDN 皮肤主题: Age of Ai 设计师: meimeiellie

分享到微信朋友圈

×

扫一扫,手机浏览