Comments (10)
MrPowerGamerBR
commented on June 12, 2024
Can confirm the same issue, the connection adder thread gets stuck and no connections are added to the pool.
What I have noticed is that what happens is the following:
- Application runs fine and well
- After a while (not sure when) the current active connections gets stuck, maybe due to network issues (?), this causes new connections to be waiting
2024-01-17 17:47:26,496 [PuddingPool connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Connection not added, stats (total=30, active=30, idle=0, waiting=2)
2024-01-17 17:47:26,496 [PuddingPool connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Connection not added, stats (total=30, active=30, idle=0, waiting=2)
2024-01-17 17:47:26,496 [PuddingPool connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Connection not added, stats (total=30, active=30, idle=0, waiting=3)
2024-01-17 17:47:26,497 [PuddingPool connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Connection not added, stats (total=30, active=30, idle=0, waiting=4)
2024-01-17 17:47:26,655 [PuddingPool connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Connection not added, stats (total=30, active=30, idle=0, waiting=5)
- The current active connections, after a while, are removed from the pool, but HikariCP fails to reconnect to the database due to...
2024-01-17 19:54:24,587 [pool-2-thread-5368 @coroutine#52534701] DEBUG com.zaxxer.hikari.pool.HikariPool - PuddingPool - Timeout failure stats (total=0, active=0, idle=0, waiting=128)
05:01:56.004 [DefaultDispatcher-worker-4 @coroutine#96539287] WARN n.p.e.s.SuspendableNestedTransaction - Exception while trying to execute query. Tries: 1
org.jetbrains.exposed.exceptions.ExposedSQLException: java.sql.SQLTransientConnectionException: PuddingPool - Connection is not available, request timed out after 30000ms (total=0, active=0, idle=0, waiting=127)
at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:49)
at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:141)
at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:127)
at org.jetbrains.exposed.sql.AbstractQuery.iterator(AbstractQuery.kt:61)
at org.jetbrains.exposed.sql.IterableExKt$mapLazy$1.iterator(IterableEx.kt:136)
at kotlin.collections.CollectionsKt___CollectionsKt.firstOrNull(_Collections.kt:269)
at org.jetbrains.exposed.dao.EntityClass.findById(EntityClass.kt:56)
at org.jetbrains.exposed.dao.EntityClass.findById(EntityClass.kt:47)
at net.perfectdreams.loritta.morenitta.LorittaBot._getOrCreateServerConfig(LorittaBot.kt:967)
at net.perfectdreams.loritta.morenitta.LorittaBot.access$_getOrCreateServerConfig(LorittaBot.kt:163)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invokeSuspend(LorittaBot.kt:949)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invoke(LorittaBot.kt)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invoke(LorittaBot.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invokeSuspend(SuspendableNestedTransaction.kt:61)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invoke(SuspendableNestedTransaction.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invoke(SuspendableNestedTransaction.kt)
at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:78)
at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext(Builders.common.kt:167)
at kotlinx.coroutines.BuildersKt.withContext(Unknown Source)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invokeSuspend(SuspendableNestedTransaction.kt:60)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invoke(SuspendableNestedTransaction.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invoke(SuspendableNestedTransaction.kt)
at org.jetbrains.exposed.sql.transactions.experimental.SuspendedKt$suspendedTransactionAsyncInternal$1.invokeSuspend(Suspended.kt:129)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
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: PuddingPool - Connection is not available, request timed out after 30000ms (total=0, active=0, idle=0, waiting=127)
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.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:141)
at org.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:138)
at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:126)
at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:127)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:76)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:75)
at kotlin.UnsafeLazyImpl.getValue(Lazy.kt:81)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction.getConnection(ThreadLocalTransactionManager.kt:89)
at org.jetbrains.exposed.sql.Transaction.getConnection(Transaction.kt)
at org.jetbrains.exposed.sql.statements.Statement.prepared(Statement.kt:24)
at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:47)
... 27 common frames omitted
Caused by: org.postgresql.util.PSQLException: This connection has been closed.
at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:993)
at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1694)
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)
... 40 common frames omitted
I've also had other stacktraces related to read timeout
org.jetbrains.exposed.exceptions.ExposedSQLException: java.sql.SQLTransientConnectionException: PuddingPool - Connection is not available, request timed out after 30000ms (total=0, active=0, idle=0, waiting=128)
at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:49)
at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:141)
at org.jetbrains.exposed.sql.Transaction.exec(Transaction.kt:127)
at org.jetbrains.exposed.sql.AbstractQuery.iterator(AbstractQuery.kt:61)
at org.jetbrains.exposed.sql.IterableExKt$mapLazy$1.iterator(IterableEx.kt:136)
at kotlin.collections.CollectionsKt___CollectionsKt.firstOrNull(_Collections.kt:269)
at org.jetbrains.exposed.dao.EntityClass.findById(EntityClass.kt:56)
at org.jetbrains.exposed.dao.EntityClass.findById(EntityClass.kt:47)
at net.perfectdreams.loritta.morenitta.LorittaBot._getOrCreateServerConfig(LorittaBot.kt:967)
at net.perfectdreams.loritta.morenitta.LorittaBot.access$_getOrCreateServerConfig(LorittaBot.kt:163)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invokeSuspend(LorittaBot.kt:949)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invoke(LorittaBot.kt)
at net.perfectdreams.loritta.morenitta.LorittaBot$getOrCreateServerConfig$3.invoke(LorittaBot.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invokeSuspend(SuspendableNestedTransaction.kt:61)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invoke(SuspendableNestedTransaction.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1$1.invoke(SuspendableNestedTransaction.kt)
at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:78)
at kotlinx.coroutines.BuildersKt__Builders_commonKt.withContext(Builders.common.kt:167)
at kotlinx.coroutines.BuildersKt.withContext(Unknown Source)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invokeSuspend(SuspendableNestedTransaction.kt:60)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invoke(SuspendableNestedTransaction.kt)
at net.perfectdreams.exposedpowerutils.sql.SuspendableNestedTransactionKt$transaction$3$1.invoke(SuspendableNestedTransaction.kt)
at org.jetbrains.exposed.sql.transactions.experimental.SuspendedKt$suspendedTransactionAsyncInternal$1.invokeSuspend(Suspended.kt:129)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:108)
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: PuddingPool - Connection is not available, request timed out after 30000ms (total=0, active=0, idle=0, waiting=128)
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.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:141)
at org.jetbrains.exposed.sql.Database$Companion$connect$3.invoke(Database.kt:138)
at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:126)
at org.jetbrains.exposed.sql.Database$Companion$doConnect$3.invoke(Database.kt:127)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:76)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction$connectionLazy$1.invoke(ThreadLocalTransactionManager.kt:75)
at kotlin.UnsafeLazyImpl.getValue(Lazy.kt:81)
at org.jetbrains.exposed.sql.transactions.ThreadLocalTransactionManager$ThreadLocalTransaction.getConnection(ThreadLocalTransactionManager.kt:89)
at org.jetbrains.exposed.sql.Transaction.getConnection(Transaction.kt)
at org.jetbrains.exposed.sql.statements.Statement.prepared(Statement.kt:24)
at org.jetbrains.exposed.sql.statements.Statement.executeIn$exposed_core(Statement.kt:47)
... 27 common frames omitted
Caused by: org.postgresql.util.PSQLException: The connection attempt failed.
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:354)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
at org.postgresql.Driver.makeConnection(Driver.java:444)
at org.postgresql.Driver.connect(Driver.java:297)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:137)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:360)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:202)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:461)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:724)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:703)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
... 3 common frames omitted
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:278)
at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:304)
at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:346)
at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:796)
at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1099)
at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:161)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:128)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:113)
at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
at org.postgresql.core.PGStream.receiveChar(PGStream.java:465)
at org.postgresql.core.v3.ConnectionFactoryImpl.enableSSL(ConnectionFactoryImpl.java:589)
at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:191)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:258)
... 14 common frames omitted
Thread dump of the connection adder thread
"PuddingPool connection adder" #99448 [100703] daemon prio=5 os_prio=0 cpu=7.68ms elapsed=4420.23s tid=0x00007f308019b090 nid=100703 runnable [0x00007f2fbdcfd000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.Net.poll([email protected]/Native Method)
at sun.nio.ch.NioSocketImpl.park([email protected]/NioSocketImpl.java:191)
at sun.nio.ch.NioSocketImpl.park([email protected]/NioSocketImpl.java:201)
at sun.nio.ch.NioSocketImpl.implRead([email protected]/NioSocketImpl.java:309)
at sun.nio.ch.NioSocketImpl.read([email protected]/NioSocketImpl.java:346)
at sun.nio.ch.NioSocketImpl$1.read([email protected]/NioSocketImpl.java:796)
at java.net.Socket$SocketInputStream.read([email protected]/Socket.java:1099)
at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:161)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:128)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:113)
at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
at org.postgresql.core.PGStream.receiveChar(PGStream.java:465)
at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:678)
at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:203)
at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:258)
at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:54)
at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:263)
at org.postgresql.Driver.makeConnection(Driver.java:444)
at org.postgresql.Driver.connect(Driver.java:297)
at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:137)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:360)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:202)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:461)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:724)
I know that it isn't a "well you just don't have any connectivity to the database" issue because if I connect to the application container and connect to the PostgreSQL server with psql, it works fine, also restarting the application fixes the issue.
Sadly I'm not sure if this is a regression in the PostgreSQL driver or in HikariCP, the last time I updated them was ~one month ago. I was using pgjdbc 42.5.0 and HikariCP 5.0.1 and back then I didn't recall any issues like that, currently I'm using pgjdbc 42.7.1 and HikariCP 5.1.0. I will try downgrading the versions later to see if the issue persists or not.
Update: To be honest, I'm not 100% sure if this is the exactly the same issue because your HikariCP version is way way way older than mine (3.4.5 vs 5.1.0) and you are using a driver than I am.
from hikaricp.
patric-r
commented on June 12, 2024
- Share your pool config
- Try to reproduce the issue with the newest HikariCP release and a recent oracle jdbc driver
from hikaricp.
igv-git
commented on June 12, 2024
- Currently we're using default values for hikari, so there is no specific config for the pool. Only exception is an environment where we're seeing that issue, I've added parameter there:
spring:
datasource:
hikari:
maxLifetime: 0
to prevent connections from being removed from the pool as a temporary workaround.
- That will take some time, the issue is intermittent and we don't have any means to force it, it may take more then a week to appear. But I can confirm the same behaviour with HikariCP version 5.1.0. I've tried this version before and the same error appeared after some time, though we didn't try any other versions for oracle driver yet.
from hikaricp.
patric-r
commented on June 12, 2024
-
As I don't know what spring is doing behind the curtain - can you enable DEBUG Logging and paste the effective configuration HikariCP is using here?
-
On which OS do you see this issue?
from hikaricp.
igv-git
commented on June 12, 2024
- Sure, here're log entries for our default config:
10:03:01.979 [main] DEBUG c.z.h.HikariConfig - HikariPool-1 - configuration:
10:03:01.981 [main] DEBUG c.z.h.HikariConfig - allowPoolSuspension.............false
10:03:01.981 [main] DEBUG c.z.h.HikariConfig - autoCommit......................true
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - catalog.........................none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - connectionInitSql...............none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - connectionTestQuery.............none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - connectionTimeout...............30000
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - dataSource......................none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - dataSourceClassName.............none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - dataSourceJNDI..................none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - dataSourceProperties............{password=<masked>}
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - driverClassName................."oracle.jdbc.OracleDriver"
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - exceptionOverrideClassName......none
10:03:01.982 [main] DEBUG c.z.h.HikariConfig - healthCheckProperties...........{}
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - healthCheckRegistry.............none
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - idleTimeout.....................600000
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - initializationFailTimeout.......1
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - isolateInternalQueries..........false
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - jdbcUrl.........................<masked>
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - leakDetectionThreshold..........0
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - maxLifetime.....................1800000
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - maximumPoolSize.................10
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - metricRegistry..................none
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - metricsTrackerFactory...........none
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - minimumIdle.....................10
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - password........................<masked>
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - poolName........................"HikariPool-1"
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - readOnly........................false
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - registerMbeans..................false
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - scheduledExecutor...............none
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - schema..........................none
10:03:01.983 [main] DEBUG c.z.h.HikariConfig - threadFactory...................internal
10:03:01.984 [main] DEBUG c.z.h.HikariConfig - transactionIsolation............default
10:03:01.984 [main] DEBUG c.z.h.HikariConfig - username........................<masked>
10:03:01.984 [main] DEBUG c.z.h.HikariConfig - validationTimeout...............5000
- Linux (RHEL, version 7.9)
from hikaricp.
rajaasthana
commented on June 12, 2024
Hi, did you solve this issue? We are experiencing same issue now.
from hikaricp.
MrPowerGamerBR
commented on June 12, 2024
Hi, did you solve this issue? We are experiencing same issue now.
In my case, the issue was that the dedicated server was losing network connectivity, so the PostgreSQL JDBC driver was getting stuck on random network calls.
from hikaricp.
KazzmanK
commented on June 12, 2024
Pretty much issues are connected with com.zaxxer.hikari.pool.PoolBase.isConnectionDead , this morning, after DB VM failure, we have same "Connection closed" exception in isConnectionDead routine, the outcome - no connection from pool available, timeout.
#1705 (comment)
#1403 (comment)
Here is how it was looked inprocess
It was trying to fill pool with connections, but failed to do so.
Once I have resources, reproduction should be like
- start as usual
- physically disconnect database via network
- see idle connections decrease
- see in logs PoolEntryCreator trying to fill pool
- restart database machine without network to clean any tcp context
- once restarted reattach db network
Just to let you know, all my attempts to simulate and reproduce issue failed.
from hikaricp.
roee-gavriel
commented on June 12, 2024
Having the same issue here. We encountering the following message
HikariPool-1 - Connection is not available, request timed out after 5000ms (total=0, active=0, idle=0, waiting=0)
from hikaricp.
rigotre7
commented on June 12, 2024
Similar issue with Hikari 4.0.3.
Logs:
2024-05-29 17:02:53.780 DEBUG 19 --- [ool housekeeper] com.zaxxer.hikari.pool.HikariPool : ****-db-pool - Pool stats (total=0, active=0, idle=0, waiting=0)
2024-05-29 17:02:53.780 DEBUG 19 --- [ool housekeeper] com.zaxxer.hikari.pool.HikariPool : ****-db-pool - Fill pool skipped, pool is at sufficient level.
2024-05-29 17:02:57.660 /****-microservice-api/6308 XXXXXX1000 DEBUG 19 --- [nio-8080-exec-1] com.zaxxer.hikari.pool.HikariPool : ****-db-pool - Add connection elided, waiting 1, queue 10
2024-05-29 17:03:07.667 /****-microservice-api/6308 XXXXXX1000 DEBUG 19 --- [nio-8080-exec-1] com.zaxxer.hikari.pool.HikariPool : ****-db-pool - Timeout failure stats (total=0, active=0, idle=0, waiting=0)
As you can see, my pool has 0 connections and 10 queued up to be opened. However, each time a user hits our API it results in a timeout with an "Unable to acquire JDBC connection" error and the following SQL error indicating the connections have been closed:
SQL Error: 0, SQLState: 08003
... 127 more
Caused by: java.sql.SQLTransientConnectionException: miluma-db-pool - Connection is not available, request timed out after 30000ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108)
... 131 more
Caused by: org.postgresql.util.PSQLException: This connection has been closed.
at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:885)
at org.postgresql.jdbc.PgConnection.setNetworkTimeout(PgConnection.java:1610)
at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:566)
at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:173)
at com.zaxxer.hikari.pool.HikariPool$KeepaliveTask.run(HikariPool.java:847)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
... 1 more
I've connected to the docker container which is running this API and can successfully telnet to my database so I know it's accessible. Furthermore, we have about 6 other services on the same network connecting to the same database. It happens mostly with this specific container.
Hikari Config:
maxLifetime: 45000
maxPoolSize: 15
minimumIdle: 5
connectionTimeout: 10000
keepAliveTime: 30000
from hikaricp.
Related Issues (20)
- Hikari + Snowflake + Oauth with token refresh HOT 1
- Introduce Extension Point To Force Eviction
- Handle Read-Only Mode After Cluster Failover HOT 1
- The connection adder thread pool is permanently blocked
- Available connections in HikariPool occassionaly drop to zero HOT 2
- java.sql.SQLFeatureNotSupportedException: Feature not implemented: No details. HOT 1
- Question : IdleTimeOut Best Practice
- Developer experience: allow configuring HikariCP with `java.time.Duration` instead of millisecond / second parameters
- The HikariDataSource.getConnection() method does not implement a fair borrow mechanism HOT 1
- question: how does `prepStmtCacheSize` property work
- A question of source code
- [Question] HikariCP tag metrics
- HikariCP Warning: "Driver does not support get/set network timeout for connections" HOT 1
- Another instance of dead pool, no new connection can be created
- `HikariProxyConnection` directly calls `delegate.getTransactionIsolation()`, causing a network call every time. HOT 1
- Why do Session Settings get reset on a connection?
- Communications link failure The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
- connectionTimeout property is not propagated to Postgres driver creating the connection
- Max-life-time expire cause application latency HOT 1
- Postgres Client thread getting stuck HOT 1
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from hikaricp.