HikariCP 线程没有被释放 - 如何排除故障？

Posted 2023-04-12

【中文标题】HikariCP 线程没有被释放 - 如何排除故障？

【英文标题】：HikariCP threads not being freed up - How to troubleshoot?

【发布时间】：2016-05-12 23:42:05

【问题描述】：

我正在尝试将应用程序从 Hibernate 3.6.10.Final（使用 c3p0 连接池）迁移到 4.3.11.Final（对于 CP，HikariCP-2.4.3）。

自迁移以来没有任何应用程序逻辑发生变化，但我认为线程现在没有被重用。

任何建议从哪里开始解决这个问题？

老persistence.properties：

hibernate.connection.url=jdbc:mysql://localhost:3306/%S?useDynamicCharsetInfo=false
hibernate.connection.driver_class=org.mariadb.jdbc.Driver
hibernate.connection.password=XXXXX
hibernate.connection.username= XXXXX
hibernate.dialect=org.hibernate.dialect.MySQL5InnoDBDialect
  hibernate.connection.provider_class=org.hibernate.connection.C3P0ConnectionProvider
hibernate.c3p0.min_size=5
hibernate.c3p0.max_size=100
hibernate.c3p0.timeout=200
hibernate.c3p0.checkoutTimeout=10000
hibernate.c3p0.maxStatementsPerConnection=40
hibernate.c3p0.idle_test_period=100
hibernate.c3p0.numHelperThreads=3
preferredTestQuery=SELECT 1
unreturnedConnectionTimeout=1080
debugUnreturnedConnectionStackTraces=false

新的persistence.properties 将 c3p0 替换为：

hibernate.connection.provider_class=com.zaxxer.hikari.hibernate.HikariConnectionProvider
hibernate.hikari.dataSource.url=jdbc:mysql://localhost:3306/%S?useDynamicCharsetInfo=false
hibernate.hikari.dataSource.user= XXXXX
hibernate.hikari.dataSource.password= XXXXX
hibernate.hikari.maximumPoolSize=100

但是应用程序运行了一段时间，然后所有线程似乎都处于活动状态并且在我重新启动应用程序之前没有释放，例如

2016-05-12 16:36:02,915 DEBUG [Hikari housekeeper (pool HikariPool-0)] hikari.pool.HikariPool.logPoolState():383 - After cleanup    pool HikariPool-0 stats (total=100, active=100, idle=0, waiting=2)

我看到这些错误：

DEBUG [Hikari housekeeper (pool HikariPool-0)] hikari.pool.HikariPool.logPoolState():383 - After cleanup    pool HikariPool-0 stats (total=100, active=100, idle=0, waiting=5)
Caused by: java.sql.SQLTransientConnectionException: HikariPool-0 - Connection is not available, request timed out after 30000ms.
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:195) ~[HikariCP-2.4.3.jar:?]
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) ~[HikariCP-2.4.3.jar:?]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:83) ~[HikariCP-2.4.3.jar:?]
    at com.zaxxer.hikari.hibernate.HikariConnectionProvider.getConnection(HikariConnectionProvider.java:106) ~[HikariCP-2.4.3.jar:?]
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1471) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
    at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:61) ~[hibernate-entitymanager-4.3.11.Final.jar:4.3.11.Final]
    ... 16 more

或者我看到了泄漏检测：

2016-05-13 09:48:06,819  WARN [Hikari housekeeper (pool HikariPool-0)] hikari.pool.ProxyLeakTask.run():87 - Connection leak detection triggered for connection org.mariadb.jdbc.MySQLConnection@4f7e08a, stack trace follows
java.lang.Exception: Apparent connection leak detected
        at com.zaxxer.hikari.hibernate.HikariConnectionProvider.getConnection(HikariConnectionProvider.java:106) ~[HikariCP-2.4.3.jar:?]
        at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:63) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:162) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:186) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:160) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1885) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1862) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1839) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.doQuery(Loader.java:910) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:355) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.doList(Loader.java:2554) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.doList(Loader.java:2540) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2370) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.Loader.list(Loader.java:2365) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:497) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:387) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:236) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1300) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103) ~[hibernate-core-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:573) ~[hibernate-entitymanager-4.3.11.Final.jar:4.3.11.Final]
        at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:449) ~[hibernate-entitymanager-4.3.11.Final.jar:4.3.11.Final]
// SNIP

代码看起来有点像这样：

import javax.persistence.EntityManager;
import javax.persistence.EntityTransaction;
//SNIP
protected List executeQuery(final String query) 

    final EntityManager entityManager = getEntityManager();
    try 
        return entityManager.createQuery(query).getResultList();
     finally 
        entityManager.clear();
    

【参考方案1】：

C3P0 正在关闭未返回池的连接，使用： 未返回连接超时=1080 debugUnreturnedConnectionStackTraces=false

HikariCP 不提供此类属性。您必须确保“实体管理器”正在关闭从池中借用的连接。

【讨论】：

我的 entityManager 被缓存了，并且存活了很长时间；在每次查询之后，我们都会执行 entityManager.clear();你是说这很糟糕，我们应该有短暂的 entityManager 吗？在 ***.com/questions/3393186/... 中提到的长期存在的那些我曾预计从应用程序逻辑的角度来看更改 c3p0->hikari 是不可见的，但可能我错了。

一般情况下，最好尽快释放资源（如连接），尤其是在资源并发且频繁使用的情况下。然而，HikariCP 选择不关闭“泄漏”连接是“正确的”恕我直言。我不是“实体经理”方面的专家，但使用 close 而不是 clear: finally entityManager.close();

感谢@nitin，现在将应用程序更改为使用只有在工作完成后才具有生命周期的 EM，并在工作完成后关闭它们，并且 Hikari 池的行为符合预期。