Every once in a while, we experience an issue in our application where applications stops on executing some mssql server query. We figured out that the issue is that HikariPool getConnection does not time out even though it should based on the connectionTimeout value set.

Here is the config of HikariDataSource

Here is the log where you can see that getConnection timed out after ~13 hours.

`2024-09-26T08:55:36.530Z ERROR 1597804 --- [DatabaseJobsScheduler-6] o.i.c.c.s.p.queue.jobs.DatabaseJob : Error on execution for Old collected traffic removal job for accountId=20001; error: Failed to execute removeOldCollectedTraffic.

java.lang.RuntimeException: Failed to execute removeOldCollectedTraffic.
at org.infobip.cdr.collector.service.persistence.queue.repository.impl.CdrDataRepositoryImpl.removeOldCollectedTraffic(Unknown Source)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:355)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:138)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:720)
at org.infobip.cdr.collector.service.persistence.queue.repository.impl.CdrDataRepositoryImpl$$SpringCGLIB$$0.removeOldCollectedTraffic()
at org.infobip.cdr.collector.service.persistence.queue.jobs.DatabaseJobsScheduler.lambda$scheduleRemovalOfOldCollectedTraffic$9(DatabaseJobsScheduler.java:128)
at org.infobip.cdr.collector.service.persistence.queue.jobs.DatabaseJob.execute(Unknown Source)
at org.infobip.cdr.collector.service.persistence.queue.jobs.DatabaseJob.run(Unknown Source)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:358)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: java.sql.SQLTransientConnectionException: cdr_collector_op_20000_db_1094001 - Connection is not available, request timed out after 47269980ms (total=6, active=0, idle=6, waiting=0)
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:686)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:99)
at org.infobip.cdr.collector.service.persistence.queue.repository.impl.CdrDataRepositoryImpl.removeOldCollectedTraffic(Unknown Source)
... 23 common frames omitted
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The connection is closed.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:233)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.checkClosed(SQLServerConnection.java:1848)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.setNetworkTimeout(SQLServerConnection.java:7228)
at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:562)
at com.zaxxer.hikari.pool.PoolBase.isConnectionDead(PoolBase.java:169)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:168)
... 26 common frames omitted`

Also worth to notice is that these errors happen but the timeout usually does trigger, but for some reason there is this case where every once in a while getConnection lasts this long...
Here is the log of getConnection when timeout does happen in time:

Caused by: java.sql.SQLTransientConnectionException: cdr_collector_op_30000_db_1094001 - Connection is not available, request timed out after 30001ms (total=2, active=2, idle=0, waiting=11) at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:686) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:99) at org.infobip.cdr.collector.service.persistence.queue.repository.impl.CdrDataRepositoryImpl.executeAggregationProcedure(CdrDataRepositoryImpl.java:74) ... 23 common frames omitted Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The connection is closed. at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:233) at com.microsoft.sqlserver.jdbc.SQLServerConnection.checkClosed(SQLServerConnection.java:1848) at com.microsoft.sqlserver.jdbc.SQLServerConnection.setNetworkTimeout(SQLServerConnection.java:7228) at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:562) at com.zaxxer.hikari.pool.PoolBase.isConnectionDead(PoolBase.java:169) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:168) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:144) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:99) at org.infobip.cdr.database.helper.SecondStageImportExecutor.execute(SecondStageImportExecutor.java:23) at org.infobip.cdr.collector.service.persistence.queue.repository.impl.TwoStageImportJobRepositoryImpl.executeCompleteTwoStageImport(TwoStageImportJobRepositoryImpl.java:26) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:355) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:138) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:768) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:720) at org.infobip.cdr.collector.service.persistence.queue.repository.impl.TwoStageImportJobRepositoryImpl$$SpringCGLIB$$0.executeCompleteTwoStageImport(<generated>) at org.infobip.cdr.collector.service.write.cdr.twostageimport.SecondStageImportJob.executeImport(SecondStageImportJob.java:65) at org.infobip.cdr.collector.service.write.cdr.twostageimport.SecondStageImportJob.process(SecondStageImportJob.java:55) at org.infobip.common.concurrent.AbstractProcessor.run(AbstractProcessor.java:91) ... 1 common frames omitted

Looking at the HikariPool getConnection, I am not sure how could this happen but it does :D .
HikariCP version that we are using is 5.1.0.