JVM内存分析：数据库连接池耗尽

提要

由于数据库连接十分耗时，采取即需即连的方式会导致应用响应缓慢，因此，在Java应用中均采用数据库连接池统一维护一定数量的Connection对象，连接池中的Connection均保持与数据库的长连接，这样，该连接将随时可用，从而提高应用响应和处理速度。

但是，在普遍的使用不当的情形中，最多的问题便是没有及时释放连接，这里的释放是指将Connection对象归还连接池。若连接未被释放，则连接池将被很快耗尽（Exhausted），从而无法提供新的连接，最终导致应用不能进行数据库操作，并在尝试获取新的连接时出现以下异常：

...
Caused by: org.hibernate.exception.GenericJDBCException: Could not open connection
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:221)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157)
    at org.hibernate.internal.SessionImpl.connection(SessionImpl.java:550)
    at org.springframework.orm.hibernate4.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:426)
    ... 9 more
Caused by: org.apache.commons.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
    at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114)
    at org.apache.commons.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
    at org.hibernate.service.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:141)
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:292)
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214)
    ... 12 more
Caused by: java.util.NoSuchElementException: Timeout waiting for idle object
    at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:1174)
    at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:106)
    ... 16 more

案例分析

有关JVM内存转储方式的说明见JVM内存分析：Tomcat内存泄漏。

在本案例应用（约定称为「应用A」）的使用过程中偶尔会在前端弹出Timeout waiting for idle object的异常提示框。经过查看完整的异常堆栈（看上面）可发现，异常发生在从连接池获取Connection时，在对GenericObjectPool源码分析后可初步确定是因为连接池已满而无法分配新的Connection造成的。

为进一步确认该问题，将应用A的内存转储（sudo -u tomcat jmap -dump:format=b,file=heap-dump.bin <java_pid>）并通过Eclipse Memory Analyzer - MAT对其内存进行分析。

点击工具栏中的OQL图标，这里需要通过OQL进行一些复杂的过滤查询（OQL：SELECT OBJECTS ds FROM org.apache.commons.dbcp.BasicDataSource ds）：

OQL的语法可从MAT的Help -> Help Contents菜单中进入帮助手册查询到；

org.apache.commons.dbcp.BasicDataSource为应用中使用的DataSource的实现类，其内部引用org.apache.commons.dbcp.PoolingDataSource，并在PoolingDataSource中负责从连接池申请新的连接；

从图中可以看到，连接池org.apache.commons.pool.impl.GenericObjectPool的_numActive为749，而在应用中为其分配的最大活跃连接数（maxActive）为750。因此，可以进一步确定连接池的确已达到分配上限，在并发情况下将不会再分配更多连接，从而导致等待超时并抛出异常。

再看看内存中是否存在未被释放的MySQL连接。

由于MAT默认不分析unreachable对象，所以，在开始前需通过其自带的工具ParseHeapDump.sh（或ParseHeapDump.bat）分析不可达对象：

1 2	# 运行该命令前需删除dump文件所在目录中由MAT生成的分析文件 $ ParseHeapDump.sh -keep_unreachable_objects heap-dump.bin

点击MAT的菜单File -> Open Heap Dump选择文件heap-dump.bin载入转储分析文件，然后，通过OQL（SELECT cn, cn.isClosed, cn.io.mysqlConnection, cn.io.mysqlConnection.closed FROM INSTANCEOF com.mysql.jdbc.JDBC4Connection cn）得到MySQL Connection对象如下：

点击工具栏中的分组图标可按照Class Loader对结果进行分组；
在MySQL驱动中的Connection所引用的相关对象为：

com.mysql.jdbc.JDBC4Connection#io:com.mysql.jdbc.MysqlIO

com.mysql.jdbc.MysqlIO#mysqlConnection:java.net.Socket

java.net.Socket#closed:boolean

可以发现，在36个连接中仅有2个是正常关闭的，其余的Connection未被关闭，但对应的Socket连接却处于关闭状态。这里可以假设出以下两种可能的情形：

Connection在使用时出现网络中断，导致Socket非正常关闭；
Connection在使用后未被正常关闭，并且在某个时刻发生了Socket连接中断；

对于第一种情形，Socket的异常关闭势必会抛出异常，并最终在使用方拦截到该异常并关闭Connection，而这里的Connection为非关闭状态，说明使用方并未准确做资源的释放处理。第二种情形，自然也是因为资源未被及时释放了。

因此，Connection没有被及时、准确地释放是相当肯定的事情了。

但这里依然有个疑问，为啥连接池里记录分配的连接为749，而实际查到的Connection对象只有30多个，其余的哪儿去了？

针对上述问题，限于基本功的问题，目前还没有确切的定论，但大致可推断是MySQL驱动中的com.mysql.jdbc.AbandonedConnectionCleanupThread对弱引用的com.mysql.jdbc.JDBC4Connection对象做了资源主动回收处理：

com.mysql.jdbc.NonRegisteringDriver.ConnectionPhantomReference为虚引用类java.lang.ref.PhantomReference的扩展类，其将在java.lang.ref.Reference.ReferenceHandler#run中等待JVM启动GC时进行清理活动。

Java引用相关的知识可阅读详解java.lang.ref包中的4种引用。

既然得到了看似很有道理的分析结论，那就应该有方法复现当前的问题。

首先，通过IDE工具查找应用中主动获取Connection对象而未释放的代码位置，最终找出以下几处：

xx/xx/xx/XxQueryImpl.java @r74605: L357, L1607
…

经过调用分析后，可找到以下几个相关的Web API以用于复现验证：

/a/xx/queryXx.mvc
/a/xx/countXx.mvc
…

需要注意的是，一般MySQL服务端会限定并发连接数，为了快速复现当前问题，可通过以下语句调整MySQL的默认最大连接数（重启后将失效）：

1 2	-- 查看默认配置： show variables like '%connect%'; SET GLOBAL max_connections = 850;

在登录应用A后，在浏览器控制台中执行以下代码便可复现最开始提到的异常问题：

var ctx = '/a';
var urls = [
    ctx + '/xx/queryXx.mvc',
    ctx + '/xx/countXx.mvc'
];
var waitTime = 0.1 * 1000;

function doRequest(urls, index) {
    if (!urls || urls.length === 0) return;

    var i = index || 0;
    var url = urls[0];
    $.ajax({url: url, success: function () {
        console.log(i, url, arguments);
        setTimeout(function() {
            doRequest(urls.slice(1), i + 1);
        }, waitTime);
    }});
}

var requestCount = 800;
var requestURLs = [];
for (var i = 0; i < requestCount / urls.length; i++) {
    requestURLs = requestURLs.concat(urls);
}
doRequest(requestURLs);