I am trying to migrate an application from Hibernate 3.6.10.Final (with c3p0 Connection Pooling) to 4.3.11.Final (and HikariCP-2.4.3 for CP).
No application logic has changed since migrating but threads now not getting reused I think.
Any advice where to begin to troubleshoot this ?
The old 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
The new persistence.properties replaces c3p0 with :
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
But the app runs for a while then all threads appear to become active and not freed up till I restart the app, e.g.
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)
I see these errors:
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
Or with leak detection on I see :
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
The code looks a bit like this:
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();
}
}
C3P0 is closing connections that are not returned to pool using: unreturnedConnectionTimeout=1080 debugUnreturnedConnectionStackTraces=false
HikariCP does NOT provide such properties. you have to make sure that 'entity manager' is closing connection borrowed from pool.