HikariCP icon indicating copy to clipboard operation
HikariCP copied to clipboard

Published 20 hours ago • verified publisher icon brettwooldridge

Timeout after 300001ms of waiting for a connection Timeout failure pool stats (total=0, inUse=0, avail=0, waiting=199)

Open masoowee opened this issue 2 years ago • 0 comments

Hello, need your advice,

I having an issue related to timeout connection to the database,

This is my Hikari configuration:

HikariCP config: hikari.maximumPoolSize=20 hikari.idleTimeout=30000 hikari.maxLifetime=60000 hikari.leakDetectionThreshold=30000 hikari.connectionTimeout=300000

Dependency version: hikari version: 2.3.12 hibernate version: 5.1.0.Final Java 8 ojdbc8 19.3.0.0

This is the debug information

2021-10-29 13:21:20.402 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(837) - HikariCP pool postpaidSupportConnectionPool configuration: 2021-10-29 13:21:20.402 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(837) - HikariCP pool postpaidSupportConnectionPool configuration: 2021-10-29 13:21:20.411 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - allowPoolSuspension.............false 2021-10-29 13:21:20.411 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - allowPoolSuspension.............false 2021-10-29 13:21:20.412 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - autoCommit......................true 2021-10-29 13:21:20.412 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - autoCommit......................true 2021-10-29 13:21:20.412 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - catalog......................... 2021-10-29 13:21:20.412 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - catalog......................... 2021-10-29 13:21:20.413 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionCustomizer............com.zaxxer.hikari.AbstractHikariConfig$1@6af20dbb 2021-10-29 13:21:20.413 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionCustomizer............com.zaxxer.hikari.AbstractHikariConfig$1@6af20dbb 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionCustomizerClassName... 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionCustomizerClassName... 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionInitSql............... 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionInitSql............... 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionTestQuery.............SELECT 1 FROM DUAL 2021-10-29 13:21:20.414 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionTestQuery.............SELECT 1 FROM DUAL 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionTimeout...............300000 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - connectionTimeout...............300000 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSource...................... 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSource...................... 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceClassName.............oracle.jdbc.pool.OracleDataSource 2021-10-29 13:21:20.415 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceClassName.............oracle.jdbc.pool.OracleDataSource 2021-10-29 13:21:20.416 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceJNDI.................. 2021-10-29 13:21:20.416 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceJNDI.................. 2021-10-29 13:21:20.416 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceProperties............{user=TNFWEBPOSTPAID, url=jdbc:oracle:thin:@cbtgrdnbl-scan.int ra.excelcom.co.id:1522/conscbt, password=<masked>} 2021-10-29 13:21:20.416 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - dataSourceProperties............{user=TNFWEBPOSTPAID, url=jdbc:oracle:thin:@cbtgrdnbl-scan.int ra.excelcom.co.id:1522/conscbt, password=<masked>} 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - driverClassName................. 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - driverClassName................. 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - healthCheckProperties...........{} 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - healthCheckProperties...........{} 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - healthCheckRegistry............. 2021-10-29 13:21:20.417 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - healthCheckRegistry............. 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - idleTimeout.....................30000 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - idleTimeout.....................30000 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - initializationFailFast..........true 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - initializationFailFast..........true 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - isolateInternalQueries..........false 2021-10-29 13:21:20.418 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - isolateInternalQueries..........false 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - jdbc4ConnectionTest.............false 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - jdbc4ConnectionTest.............false 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - jdbcUrl......................... 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - jdbcUrl......................... 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - leakDetectionThreshold..........30000 2021-10-29 13:21:20.419 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - leakDetectionThreshold..........30000 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - maxLifetime.....................60000 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - maxLifetime.....................60000 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - maximumPoolSize.................20 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - maximumPoolSize.................20 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - metricRegistry.................. 2021-10-29 13:21:20.420 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - metricRegistry.................. 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - minimumIdle.....................20 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - minimumIdle.....................20 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - password........................<masked> 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - password........................<masked> 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - poolName........................postpaidSupportConnectionPool 2021-10-29 13:21:20.421 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - poolName........................postpaidSupportConnectionPool 2021-10-29 13:21:20.423 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - readOnly........................false 2021-10-29 13:21:20.423 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - readOnly........................false 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - registerMbeans..................false 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - registerMbeans..................false 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - threadFactory................... 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - threadFactory................... 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - transactionIsolation............ 2021-10-29 13:21:20.424 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - transactionIsolation............ 2021-10-29 13:21:20.425 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - username........................ 2021-10-29 13:21:20.425 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - username........................ 2021-10-29 13:21:20.426 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - validationTimeout...............5000 2021-10-29 13:21:20.426 [http-bio-8080-exec-10705] DEBUG com.zaxxer.hikari.HikariConfig.logConfiguration(848) - validationTimeout...............5000 2021-10-29 13:21:20.426 [http-bio-8080-exec-10705] INFO com.zaxxer.hikari.HikariDataSource.<init>(79) - HikariCP pool postpaidSupportConnectionPool is starting.

This is the stack trace from the log

2021-10-29 12:41:40.590 [HikariCP connection filler (pool postpaidSupportConnectionPool)] DEBUG com.zaxxer.hikari.pool.HikariPool.addConnection(466) - Connection attempt to database postpaidSupportConnectio nPool failed: IO Error: Connection reset by peer, Authentication lapse 1 ms. java.sql.SQLRecoverableException: IO Error: Connection reset by peer, Authentication lapse 1 ms. at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:874) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:793) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:57) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:747) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.pool.OracleDataSource.getPhysicalConnection(OracleDataSource.java:406) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:291) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:206) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:184) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at com.zaxxer.hikari.pool.BaseHikariPool.addConnection(BaseHikariPool.java:444) ~[HikariCP-java6-2.3.12.jar:na] at com.zaxxer.hikari.pool.BaseHikariPool$1.run(BaseHikariPool.java:419) [HikariCP-java6-2.3.12.jar:na] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_265] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_265] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_265] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_265] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_265] Caused by: java.io.IOException: Connection reset by peer, Authentication lapse 1 ms. at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:870) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] ... 14 common frames omitted Caused by: java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[na:1.8.0_265] at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) ~[na:1.8.0_265] at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) ~[na:1.8.0_265] at sun.nio.ch.IOUtil.write(IOUtil.java:65) ~[na:1.8.0_265] at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:468) ~[na:1.8.0_265] at oracle.net.nt.TimeoutSocketChannel.write(TimeoutSocketChannel.java:203) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.net.ns.NIOPacket.writeToSocketChannel(NIOPacket.java:350) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.net.ns.NIONSDataChannel.writeDataToSocketChannel(NIONSDataChannel.java:199) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.net.ns.NIONSDataChannel.writeDataToSocketChannel(NIONSDataChannel.java:144) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CMAREngineNIO.flush(T4CMAREngineNIO.java:743) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CMAREngineNIO.prepareForUnmarshall(T4CMAREngineNIO.java:756) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CMAREngineNIO.unmarshalUB1(T4CMAREngineNIO.java:429) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:407) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:268) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CTTIoauthenticate.doOSESSKEY(T4CTTIoauthenticate.java:521) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:691) ~[ojdbc8-19.3.0.0.jar:19.3.0.0.0] ... 14 common frames omitted 2021-10-29 12:08:06.650 [http-bio-8080-exec-9807] DEBUG com.zaxxer.hikari.pool.HikariPool.logPoolState(588) - Timeout failure pool stats postpaidSupportConnectionPool (total=0, inUse=0, avail=0, waiting=199 ) 2021-10-29 12:08:06.657 [http-bio-8080-exec-9807] ERROR c.x.p.c.i.SoarRestServiceClientImpl.findResource(225) - Exception org.springframework.transaction.CannotCreateTransactionException: Could not open Hibernate Session for transaction; nested exception is org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection at org.springframework.orm.hibernate5.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:541) ~[spring-orm-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) ~[spring-tx-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:427) ~[spring-tx-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:276) ~[spring-tx-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) ~[spring-aop-4.2.2.RELEASE.jar:4.2.2.RELEASE] at com.sun.proxy.$Proxy262.insertAuditLog(Unknown Source) ~[na:na] at com.xl.prioritas.service.impl.AuditLogServiceImpl.insertAuditLog(AuditLogServiceImpl.java:18) ~[classes/:na] at com.xl.prioritas.client.impl.BaseRestServiceClient.logging(BaseRestServiceClient.java:153) ~[classes/:na] at com.xl.prioritas.client.impl.SoarRestServiceClientImpl.findResource(SoarRestServiceClientImpl.java:197) ~[classes/:na] at com.xl.prioritas.service.impl.SoarRestServiceImpl.findResource(SoarRestServiceImpl.java:117) [classes/:na] at com.xl.prioritas.controller.SoaIntegrationController.getNiceNumberFromSinglePool(SoaIntegrationController.java:93) [classes/:na] at sun.reflect.GeneratedMethodAccessor1410.invoke(Unknown Source) ~[na:na] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_265] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_265] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) [spring-web-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137) [spring-web-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:806) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:729) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:650) [servlet-api.jar:na] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) [spring-webmvc-4.2.2.RELEASE.jar:4.2.2.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) [servlet-api.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [catalina.jar:7.0.67] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.67] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat7-websocket.jar:7.0.67] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [catalina.jar:7.0.67] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.67] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [catalina.jar:7.0.67] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [catalina.jar:7.0.67] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) [catalina.jar:7.0.67] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) [catalina.jar:7.0.67] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:7.0.67] at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) [catalina.jar:7.0.67] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [catalina.jar:7.0.67] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423) [catalina.jar:7.0.67] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079) [tomcat-coyote.jar:7.0.67] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) [tomcat-coyote.jar:7.0.67] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-coyote.jar:7.0.67] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_265] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_265] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-coyote.jar:7.0.67] at java.lang.Thread.run(Thread.java:748) [na:1.8.0_265] Caused by: org.hibernate.QueryTimeoutException: Unable to acquire JDBC Connection at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:66) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:111) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:97) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:87) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:109) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:227) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:234) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1525) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.springframework.orm.hibernate5.HibernateTransactionManager.doBegin(HibernateTransactionManager.java:499) ~[spring-orm-4.2.2.RELEASE.jar:4.2.2.RELEASE] ... 48 common frames omitted Caused by: java.sql.SQLTimeoutException: Timeout after 300001ms of waiting for a connection. at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:233) ~[HikariCP-java6-2.3.12.jar:na] at com.zaxxer.hikari.pool.BaseHikariPool.getConnection(BaseHikariPool.java:183) ~[HikariCP-java6-2.3.12.jar:na] at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:93) ~[HikariCP-java6-2.3.12.jar:na] at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:84) ~[hibernate-core-5.1.0.Final.jar:5.1.0.Final] ... 55 common frames omitted

I am still confused why the application does not release the connection pool, although I have already set the max lifetime but still much idle connection on the database.

Why pool stats (total=0, inUse=0, avail=0, waiting=199) ?

masoowee avatar Oct 29 '21 08:10 masoowee