HikariCP icon indicating copy to clipboard operation
HikariCP copied to clipboard

Published 20 hours ago • verified publisher icon brettwooldridge

Hikari cp unable to make new connections after connection has passed maxlifetime

Open rawatkav opened this issue 5 years ago • 9 comments

Environment


HikariCP version: 2.7.9

JDK version     : 1.8.0_111

Database        : Oracle

Driver version  : 0jdbc6 11.1.0.7.0


Hi,

is this issue resolved?

I am facing similar issue where Hikari CP is not able create new connections after connection has passed maxLifetime.

Hikari configuration:

HikariPool-1 - configuration:

allowPoolSuspension.............false

autoCommit......................true

catalog.........................none

connectionInitSql...............none

connectionTestQuery.............none

connectionTimeout...............60000

dataSource......................none

dataSourceClassName.............none

dataSourceJNDI..................none

dataSourceProperties............{password=}

driverClassName................."oracle.jdbc.OracleDriver"

healthCheckProperties...........{}

healthCheckRegistry.............none

idleTimeout.....................600000

initializationFailFast..........true

initializationFailTimeout.......1

isolateInternalQueries..........false

jdbc4ConnectionTest.............false

jdbcUrl.........................jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST = (LOAD_BALANCE = off) (FAILOVER = on) (ADDRESS = (PROTOCOL = TCP) (Host = ******)(Port = ****) ) (ADDRESS = (PROTOCOL = TCP) (Host = *****)(Port = ***)) ) (CONNECT_DATA = (SERVICE_NAME = ******) (FAILOVER_MODE =(TYPE = session) (METHOD = BASIC) (RETRIES = 180) (DELAY = 5) ) ) )

leakDetectionThreshold..........60000

maxLifetime.....................1800000

maximumPoolSize.................5

metricRegistry..................none

metricsTrackerFactory...........com.zaxxer.hikari.metrics.micrometer.MicrometerMetricsTrackerFactory@268f106e

minimumIdle.....................5

poolName........................"HikariPool-1"

readOnly........................false

registerMbeans..................false

scheduledExecutor...............none

scheduledExecutorService........internal

schema..........................none

threadFactory...................internal

transactionIsolation............default

validationTimeout...............5000

HikariPool-1 - Starting...

HikariPool-1 - Driver does not support get/set network timeout for connections. (oracle.jdbc.driver.T4CConnection.getNetworkTimeout()I)

HikariPool-1 - Added connection oracle.jdbc.driver.T4CConnection@48e1f6c7

in the logs:


2019-06-03 03:13:39.716 DEBUG 94796 --- [HikariPool-1 connection closer] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Closing connection oracle.jdbc.driver.T4CConnection@5843e613: (connection has passed maxLifetime)

 

2019-06-03 03:13:44.071 DEBUG 94796 --- [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=0, active=0, idle=0, waiting=10)

2019-06-03 03:14:14.074 DEBUG 94796 --- [HikariPool-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=0, active=0, idle=0, waiting=10)

 

2019-06-03 03:35:12.425 DEBUG 94796 --- [HikariPool-1 connection adder] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection oracle.jdbc.driver.T4CConnection@702afe36

It could create connections only after 12 minutes.

can you please help in this regard?

rawatkav avatar Jun 03 '19 05:06 rawatkav

@brettwooldridge please help.

rawatkav avatar Jun 03 '19 21:06 rawatkav

I'm seeing this as well, hikari closes the connections after maxLifetime but no new ones are opened

jmooo avatar Sep 05 '19 21:09 jmooo

Observing the same with the following configuration: Spring Boot 2.1.8, Java 1.8.0_222, Hikari CP 3.2.0. Pool configuation:

 autoCommit......................true
 catalog.........................none
 connectionInitSql...............none
 connectionTestQuery.............none
 connectionTimeout...............1000
 dataSource......................none
 dataSourceClassName.............none
 dataSourceJNDI..................none
 dataSourceProperties............{password=<masked>}
 driverClassName................."oracle.jdbc.OracleDriver"
 healthCheckProperties...........{}
 healthCheckRegistry.............none
 idleTimeout.....................600000
 initializationFailTimeout.......1
 isolateInternalQueries..........false
 jdbcUrl.........................jdbc:oracle:thin:@xxx.xxx.xxx:1521:xxxxxx
 leakDetectionThreshold..........60000
 maxLifetime.....................1800000
 maximumPoolSize.................50
 metricRegistry..................none
 metricsTrackerFactory...........none
 minimumIdle.....................50
 password........................<masked>
 poolName........................"APPDS"
 readOnly........................false
 registerMbeans..................false
 scheduledExecutor...............none
 schema..........................none
 threadFactory...................internal
 transactionIsolation............default
 username........................"xxxxxxxxxx"
 validationTimeout...............5000

Appication works fine several days, and we observe connections that reached their lifetime are getting evicted from the pool. But then it goes like this:

2020-02-04 23:03:45.510 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=50, active=0, idle=50, waiting=0)
2020-02-04 23:03:47.302 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@18334bee: (connection has passed maxLifetime)
2020-02-04 23:03:47.348 DEBUG 32038 --- [APPDS connection adder] com.zaxxer.hikari.pool.HikariPool        : APPDS - Added connection oracle.jdbc.driver.T4CConnection@4ba59f0
2020-02-04 23:03:48.466 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@b0ac8f8: (connection has passed maxLifetime)
2020-02-04 23:03:48.512 DEBUG 32038 --- [APPDS connection adder] com.zaxxer.hikari.pool.HikariPool        : APPDS - Added connection oracle.jdbc.driver.T4CConnection@222bde6a
2020-02-04 23:03:52.640 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@1ee68750: (connection has passed maxLifetime)
2020-02-04 23:03:52.741 DEBUG 32038 --- [APPDS connection adder] com.zaxxer.hikari.pool.HikariPool        : APPDS - Added connection oracle.jdbc.driver.T4CConnection@5a4ea50d
2020-02-04 23:03:55.225 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@662d729f: (connection has passed maxLifetime)
2020-02-04 23:03:56.766 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@5fdf2f06: (connection has passed maxLifetime)
2020-02-04 23:04:04.021 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2b35e8da: (connection has passed maxLifetime)
2020-02-04 23:04:15.511 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=47, active=0, idle=47, waiting=0)
2020-02-04 23:04:19.414 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2a92d1b8: (connection has passed maxLifetime)
2020-02-04 23:04:21.879 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@271b2425: (connection has passed maxLifetime)
2020-02-04 23:04:33.972 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@fcb235: (connection has passed maxLifetime)
2020-02-04 23:04:45.511 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=44, active=0, idle=44, waiting=0)
2020-02-04 23:05:01.572 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@572888f4: (connection has passed maxLifetime)
2020-02-04 23:05:11.271 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@7804266c: (connection has passed maxLifetime)
2020-02-04 23:05:15.511 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=42, active=0, idle=42, waiting=0)
2020-02-04 23:05:19.870 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2f0bd447: (connection has passed maxLifetime)
2020-02-04 23:05:23.225 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@109abb73: (connection has passed maxLifetime)
2020-02-04 23:05:24.964 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@128150e8: (connection has passed maxLifetime)
2020-02-04 23:05:28.757 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@42cbec4c: (connection has passed maxLifetime)
2020-02-04 23:05:29.769 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@688739c9: (connection has passed maxLifetime)
2020-02-04 23:05:30.683 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@4c2cc63c: (connection has passed maxLifetime)
2020-02-04 23:05:42.840 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@6382aa69: (connection has passed maxLifetime)
2020-02-04 23:05:45.223 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@42a10759: (connection has passed maxLifetime)
2020-02-04 23:05:45.511 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=34, active=0, idle=34, waiting=0)
2020-02-04 23:06:01.360 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@7c33053f: (connection has passed maxLifetime)
2020-02-04 23:06:04.199 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@706274ed: (connection has passed maxLifetime)
2020-02-04 23:06:10.344 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@14ef30ce: (connection has passed maxLifetime)
2020-02-04 23:06:11.088 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@4fd2de7: (connection has passed maxLifetime)
2020-02-04 23:06:15.512 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=30, active=0, idle=30, waiting=0)
2020-02-04 23:06:21.783 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@5bbe87fb: (connection has passed maxLifetime)
2020-02-04 23:06:34.925 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@44c4e22b: (connection has passed maxLifetime)
2020-02-04 23:06:45.512 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=28, active=0, idle=28, waiting=0)
2020-02-04 23:06:52.253 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2b33823f: (connection has passed maxLifetime)
2020-02-04 23:06:55.244 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@1ed648d1: (connection has passed maxLifetime)
2020-02-04 23:06:56.488 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@45d688ce: (connection has passed maxLifetime)
2020-02-04 23:07:15.512 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=25, active=0, idle=25, waiting=0)
2020-02-04 23:07:31.193 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@231c317b: (connection has passed maxLifetime)
2020-02-04 23:07:45.513 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:08:15.513 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:08:45.513 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:09:15.513 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:09:45.514 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:10:15.514 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:10:45.514 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:11:15.515 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:11:45.515 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:12:15.515 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:12:45.516 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:13:15.516 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:13:45.516 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:14:15.517 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:14:45.517 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:15:15.517 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:15:45.518 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:16:15.518 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:16:45.518 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:17:15.519 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:17:45.519 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:18:15.519 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:18:45.519 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:19:15.520 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:19:45.520 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:20:15.521 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:20:45.521 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:21:15.521 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:21:45.522 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:22:15.522 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:22:45.522 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:23:15.523 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:23:45.523 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:24:15.523 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:24:45.524 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:25:15.524 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:25:45.524 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:26:15.525 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:26:45.525 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:27:15.525 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:27:45.525 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:28:15.526 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:28:45.526 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=24, active=0, idle=24, waiting=0)
2020-02-04 23:29:00.762 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@33c8871e: (connection has passed maxLifetime)
2020-02-04 23:29:15.526 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=23, active=0, idle=23, waiting=0)
2020-02-04 23:29:45.527 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=23, active=0, idle=23, waiting=0)
2020-02-04 23:29:56.068 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@751e45ab: (connection has passed maxLifetime)
2020-02-04 23:30:15.527 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=22, active=0, idle=22, waiting=0)
2020-02-04 23:30:45.527 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=22, active=0, idle=22, waiting=0)
2020-02-04 23:30:57.045 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@671c9476: (connection has passed maxLifetime)
2020-02-04 23:31:05.624 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@25efb72e: (connection has passed maxLifetime)
2020-02-04 23:31:15.528 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=20, active=0, idle=20, waiting=0)
2020-02-04 23:31:31.784 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@7596cb51: (connection has passed maxLifetime)
2020-02-04 23:31:32.134 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@6abbf37d: (connection has passed maxLifetime)
2020-02-04 23:31:45.528 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=18, active=0, idle=18, waiting=0)
2020-02-04 23:31:49.422 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@3fe8d771: (connection has passed maxLifetime)
2020-02-04 23:31:57.810 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@7ef5ffea: (connection has passed maxLifetime)
2020-02-04 23:32:07.781 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@c9f22a: (connection has passed maxLifetime)
2020-02-04 23:32:14.287 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@4dd345c1: (connection has passed maxLifetime)
2020-02-04 23:32:15.528 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=14, active=0, idle=14, waiting=0)
2020-02-04 23:32:16.820 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@25716bb1: (connection has passed maxLifetime)
2020-02-04 23:32:20.651 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@7b4ffb74: (connection has passed maxLifetime)
2020-02-04 23:32:32.767 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@d77ab00: (connection has passed maxLifetime)
2020-02-04 23:32:34.252 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2e3bfbf5: (connection has passed maxLifetime)
2020-02-04 23:32:40.890 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@353f7291: (connection has passed maxLifetime)
2020-02-04 23:32:45.528 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=9, active=0, idle=9, waiting=0)
2020-02-04 23:32:52.643 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@63496f91: (connection has passed maxLifetime)
2020-02-04 23:32:53.264 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@48510d80: (connection has passed maxLifetime)
2020-02-04 23:32:54.365 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@2cbb4c92: (connection has passed maxLifetime)
2020-02-04 23:33:08.770 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@4303fe1a: (connection has passed maxLifetime)
2020-02-04 23:33:12.699 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@42ac83a0: (connection has passed maxLifetime)
2020-02-04 23:33:15.529 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=4, active=0, idle=4, waiting=0)
2020-02-04 23:33:20.094 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@3b0101a8: (connection has passed maxLifetime)
2020-02-04 23:33:27.164 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@4ba59f0: (connection has passed maxLifetime)
2020-02-04 23:33:33.319 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@222bde6a: (connection has passed maxLifetime)
2020-02-04 23:33:45.529 DEBUG 32038 --- [APPDS housekeeper] com.zaxxer.hikari.pool.HikariPool        : APPDS - Pool stats (total=1, active=0, idle=1, waiting=0)
2020-02-04 23:33:49.884 DEBUG 32038 --- [APPDS connection closer] com.zaxxer.hikari.pool.PoolBase          : APPDS - Closing connection oracle.jdbc.driver.T4CConnection@5a4ea50d: (connection has passed maxLifetime)
2020-02-04 23:33:51.485 DEBUG 32038 --- [scheduler-49] com.zaxxer.hikari.pool.HikariPool        : APPDS - Timeout failure stats (total=0, active=0, idle=0, waiting=0)
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLTransientConnectionException: APPDS - Connection is not available, request timed out after 1001ms.
Caused by: java.sql.SQLTransientConnectionException: APPDS - Connection is not available, request timed out after 1001ms.
2020-02-04 23:33:51.488 ERROR 32038 --- [scheduler-49] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLTransientConnectionException: APPDS - Connection is not available, request timed out after 1001ms.
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:305) ~[spring-jdbc-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378) ~[spring-tx-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:475) ~[spring-tx-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289) ~[spring-tx-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98) ~[spring-tx-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
...
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_222]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_222]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_222]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_222]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_222]
Caused by: java.sql.SQLTransientConnectionException: APPDS - Connection is not available, request timed out after 1001ms.
	at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676) ~[HikariCP-3.2.0.jar!/:na]
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190) ~[HikariCP-3.2.0.jar!/:na]
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155) ~[HikariCP-3.2.0.jar!/:na]
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-3.2.0.jar!/:na]
	at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:262) ~[spring-jdbc-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	... 16 common frames omitted

It takes 30 minutes to deplete the pool. After this point no connections are created and log is full of Connection is not available errors

ssttaarr avatar Feb 05 '20 12:02 ssttaarr

Any update on this?

wesoos avatar Feb 24 '20 03:02 wesoos 

"myCP connection adder" #38244 daemon prio=5 os_prio=0 tid=0x00007fa06c04c800 nid=0x11119 runnable [0x00007fa062c18000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
	at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
	at sun.nio.ch.IOUtil.read(IOUtil.java:197)
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:377)
	- locked <0x0000000084801418> (a java.lang.Object)
	at oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:144)
	at oracle.net.ns.NIOHeader.readHeaderBuffer(NIOHeader.java:82)
	at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:139)
	at oracle.net.ns.NIOPacket.readFromSocketChannel(NIOPacket.java:101)
	at oracle.net.ns.NIONSDataChannel.readDataFromSocketChannel(NIONSDataChannel.java:80)
	at oracle.net.ns.NIONSDataChannel.readPayloadDataFromSocketChannel(NIONSDataChannel.java:228)
	at oracle.net.ns.NIORedirectPacket.readPayloadBuffer(NIORedirectPacket.java:69)
	at oracle.net.ns.NIOPacket.readNIOPacket(NIOPacket.java:282)
	at oracle.net.ns.NSProtocolNIO.negotiateConnection(NSProtocolNIO.java:118)
	at oracle.net.ns.NSProtocol.connect(NSProtocol.java:317)
	at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1438)
	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:518)
	at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:688)
	at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:39)
	at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:691)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:95)
	at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:101)
	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:341)
	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:193)
	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:430)
	at com.zaxxer.hikari.pool.HikariPool.access$500(HikariPool.java:64)
	at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:570)
	at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:563)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

aoksenholt avatar Mar 27 '20 10:03 aoksenholt

We are seeing similar issues with , and badly affecting production. We print hikari stats often, and definitely it is not the case of connection leak. Please folks look into this, it looks like similar issues logged earlier, but not followed or concluded.

Please provide any update on this or guideline to workaround this issue without restarting application (ex: a way to restart datasource/hikari pool). Thanks.

cc: @brettwooldridge

Hikari - 3.3.1 openjdk - 11.0.8

Caused by: java.sql.SQLTransientConnectionException: HikariPool-2 - Connection is not available, request timed out after 30000ms.

at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:697) ~[HikariCP-3.3.1.jar:?]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196) ~[HikariCP-3.3.1.jar:?]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:161) ~[HikariCP-3.3.1.jar:?]
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100) ~[HikariCP-3.3.1.jar:?]
at com.myapp.server.datasource.SerializableDataSource.getConnection(SerializableDataSource.java:98) ~[myapp-database-dao-impl-20.4.0.jar:?]
at org.springframework.jdbc.datasource.lookup.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:170) ~[spring-jdbc-5.2.6.RELEASE.jar:5.2.6.RELEASE]
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:104) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:134) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:149) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:151) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:2091) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:2021) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1999) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.doQuery(Loader.java:953) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:354) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.doList(Loader.java:2825) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.doList(Loader.java:2807) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2639) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.Loader.list(Loader.java:2634) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:109) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1875) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:370) ~[hibernate-core-5.4.16.Final.jar:5.4.16.Final]
at org.springframework.orm.hibernate5.HibernateTemplate.lambda$loadAll$4(HibernateTemplate.java:547) ~[spring-orm-5.2.6.RELEASE.jar:5.2.6.RELEASE]
at org.springframework.orm.hibernate5.HibernateTemplate.doExecute(HibernateTemplate.java:385) ~[spring-orm-5.2.6.RELEASE.jar:5.2.6.RELEASE]
... 26 more

ashokpanchal avatar Sep 10 '21 04:09 ashokpanchal

We just had the exactly same issue as reported by ashokpanchal . IN our case for cutover or failover situation where multiple host are connected and the ones which fail are then no longer reachable because shutdown/replaced deallocated/ not available .. the connection which once was linked to this ip/host are froozen and can not be reused by the pool. The pool is decreased by this number of connections and so fore the scalability degraded until outage . This is a major issue. To repeat my predecessor.

Please provide any update on this or guideline to workaround this issue without restarting application (ex: a way to restart datasource/hikari pool). Thanks.

cforce avatar Feb 24 '22 13:02 cforce

Same issue exsts in my prouduction few years,hope some one can resolve it. I have switch to another high-performance pool long time, which was not found some similar issues, so advise to try ... , you can find out it in my fork list. Good lucky to all.

JoyceLikeRose avatar Feb 27 '22 01:02 JoyceLikeRose

Could you try to use driver manager to get a connection from the oracle database Instead of jdbctemplate.getConnection() Connection con = DriverManager.getConnection("URL", "USERNAME","PASSWORD");

CodeMSC avatar May 18 '22 10:05 CodeMSC

Hi Team, please help to the below query - Production issue

  1. Application - Java Spring boot
  2. Application code deployed in Azure PODS
  3. POD is losing the minimum idle connection of Hikari CP- from 10 to 0
  4. Every time only one of the POD is having exception as 500 - Unable to acquire while JDBC connection.
  5. Once the connection comes to 0- application is not responding & not able to create the new connection.
  6. If PODS are rollout- New PODS are deploying then application working for few days.
  7. Again, we are getting same issue for new PODS also as 500 exceptions Unable to acquire JDBC connection. image image

rindana avatar Feb 23 '23 13:02 rindana