Hikaricp: Connection.setNetworkTimeout cannot be called on a closed connection

[sooyoung32]

Environment

HikariCP version: 3.2.0
JDK version     : 1.8.0_161
Database        : Aurora MySql 5..7
Driver version  : Maria JDBC ConnectorJ 2.2.6

---

My app configurations are listed below.
spring boot version : 2.0.8

spring:
  datasource:
    hikari:
      jdbc-url: jdbc:mariadb:aurora:dbUrl:port/dbNanme?connectTimeout=10&validConnectionTimeout=10&socketTimeout=60000
      username:
      password: 
      validation-timeout: 1000 # must be less than the connectionTimeout
      max-lifetime: 580000
      maximum-pool-size: 15  # minimumIdle same as maximumPoolSize
      connection-timeout: 2000
````

And in HikariCP, there are warnings and errors in the pattern below.

2019-02-18 00:30:14.667 WARN 23197 --- [nio-5000-exec-8] com.zaxxer.hikari.pool.PoolBase : conn-pool - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@721a4c34 (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.
2019-02-18 00:30:15.671 WARN 23197 --- [nio-5000-exec-8] com.zaxxer.hikari.pool.PoolBase : conn-pool - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@6b173c77 (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

2019-02-18 00:30:15.673 ERROR 23197
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLTransientConnectionException: conn-pool - Connection is not available, request timed out after 2006ms.
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:305)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:474)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
at com.myapp.MyService$$EnhancerBySpringCGLIB$$e06a911a.getMyQuery()
at com.myapp.MyController.getMyQuery(MyController.java:82)
at sun.reflect.GeneratedMethodAccessor89.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:891)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:873)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:117)
at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:106)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTransientConnectionException: conn-pool - Connection is not available, request timed out after 2006ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:262)
... 70 common frames omitted
Caused by: java.sql.SQLException: Connection.setNetworkTimeout cannot be called on a closed connection
at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getSqlException(ExceptionMapper.java:211)
at org.mariadb.jdbc.MariaDbConnection.setNetworkTimeout(MariaDbConnection.java:1632)
at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
... 73 common frames omitted

2019-02-18 00:30:15.736 WARN 23197 --- [nio-5000-exec-6] com.zaxxer.hikari.pool.PoolBase : conn-pool - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@49d8cd9b (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

```

I applied the following solutions but they were not resolved.

1. Reduce maxLifeTime to less than 10 minutes
2. Version Up 2.7.9 -> 3.2.0
3. Apply @transactional to business logic

I understand from the above logs that "Failed to validate connection .." occurs while attempting to bring a connection and "Connection.setNetworkTimeout can not be opened on closed connection" error occurs when there is no valid connection . Is my guess right?

Regarding the issue, I have the following questions.

1. What should I do to resolve the error?
     1-1. Why does the "Failed to validate connection .." warning log occur?
     1-2. Why does "Connection.setNetworkTimeout can not be called on a closed connection" after waning?
     1-3. If the conenction is actually closed, does not the hikari pool retry to get the correct connection again? Or does the connection timeout end during the retry?
2. You told me to set "leakDetectionThreshold" in other issues, what does the configuration do in detail?

Thank you in advance for your help.

[brettwooldridge]

@sooyoung32 This exception is suppressed in HikariCP v3.3.0+.

[ibouakl]

@sooyoung32 This exception is suppressed in HikariCP v3.3.0+.

Hello @sooyoung32 ,

we use Hikari CP V3.3.0 and we configure maxLifeTime = 10 min. But we have always this warning;

WARN com.zaxxer.hikari.pool.PoolBase:179 - inventory-data-source - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@1fd8eaf1 (Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

Why does the warning log occur?

Thank you

[chrisinmtown]

I hear you saying, this warning from version 3.2.0 is not a sign of trouble and the solution is to upgrade to version 3.3.0. Please confirm.

In my case Spring-Boot version 2.1.3 chooses the HikariCP version, so I guess this warning will go away when the Spring peeps upgrade.

[aperger]

This error is still exist. I think. I got the the following error with MariaDB (Client v2.6.2 + HirakiCP v3.4.5 + default connection configuration of Spring Boot v2.2.8):

2020-10-05 16:05:00.003  WARN 11152 --- [pool-1-thread-2] com.zaxxer.hikari.pool.PoolBase          : poolDbKOMP - Failed to validate connection org.mariadb.jdbc.MariaDbConnection@38a19932 ((conn=1022572) Connection.setNetworkTimeout cannot be called on a closed connection). Possibly consider using a shorter maxLifetime value.

[brettwooldridge]

@aperger Importantly, this is not an error, it is a warning. It is pointing out a condition that should not occur in a properly configured pool/database. HikariCP should ideally never find a Connection in the pool that fails validation because the Connection has already been closed by the database server. The fix, as suggested, is to shorten the maxLifetime value so that HikariCP retires the Connection before any database-side timeout occurs.

Every time HikariCP encounters this condition, you should consider it a hit to performance. If Connections are proactively retired by HikariCP, and the Connection replaced in the background by HikariCP, your application will never encounter a wait caused by discovering, evicting, and replacing dead Connections at the time your application is calling getConnection().