一个由session.close()引发的血案

最新推荐文章于 2025-07-08 17:01:12 发布

sunla198910

最新推荐文章于 2025-07-08 17:01:12 发布

阅读量2w

点赞数 8

CC 4.0 BY-SA版权

分类专栏： java 文章标签： java mybatis

本文链接：https://blog.youkuaiyun.com/java_magicsun/article/details/60134805

java 专栏收录该内容

22 篇文章

订阅专栏

本文分析了一个使用MyBatis框架项目的连接池异常问题，详细讲述了如何定位到未关闭SqlSession导致的问题，并深入探讨了MyBatis内部实现，最终解决了连接池中出现关闭连接异常的情况。

最近接手了个新项目, 项目一直存在使用已关闭的连接异常问题.

上图:

项目环境:

1.使用的是 mybatis-3.2.6.jar orm框架

2.使用mybatis 默认提供的 pooled 连接池

配置详见:

http://www.cnblogs.com/caoyc/p/5574827.html

问题分析:

1. 问题猜测:

因为公司连接mysql 中间有层F5的代理,考虑是不是mysql的wait_timeout 已过期,但是F5的与应用的连接还是active状态

解决方案:

<property name="poolMaximumActiveConnections" value="20"/>
<property name="poolPingQuery" value="SELECT NOW()" />
<property name="poolPingEnabled" value="true" />
<!-- 设置获取连接超时时间 -->
<property name="poolTimeToWait" value="1000" />
<!-- 设置连接最大检测时间 -->
<property name="poolMaximumCheckoutTime" value="1000"/>
<!-- 配置poolPingQuery多次时间被用一次 -->
<property name="poolPingConnectionsNotUsedFor" value="500"/>

修改配置文件中 poolPingConnectionsNotUsedFor 参数使其小于F5的time_out 但问题依旧

2.问题猜测:

线程池实现有bug,导致有极端情况没有判断出连接是否可用,而继续存活于idleConnections 池中

解决方案:

跟踪源码,打开日志等级为debug.

通过跟踪有问题的connection 的hashcode (554300411) 发现在

其中一段时间中没有Returned connetion ..

可以发现正常的checkout - return 都相差不到100ms

而从这条日志开始 checkout 到下一次return 相隔了有5分钟!!!!!

继续排查

cat xxx.log |grep "[03-02 19:12:36 103 DEBUG] [pool-37-thread-1] datasource.pooled.PooledDataSource.popConnection 369 - Checked out connection 554300411 from pool." -A 50 --color

发现执行了这方法.就再也没有在5分钟之内return poll 了。

开始怀疑是慢sql 导致的。但是日志可以看出整个查询也就消耗了4ms

跟踪代码吧。

SqlSession session = sqlSessionFactory.openSession(true);
....
 catch (Exception e) {
            log.error("xxxx", e);
            response.setResponseCode(ResponseCode.SYSTEM_ERROR.getCode());
            response.setErrorMessage("xxxx");
            throw e;
        }

没有调用 session.close() !!!!!!!!!!!!

修改掉。好了。问题fix了。

那么问题来了。为什么没有调用session.close()会出现这个问题呢?

================我们来看下 mybatis对于close() 干了什么 =====================

public class DefaultSqlSession implements SqlSession {
 
public void close() {
    try {
      /** 关键 */
      executor.close(isCommitOrRollbackRequired(false));
      dirty = false;
    } finally {
      ErrorContext.instance().reset();
    }
  }
}

public abstract class BaseExecutor implements Executor {

public void close(boolean forceRollback) {
    try {
      try {
        rollback(forceRollback);
      } finally {
        /** 关键 */
        if (transaction != null) transaction.close();
      }
    } catch (SQLException e) {
      // Ignore.  There's nothing that can be done at this point.
      log.warn("Unexpected exception on closing transaction.  Cause: " + e);
    } finally {
      transaction = null;
      deferredLoads = null;
      localCache = null;
      localOutputParameterCache = null;
      closed = true;
    }
  }
}

public class JdbcTransaction implements Transaction {
 
public void close() throws SQLException {
    if (connection != null) {
      resetAutoCommit();
      if (log.isDebugEnabled()) {
        log.debug("Closing JDBC Connection [" + connection + "]");
      }
      /** 关键 */
      connection.close();
    }
  }
}

找到关键了。最终执行了 connection.close(). 那 connection 是由谁生成的呢？

我们从头开始.

SqlSession session = sqlSessionFactory.openSession(false);

public class DefaultSqlSessionFactory implements SqlSessionFactory {
 
  private SqlSession openSessionFromDataSource(ExecutorType execType, TransactionIsolationLevel level, boolean autoCommit) {
    Transaction tx = null;
    try {
      /** 关键 */
      final Environment environment = configuration.getEnvironment();
      final TransactionFactory transactionFactory = getTransactionFactoryFromEnvironment(environment);
      /** 关键 */
      tx = transactionFactory.newTransaction(environment.getDataSource(), level, autoCommit);
      final Executor executor = configuration.newExecutor(tx, execType);
      return new DefaultSqlSession(configuration, executor, autoCommit);
    } catch (Exception e) {
      closeTransaction(tx); // may have fetched a connection so lets call close()
      throw ExceptionFactory.wrapException("Error opening session.  Cause: " + e, e);
    } finally {
      ErrorContext.instance().reset();
    }
  }
}

这两段代码就决定了最终使用什么样的datasource

由于前面配置以及告知使用 <dataSource type="POOLED"> 所以我们看下 pooledDataSource的实现

/**
* 该类实现了动态代理接口
*/
class PooledConnection implements InvocationHandler {
 
/** 构造器中 注意有个proxyConnection 代理了Connection 使执行connection任何方法
 *  都会执行invoke方法 
 */
 public PooledConnection(Connection connection, PooledDataSource dataSource) {
    this.hashCode = connection.hashCode();
    this.realConnection = connection;
    this.dataSource = dataSource;
    this.createdTimestamp = System.currentTimeMillis();
    this.lastUsedTimestamp = System.currentTimeMillis();
    this.valid = true;
    this.proxyConnection = (Connection) Proxy.newProxyInstance(Connection.class.getClassLoader(), IFACES, this);
  }

/**
 * invoke中对close做了特殊处理,是close调用时 执行的是pushConnection操作
 */
public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
    String methodName = method.getName();
    if (CLOSE.hashCode() == methodName.hashCode() && CLOSE.equals(methodName)) {
      dataSource.pushConnection(this);
      return null;
    } else {
      try {
        if (!Object.class.equals(method.getDeclaringClass())) {
          // issue #579 toString() should never fail
          // throw an SQLException instead of a Runtime
          checkConnection();
        }
        return method.invoke(realConnection, args);
      } catch (Throwable t) {
        throw ExceptionUtil.unwrapThrowable(t);
      }
    }
  }  
}

public class PooledDataSource implements DataSource {

/** 从 空闲的连接池中获取可用连接 (省部分代码)*/
private PooledConnection popConnection(String username, String password) throws SQLException {
    while (conn == null) {
      synchronized (state) {
        if (state.idleConnections.size() > 0) {
          // Pool has available connection
          conn = state.idleConnections.remove(0);
            ..............
        } else {
          // Pool does not have available connection
          if (state.activeConnections.size() < poolMaximumActiveConnections) {
            // Can create new connection
            conn = new PooledConnection(dataSource.getConnection(), this);
            @SuppressWarnings("unused")
            //used in logging, if enabled
            Connection realConn = conn.getRealConnection();
            if (log.isDebugEnabled()) {
              log.debug("Created connection " + conn.getRealHashCode() + ".");
            }
          } else {
            // Cannot create new connection
            ............
            if (longestCheckoutTime > poolMaximumCheckoutTime) {
              // Can claim overdue connection
              .......
              state.activeConnections.remove(oldestActiveConnection);
              if (!oldestActiveConnection.getRealConnection().getAutoCommit()) {
                oldestActiveConnection.getRealConnection().rollback();
              }
              /** 这里默认构造器有个小坑 会重置 LastUsedTimestamp  */
              conn = new PooledConnection(oldestActiveConnection.getRealConnection(), this);
              oldestActiveConnection.invalidate();
            }
          }
        }
        if (conn != null) {
          if (conn.isValid()) {
            if (!conn.getRealConnection().getAutoCommit()) {
              conn.getRealConnection().rollback();
            }
            conn.setConnectionTypeCode(assembleConnectionTypeCode(dataSource.getUrl(), username, password));
            conn.setCheckoutTimestamp(System.currentTimeMillis());
            conn.setLastUsedTimestamp(System.currentTimeMillis());
            state.activeConnections.add(conn);
          } else {
            if (log.isDebugEnabled()) {
              log.debug("A bad connection (" + conn.getRealHashCode() + ") was returned from the pool, getting another connection.");
            }
            ...........
            conn = null;
            ...........
          }
        }
      }
    }
    .............
    }
    return conn;
  }

/** 把激活连接从 活动连接池中移除 放回到 空闲连接池中 */
protected void pushConnection(PooledConnection conn) throws SQLException {

    synchronized (state) {
      state.activeConnections.remove(conn);
      ..........
      state.idleConnections.add(newConn);
      ............
      }
  }
  
}

问题很明显了。如果不调用close 方法

当前连接不会释放回空闲连接池中,一直存在于活动连接池中, 当空闲连接池耗光之后 pop 会从 活动连接池 中选取第一个连接

返回给应用.而这个时候这个连接从最后次使用到拿出来可能过了 好几分钟了。就真的是个处于关闭状态的连接了