HikariCP - connection is not available

Asked 6/10, 2015 at 11:14 Answered 13/1 at 16:36

Solved hibernate postgresql spring-boot hikaricp

127

We have Spring-boot/Hibernate/PostgreSQL application in our project and use Hikari as the connection pool. We keep running into the following problem: after few hours active connections number grows to the limit and we get the errors like this (full stack trace is at the end of the question):

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:213) ~[HikariCP-2.4.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:163) ~[HikariCP-2.4.1.jar:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85) ~[HikariCP-2.4.1.jar:na]
    at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    ... 126 common frames omitted

Here is the version info:

Spring-boot version:   1.2.3.RELEASE
HikariCP version:      2.4.1
Hibernate version:     4.3.6.Final
Postgresql jdbc:       9.3-1102-jdbc41
Server version:        Apache Tomcat/8.0.23
JVM Version:           1.8.0_45-b14

JPA/Hibernate config:

jpa:
    database-platform: org.hibernate.dialect.PostgreSQL82Dialect
    database: POSTGRESQL
    openInView: false
    show_sql: false
    generate-ddl: false
    hibernate:
        ddl-auto: none
        naming-strategy: org.hibernate.cfg.EJB3NamingStrategy
    properties:
        hibernate.cache.use_second_level_cache: true
        hibernate.cache.use_query_cache: false
        hibernate.generate_statistics: false
        hibernate.cache.region.factory_class: org.hibernate.cache.ehcache.SingletonEhCacheRegionFactory
        hibernate.enable_lazy_load_no_trans: true
        hibernate.event.merge.entity_copy_observer: allow

HikariCP config:

2015-10-06 12:26:44,252 DEBUG [localhost-startStop-1] HikariConfig: HikariPool-0 - configuration:
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: allowPoolSuspension.............false
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: autoCommit......................true
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: catalog.........................
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: connectionInitSql...............
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: connectionTestQuery.............
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: connectionTimeout...............30000
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: dataSource......................
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: dataSourceClassName.............org.postgresql.ds.PGSimpleDataSource
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: dataSourceJNDI..................
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: dataSourceProperties............{user=postgres, password=<masked>, databaseName=lms, serverName=*.*.*.*:5432}
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: driverClassName.................
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: healthCheckProperties...........{}
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: healthCheckRegistry.............
2015-10-06 12:26:44,274 DEBUG [localhost-startStop-1] HikariConfig: idleTimeout.....................30000
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: initializationFailFast..........true
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: isolateInternalQueries..........false
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: jdbc4ConnectionTest.............false
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: jdbcUrl.........................
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: leakDetectionThreshold..........0
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: maxLifetime.....................1800000
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: maximumPoolSize.................20
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: metricRegistry..................com.codahale.metrics.MetricRegistry@63d2fc48
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: metricsTrackerFactory...........
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: minimumIdle.....................10
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: password........................<masked>
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: poolName........................HikariPool-0
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: readOnly........................false
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: registerMbeans..................false
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: scheduledExecutorService........
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: threadFactory...................
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: transactionIsolation............
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: username........................
2015-10-06 12:26:44,275 DEBUG [localhost-startStop-1] HikariConfig: validationTimeout...............5000
2015-10-06 12:26:44,276 INFO  [localhost-startStop-1] HikariDataSource: HikariPool-0 - is starting.
2015-10-06 12:26:44,432 DEBUG [localhost-startStop-1] PoolElf: HikariPool-0 - Connection.setNetworkTimeout() is not supported (Method org.postgresql.jdbc4.Jdbc4Connection.getNetworkTimeout() is not yet implemented.)

Full stack trace:

2015-10-06 12:09:36,885 DEBUG [http-nio-8080-exec-25] PoolElf: HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@3cc4d919
2015-10-06 12:09:42,651 DEBUG [Hikari housekeeper (pool HikariPool-0)] HikariPool: Before cleanup   pool HikariPool-0 stats (total=20, active=20, idle=0, waiting=1)
2015-10-06 12:09:42,652 DEBUG [Hikari housekeeper (pool HikariPool-0)] HikariPool: After cleanup    pool HikariPool-0 stats (total=20, active=20, idle=0, waiting=1)
2015-10-06 12:10:06,885 DEBUG [http-nio-8080-exec-25] HikariPool: Timeout failure   pool HikariPool-0 stats (total=20, active=20, idle=0, waiting=0)
2015-10-06 12:10:06,885 WARN  [http-nio-8080-exec-25] SqlExceptionHelper: SQL Error: 0, SQLState: null
2015-10-06 12:10:06,885 ERROR [http-nio-8080-exec-25] SqlExceptionHelper: HikariPool-0 - Connection is not available, request timed out after 30000ms.
2015-10-06 12:10:06,885 DEBUG [http-nio-8080-exec-25] PoolElf: HikariPool-0 - Reset (nothing) on connection org.postgresql.jdbc4.Jdbc4Connection@3cc4d919
2015-10-06 12:10:06,886 ERROR [http-nio-8080-exec-25] ErrorPageFilter: Forwarding to error page from request [/api/courses/121387/quizzes/i6fa2562510bf8578712380a87a433e97/student/30175] due to exception [org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.hibernate.exception.JDBCConnectionException: Could not open connection]
java.lang.RuntimeException: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.hibernate.exception.JDBCConnectionException: Could not open connection
    at lms.security.xauth.XAuthTokenFilter.doFilter(XAuthTokenFilter.java:86) ~[XAuthTokenFilter.class:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:120) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:91) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:53) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:213) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:176) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:102) ~[spring-boot-actuator-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:85) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:113) [spring-boot-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.springframework.boot.context.web.ErrorPageFilter.access$000(ErrorPageFilter.java:59) [spring-boot-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.springframework.boot.context.web.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:88) [spring-boot-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:106) [spring-boot-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:8.0.23]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [catalina.jar:8.0.23]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) [catalina.jar:8.0.23]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) [catalina.jar:8.0.23]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [catalina.jar:8.0.23]
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:617) [catalina.jar:8.0.23]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [catalina.jar:8.0.23]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518) [catalina.jar:8.0.23]
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091) [tomcat-coyote.jar:8.0.23]
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668) [tomcat-coyote.jar:8.0.23]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1521) [tomcat-coyote.jar:8.0.23]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1478) [tomcat-coyote.jar:8.0.23]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_45]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.0.23]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_45]
Caused by: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.hibernate.exception.JDBCConnectionException: Could not open connection
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:978) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:648) ~[servlet-api.jar:na]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) ~[servlet-api.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:104) ~[metrics-servlet-3.1.1.jar:3.1.1]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-websocket.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.boot.actuate.autoconfigure.EndpointWebMvcAutoConfiguration$ApplicationContextHeaderFilter.doFilterInternal(EndpointWebMvcAutoConfiguration.java:291) ~[spring-boot-actuator-1.2.3.RELEASE.jar:1.2.3.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) [spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.23]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.23]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:316) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:126) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:122) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:168) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:48) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) ~[spring-security-web-4.0.0.RELEASE.jar:na]
    at lms.security.xauth.XAuthTokenFilter.doFilter(XAuthTokenFilter.java:84) ~[XAuthTokenFilter.class:na]
    ... 46 common frames omitted
Caused by: org.hibernate.exception.JDBCConnectionException: Could not open connection
    at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:65) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:112) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:235) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1435) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:250) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.readElementByIndex(AbstractPersistentCollection.java:376) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.collection.internal.PersistentMap.get(PersistentMap.java:164) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at java_util_Map$get.call(Unknown Source) ~[na:na]
    at lms.service.QuizService.processAnswers(QuizService.groovy:66) ~[QuizService.class:na]
    at lms.service.QuizService$$FastClassBySpringCGLIB$$4dcc8beb.invoke(<generated>) ~[spring-core-4.1.6.RELEASE.jar:na]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at lms.service.QuizService$$EnhancerBySpringCGLIB$$37a60c0a.processAnswers(<generated>) ~[spring-core-4.1.6.RELEASE.jar:na]
    at lms.web.rest.CourseResource.saveQuizResults(CourseResource.java:537) ~[CourseResource.class:na]
    at lms.web.rest.CourseResource$$FastClassBySpringCGLIB$$e3d2ba4d.invoke(<generated>) ~[spring-core-4.1.6.RELEASE.jar:na]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:68) ~[spring-security-core-4.0.0.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:48) ~[metrics-spring-3.0.4.jar:na]
    at com.ryantenney.metrics.spring.TimedMethodInterceptor.invoke(TimedMethodInterceptor.java:34) ~[metrics-spring-3.0.4.jar:na]
    at com.ryantenney.metrics.spring.AbstractMetricMethodInterceptor.invoke(AbstractMetricMethodInterceptor.java:59) ~[metrics-spring-3.0.4.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653) ~[spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at lms.web.rest.CourseResource$$EnhancerBySpringCGLIB$$ff854301.saveQuizResults(<generated>) ~[spring-core-4.1.6.RELEASE.jar:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_45]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_45]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) ~[spring-web-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966) ~[spring-webmvc-4.1.6.RELEASE.jar:4.1.6.RELEASE]
    ... 81 common frames omitted
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:213) ~[HikariCP-2.4.1.jar:na]
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:163) ~[HikariCP-2.4.1.jar:na]
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85) ~[HikariCP-2.4.1.jar:na]
    at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]
    ... 126 common frames omitted
2015-10-06 12:10:12,651 DEBUG [Hikari housekeeper (pool HikariPool-0)] HikariPool: Before cleanup   pool HikariPool-0 stats (total=20, active=19, idle=1, waiting=0)
2015-10-06 12:10:12,652 DEBUG [Hikari housekeeper (pool HikariPool-0)] HikariPool: After cleanup    pool HikariPool-0 stats (total=20, active=19, idle=1, waiting=0)

Any clue would be helpful!

Pinnatifid answered 6/10, 2015 at 11:14 Comment(1)

For me this happened because I forgot to connect to my Work VPN, which meant the connections were blocked... – Bubble 14/11, 2016 at 10:37

103

I managed to fix it finally. The problem is not related to HikariCP. The problem persisted because of some complex methods in REST controllers executing multiple changes in DB through JPA repositories. For some reasons calls to these interfaces resulted in a growing number of "freezed" active connections, exhausting the pool. Either annotating these methods as @Transactional or enveloping all the logic in a single call to transactional service method seem to solve the problem.

Pinnatifid answered 10/12, 2015 at 9:55 Comment(7)

How did u find the method with problem? I having the same problem :( tks – Jaques 26/6, 2017 at 19:0

As I remember, I just called every suspected controller method manually many times with bursts of simultaneous requests (emulating real use cases) checking if this will trigger the Hikari problem. I probably debugged the service methods to discover how does Hibernate act in case of problems, but it was enough to just call every method N times in a short period of time and check if this exhausts the pool. – Pinnatifid 27/6, 2017 at 20:55

I have the same issue with my project. We have JPA but didn't use anything to manage it. Is @Transactional is required for every DB request? psql (10.6 (Debian 10.6-1.pgdg90+1)) – Casiecasilda 29/2, 2020 at 10:36

@Chhaiya Harshad @Transactional may be used to wrap the business methods containing multiple calls to DB which should be executed in the same transaction. E.g. you have to read some value from table 1, process it and and write changes to tables 2 and 3 in a single business method. If you want the changes in table 2 to be rolled back in case of error writing to table 3 you should wrap the whole method in @Transactional to get a predictable result. – Pinnatifid 30/3, 2020 at 17:17

could you explain more about that? for example, i have a similar situation that includes the invoking of @Async methods and multiple calls to a sybase database :'( – Whencesoever 16/9, 2021 at 22:50

@MarlonLópez I'm a bit out of context already, but you may check that you have transactions (i.e. @Transactional annotations) in methods both outside and inside the Async methods. Also this may be of help: #19936309 – Pinnatifid 17/9, 2021 at 9:2

I used @Transactional annotation and it solved my issue. In my case, I call a stored procedure that returns REF_CURSOR and the connection was somehow remained blocked until using @Transactional annotation. Thanks. – Optional 20/1, 2022 at 8:24

From stack trace:

HikariPool: Timeout failure pool HikariPool-0 stats (total=20, active=20, idle=0, waiting=0) Means pool reached maximum connections limit set in configuration.

The next line: HikariPool-0 - Connection is not available, request timed out after 30000ms. Means pool waited 30000ms for free connection but your application not returned any connection meanwhile.

Mostly it is connection leak (connection is not closed after borrowing from pool), set leakDetectionThreshold to the maximum value that you expect SQL query would take to execute.

otherwise, your maximum connections 'at a time' requirement is higher than 20 !

Jat answered 6/10, 2015 at 12:27 Comment(11)

Thanks for reply, I added leak detection in the config, let's see. I've also found a similar issue on hikari tracker: github.com/brettwooldridge/HikariCP/issues/109 – Pinnatifid 6/10, 2015 at 12:56

At the startup 3 connections are used immediately: (total=13, active=3, idle=10, waiting=0)

2015-10-06 16:20:00,188 WARN  [Hikari housekeeper (pool HikariPool-0)] LeakTask: Connection leak detection triggered for connection org.postgresql.jdbc4.Jdbc4Connection@34e1598c, stack trace follows java.lang.Exception: Apparent connection leak detected 	at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139) ~[hibernate-core-4.3.6.Final.jar:4.3.6.Final]

– Pinnatifid 6/10, 2015 at 13:26

Leak detection threshold was set and triggered after 15 seconds. increase threshold to the time it takes to start app and some ? [INFO] lms.Application - Started Application in 46.102 seconds (JVM running for 49.097) – Jat 6/10, 2015 at 14:14

I used to set it to 100000, and got exactly the same error after application startup ended in 36 seconds. – Pinnatifid 6/10, 2015 at 14:31

In pg_stat_activity these leaking connections are shown as idle with query "SELECT 1" – Pinnatifid 6/10, 2015 at 14:35

either spring or hibernate is not closing that connection. HikariCP is working ok, as per setup. – Jat 6/10, 2015 at 15:2

I've set maxLifetime for HikariCP. It should help. – Pinnatifid 7/10, 2015 at 9:38

any progress? check spring and hibernate configuration. also to keep focused people interest, remove other tags from question. only spring-boot, hibernate, hikaricp suffice. – Jat 9/10, 2015 at 5:36

After setting maxLifeTime=30000 and maxConnections=50 we still have the number of active connections growing slowly under very gentle usage. I plan to load test the system to try to identify the problem. I think postgres usage may be essential detail. – Pinnatifid 9/10, 2015 at 13:32

generally maxLifeTime=30000 is too low and maxConnections=50 is higher for most. see github.com/brettwooldridge/HikariCP/wiki/About-Pool-Sizing – Jat 9/10, 2015 at 13:44

Nitin, thanks for replies. I localized the problem, it's definitely related to Hibernate. After certain user actions the number of active connections grows, more and more connection leaks are detected, and finally the application freezes. Surprisingly small maxLifetime setting doesn't help, these connections remain active. – Pinnatifid 26/10, 2015 at 12:35

problem was solved for me by adding the following properties to application.properties file:

  spring.datasource.hikari.connection-test-query=SELECT 1 FROM DUAL
  spring.datasource.hikari.connection-timeout=600000
  spring.datasource.hikari.maximum-pool-size=500
  spring.datasource.hikari.max-lifetime=1800000
  spring.datasource.hikari.minimum-idle=20
  spring.datasource.hikari.validation-timeout=3000
  spring.datasource.hikari.idle-timeout=60000

Mast answered 6/12, 2021 at 20:31 Comment(1)

Just increasing spring.datasource.hikari.maximum-pool-size worked for me. Thank you. – Fatherland 23/5, 2022 at 18:7

I had a similar issue, and the culprit turned out to be the use of jdbc's "queryForStream". More info in the article below, but essentially you need to explicitly close the stream or the connection remains open.

https://mjchi7.github.io/posts/jdbctemplate-queryforstream-connection-leak/

Diaphone answered 9/3, 2023 at 14:54 Comment(1)

Also had same issue and found that you need to use try with resources to ensure your stream always gets automatically closed github.com/spring-projects/spring-framework/issues/27988 – Lapierre 17/2 at 0:28

I faced the same problem on a project i was working with a colleague. He was using jdbc and he forgot to close some of his database connections after completion. this threw this error. make sure every database connection is closed if you are not using Hibernate or JDBC template.. Visit this site for more sample https://mkyong.com/jdbc/hikaripool-1-connection-is-not-available-request-timed-out-after-30002ms/

Seamaid answered 25/3, 2022 at 16:23 Comment(0)

I was a similar problem as described by user19316412

I'm using JdbcClient (springboot 3.2, java 21) and wanted to process the query result straight away.

        List<BigDecimal> out = jdbcClient
             .sql("""
                     SELECT DISTINCT percent
                     FROM order
                     WHERE active=true
                     """)
             .query((rs, __) -> rs.getBigDecimal("percent"))
             .stream()
             .map(bd -> bd.multiply(_100))
             .map(bd -> bd.setScale(0, RoundingMode.HALF_UP))
             .toList();

It looks quite ok, but quite quickly I received messages about the lack of connection to the database. Enable logging:

<logger name="com.zaxxer.hikari.pool" level="DEBUG" />

it showed the cause of the problem well:

[HikariPool-1 housekeeper] WARN  c.zaxxer.hikari.pool.ProxyLeakTask [] - Connection leak detection triggered for org.postgresql.jdbc.PgConnection@67e11bda on thread http-nio-8082-exec-3, stack trace follows
java.lang.Exception: Apparent connection leak detected
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
    at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:160)
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:118)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:81)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:653)
    at org.springframework.jdbc.core.JdbcTemplate.queryForStream(JdbcTemplate.java:844)
    at org.springframework.jdbc.core.JdbcTemplate.queryForStream(JdbcTemplate.java:863)
    at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.queryForStream(NamedParameterJdbcTemplate.java:237)
    at org.springframework.jdbc.core.simple.DefaultJdbcClient$DefaultStatementSpec$NamedParamMappedQuerySpec.stream(DefaultJdbcClient.java:361)
    at pl.apinn.jflowers.DiscountController.ordersClientFromYear(DiscountController.java:59)
    at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
    at java.base/java.lang.reflect.Method.invoke(Method.java:578)

line: (DiscountController.java:59) points to .stream()

so I added a terminal operations: .list() on database query and it helped:

    List<BigDecimal> out = jdbcClient
            .sql("""
                    SELECT DISTINCT percent
                    FROM order
                    WHERE active=true
                    """)
            .query((rs, __) -> rs.getBigDecimal("percent"))
            .list()
            .stream()
            .map(bd -> bd.multiply(_100))
            .map(bd -> bd.setScale(0, RoundingMode.HALF_UP))
            .toList();

Osbourn answered 13/1 at 16:36 Comment(0)

The VPN issue mentioned by AO_ is quite common yet neglected one.

One of the possible reasons could be that a person is requesting resources from server where requests are blocked by the organization's VPN. In that case one can try connecting via the VPN. This has happened to me in the past.

In a distributed work culture this can happen on several occasions mostly when the Internet connection gets lost/reset which disconnects from the VPN. The only way in such cases is to connect back to the VPN once the internet connection is back.

Kamerman answered 1/12, 2021 at 9:35 Comment(0)

Hot tags

Godot Unity Godot Help Programming Godot 4.X GUI GDScript 3D 2D Physics CSharp Godot 3.X VR XR Projects C++

Recommended topics

Hot tags