Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cleanup of broken connections not working (2.3.0-rc3) #220

Closed
dfex55 opened this issue Dec 23, 2014 · 10 comments
Closed

Cleanup of broken connections not working (2.3.0-rc3) #220

dfex55 opened this issue Dec 23, 2014 · 10 comments
Labels

Comments

@dfex55
Copy link

dfex55 commented Dec 23, 2014

Version 2.3.0-rc3 (and some previous snapshots) of HikariCP does not cleanup broken connections, although they seem to be recognized as broken.
The broken connections stay in the pool. If many connections are broken, the pool will be filled till maximum pool size is reached. After the max size is reached, no new connections will be created by calling getConnection().

How to test:
Use the following configuration:

    HikariConfig dsConfig = new HikariConfig();
    dsConfig.setDataSourceClassName("org.postgresql.ds.PGSimpleDataSource");
    dsConfig.addDataSourceProperty("socketTimeout", 1);
    dsConfig.setMaximumPoolSize(5);
    dsConfig.setMinimumIdle(0);
    dsConfig.setIdleTimeout(1000);
    dsConfig.setConnectionTimeout(1000);

Every query longer than one second will be terminated by the postgres jdbc driver with an exception.

  • 5 times: call getConnection and execute a query which will take longer than one second.
  • call getConnection()

Expected behavior should be:
The last getConnection() call returns a valid connection

Here is what happens with 2.3.0-rc3:
five times:

Connection org.postgresql.jdbc4.Jdbc4Connection@66c5746f (app [pool]) marked as broken because of SQLSTATE(08006), ErrorCode(0).
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_65]
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) ~[postgresql-9.3-1102.jdbc41.jar:na]
Wrapped by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:281) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:304) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementProxy.executeQuery(PreparedStatementProxy.java:52) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementJavassistProxy.executeQuery(PreparedStatementJavassistProxy.java) [HikariCP-java6-2.3.0-rc3.jar:na]




Connection org.postgresql.jdbc4.Jdbc4Connection@66c5746f (app [pool]) marked as broken because of SQLSTATE(08003), ErrorCode(0).
org.postgresql.util.PSQLException: This connection has been closed.
    at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:843) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc3.AbstractJdbc3Connection.prepareStatement(AbstractJdbc3Connection.java:275) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Connection.prepareStatement(AbstractJdbc2Connection.java:317) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionProxy.prepareStatement(ConnectionProxy.java:256) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionJavassistProxy.prepareStatement(ConnectionJavassistProxy.java) [HikariCP-java6-2.3.0-rc3.jar:na]

After that in the DEBUG log:

Before cleanup pool stats app [pool] (total=5, inUse=5, avail=0, waiting=0)

After cleanup pool stats app [pool] (total=5, inUse=5, avail=0, waiting=0)

If getConnection() is called now, the following exception will be thrown:

java.sql.SQLException: Timeout after 1011ms of waiting for a connection.
    at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:205) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:91) ~[HikariCP-java6-2.3.0-rc3.jar:na]

This state is permanent. The connection pool will not recover itself over time!

Trying the same with HikariCP 2.2.5 shows the expected behavior:

five times:

java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_65]
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) ~[postgresql-9.3-1102.jdbc41.jar:na]
Wrapped by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:281) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:304) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementProxy.executeQuery(PreparedStatementProxy.java:52) ~[HikariCP-java6-2.2.5.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementJavassistProxy.executeQuery(PreparedStatementJavassistProxy.java) ~[HikariCP-java6-2.2.5.jar:na]
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeSelect(DatabaseAccessor.java:931) ~[eclipselink_2.3.2.v20111125-r10461.jar:2.3.2.v20111125-r10461]
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:607) ~[eclipselink_2.3.2.v20111125-r10461.jar:2.3.2.v20111125-r10461]

The DEBUG log shows:

Before cleanup pool stats app [pool] (total=0, inUse=0, avail=0, waiting=0)

After cleanup pool stats app [pool] (total=0, inUse=0, avail=0, waiting=0)

Note: the pool is empty -> good

A call to getConnection() works as expected.

@brettwooldridge
Copy link
Owner

If you enable debug logging, after the " marked as broken because of SQLSTATE(08006), ErrorCode(0)" exception, do you get a log that says something like "Connection returned to pool app [pool] is broken or evicted. Closing connection."?

@brettwooldridge
Copy link
Owner

Any update on this issue? I'm away from my computer until this coming Friday, but I can try to reproduce the issue then.

@dfex55
Copy link
Author

dfex55 commented Dec 29, 2014

Sorry for the late response.

With HikariCP 2.2.5 there is an additional WARN and DEBUG:

WARN  com.zaxxer.hikari.proxy.ConnectionProxy 
Connection org.postgresql.jdbc4.Jdbc4Connection@442692f8 (app [pool]) marked as broken because of SQLSTATE(08003), ErrorCode(0).
org.postgresql.util.PSQLException: This connection has been closed.
    at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:843) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:860) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionProxy.rollback(ConnectionProxy.java:336) ~[HikariCP-java6-2.2.5.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionJavassistProxy.rollback(ConnectionJavassistProxy.java) [HikariCP-java6-2.2.5.jar:na]
… 
    at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:127)
DEBUG com.zaxxer.hikari.pool.HikariPool 
Connection returned to pool app [pool] is broken or evicted.  Closing connection.

Using HikariCP 2.3.0 RC3 there is a WARN when doing a rollback after the failed query.

WARN  org.eclipse.persistence.logging.default 
org.postgresql.util.PSQLException: This connection has been closed.
    at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:843) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:860) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionProxy.rollback(ConnectionProxy.java:306) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionJavassistProxy.rollback(ConnectionJavassistProxy.java) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicRollbackTransaction(DatabaseAccessor.java:1578)

A log message about returning the connection back to the pool (and closing) is missing.

I am using eclipselink to reproduce the issue in a dev-version of our app. It seems that eclipselink is never returning the connection, because the connection is reported as closed and is actually closed (no more connections visible to postgres). The pool instead reports all connections are in use.

Just a note:
Maybe a new error handling in the HikariCP (e.g. a proxy) instantly closes the connection after an exception occurs, but not removes the connection from the pool?!
In my case, eclipselink cannot return/close/rollback the connection, because it is already closed. Therefore all connection slots will remain blocked in the pool.

btw: the connection leak detection gets also triggered if enabled

@dfex55
Copy link
Author

dfex55 commented Dec 29, 2014

this might also be interesting:
in 2.3.0 RC3:

WARN  com.zaxxer.hikari.proxy.ConnectionProxy 
Connection org.postgresql.jdbc4.Jdbc4Connection@1d1ebc3 (app [pool]) marked as broken because of SQLSTATE(08006), ErrorCode(0).
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:152) ~[na:1.7.0_65]
    at java.net.SocketInputStream.read(SocketInputStream.java:122) ~[na:1.7.0_65]
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:143) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:112) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:71) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:282) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1741) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) ~[postgresql-9.3-1102.jdbc41.jar:na]
Wrapped by: org.postgresql.util.PSQLException: An I/O error occurred while sending to the backend.
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:281) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:419) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:304) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementProxy.executeQuery(PreparedStatementProxy.java:52) ~[HikariCP-java6-2.3.0-rc3.jar:na]
    at com.zaxxer.hikari.proxy.PreparedStatementJavassistProxy.executeQuery(PreparedStatementJavassistProxy.java) [HikariCP-java6-2.3.0-rc3.jar:na]
…
    at org.eclipse.persistence.internal.jpa.EJBQueryImpl.executeReadQuery(EJBQueryImpl.java:485) 
    at org.eclipse.persistence.internal.jpa.EJBQueryImpl.getResultList(EJBQueryImpl.java:742) 

The log message "marked as broken because of SQLSTATE" appears when executing the query.

in 2.2.5

WARN  com.zaxxer.hikari.proxy.ConnectionProxy 
Connection org.postgresql.jdbc4.Jdbc4Connection@442692f8 (app [pool]) marked as broken because of SQLSTATE(08003), ErrorCode(0).
org.postgresql.util.PSQLException: This connection has been closed.
    at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:843) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:860) ~[postgresql-9.3-1102.jdbc41.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionProxy.rollback(ConnectionProxy.java:336) ~[HikariCP-java6-2.2.5.jar:na]
    at com.zaxxer.hikari.proxy.ConnectionJavassistProxy.rollback(ConnectionJavassistProxy.java) [HikariCP-java6-2.2.5.jar:na]
… 
    at org.eclipse.persistence.internal.jpa.transaction.EntityTransactionImpl.rollback(EntityTransactionImpl.java:127)

The message gets logged when rollback is called, not when the query fails. Maybe that change causes the error/incompatibility?

@brettwooldridge
Copy link
Owner

Interesting. Good clues.

brettwooldridge added a commit that referenced this issue Jan 2, 2015
… should reflect HikariCP's understanding of the closed state rather than delegating to the driver.
@abdelgadir
Copy link

Hi,
with hikari version 2.2.5, I am having a similar issue with leaking connections with postgres. the leak detection stack trace is as follows

2015-01-06 09:21:36.762 [Hikari Housekeeping Timer (pool HikariPool-0)] WARN com.zaxxer.hikari.util.LeakTask - Connection leak detection triggered, stack trace follows
java.lang.Exception: null
at org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider.getConnection(InjectedDataSourceConnectionProvider.java:70) ~[hibernate-entitymanager-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:301) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:214) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:157) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:160) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1351) ~[hibernate-core-4.2.8.Final.jar:4.2.8.Final]
at org.hibernate.ejb.TransactionImpl.begin(TransactionImpl.java:59) ~[hibernate-entitymanager-4.2.8.Final.jar:4.2.8.Final]
at org.springframework.orm.jpa.DefaultJpaDialect.beginTransaction(DefaultJpaDialect.java:70) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:61) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:378) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:372) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:417) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:255) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) ~[spring-aop-3.2.11.RELEASE.jar:3.2.11.RELEASE]
at com.sun.proxy.$Proxy251.updateAccount(Unknown Source) ~[na:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:188) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:104) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:204) ~[cxf-rt-frontend-jaxrs-2.7.11.jar:2.7.11]
at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:101) ~[cxf-rt-frontend-jaxrs-2.7.11.jar:2.7.11]
at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:94) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:272) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[cxf-api-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:241) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:248) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:222) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:153) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:286) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:206) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:644) ~[servlet-api.jar:na]
at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:262) ~[cxf-rt-transports-http-2.7.11.jar:2.7.11]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[catalina.jar:8.0.15]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-websocket.jar:8.0.15]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[catalina.jar:8.0.15]
at com.ukfuels.velos.services.bl.internalinterface.impl.security.ResponseDebugFilter.doFilter(ResponseDebugFilter.java:31) ~[ResponseDebugFilter.class:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) ~[catalina.jar:8.0.15]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) ~[catalina.jar:8.0.15]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) ~[catalina.jar:8.0.15]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) ~[catalina.jar:8.0.15]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) ~[catalina.jar:8.0.15]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:537) ~[catalina.jar:8.0.15]
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085) ~[tomcat-coyote.jar:8.0.15]
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:658) ~[tomcat-coyote.jar:8.0.15]
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222) ~[tomcat-coyote.jar:8.0.15]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1556) ~[tomcat-coyote.jar:8.0.15]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1513) ~[tomcat-coyote.jar:8.0.15]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_65]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-util.jar:8.0.15]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]

I am using spring and hibernate. My beans are transactional so there is a transaction boundary (via @transactional annotation).

The only Hikari properties I am setting explicitly are below:
jdbc.maximumPoolSize=100
jdbc.leakDetectionThreshold=60000

my spring config for datasource and hikari are below:

<bean id="hikariConfig" class="com.zaxxer.hikari.HikariConfig">
    <property name="jdbcUrl" value="${jdbc.url}"/>
    <property name="username" value="${jdbc.user}"/>
    <property name="password" value="${jdbc.password}"/>
    <property name="maximumPoolSize" value="${jdbc.maximumPoolSize}"/>
    <property name="driverClassName" value="org.postgresql.Driver"/>
    <property name="leakDetectionThreshold" value="${jdbc.leakDetectionThreshold}"/>
</bean>

<bean id="dataSource" class="com.zaxxer.hikari.HikariDataSource" destroy-method="shutdown">
    <constructor-arg ref="hikariConfig"/>
</bean>

is there anything I can do to instruct hikari to recycle the broken/leaked connections so that I don't have to keep restarting the system every few days as currently the case. I tried to trace the source of leak but unable to locate it since I am not acquiring or releasing any connections myself (it is all hibernate and spring doing the work)

@brettwooldridge
Copy link
Owner

@abdelgadir this looks unrelated to the source of this bug, which was caused by the removal of an overriden method in our Connection proxy in the 2.3.0 release candidate, but should not be an issue in 2.2.5.

It looks like you've run into a Hibernate bug, fixed in 4.2.16, see bug HHH-9312 in the release notes for Hibernate 4.2.16.

Additionally, release 4.2.15 introduced a connection provider for HikariCP, which I would highly recommend over the injected datasource connection provider you are using now. See our wiki for several ways to configure HikariCP with Spring+Hibernate.

@brettwooldridge
Copy link
Owner

@dfex55 2.3.0-rc4 has been published to the sonatype staging repository, can you give it a try?

@dfex55
Copy link
Author

dfex55 commented Jan 7, 2015

2.3.0-rc4 fixed the issue. Thank you.

@abdelgadir
Copy link

thank you very much for quick response. I will take a look into the hibernate issues and will look to upgrade both libraries

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants