0

I have read an answer posted on this community, but I guess, my issue is not like that.

I have a job scheduled at 8 AM every day. Within two minutes my job becomes finished. But I am facing an issue. After closing the connection(because maxLifetime passed), sometimes adding new connection is being elided. I get Add connection elided then. But after some times, it adds new connection in Hikari pool. I am giving some log of those scenarios:

2021-01-09 05:07:59.606 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=10, active=0, idle=10, waiting=0)
2021-01-09 05:07:59.606 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 05:08:12.535 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@2f5f578e: (connection has passed maxLifetime)
2021-01-09 05:08:12.606 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@65d1a1ad: (connection has passed maxLifetime)
2021-01-09 05:08:12.606 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 1
2021-01-09 05:08:12.624 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4f0ee473
2021-01-09 05:08:12.708 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@41c903e2
2021-01-09 05:08:12.708 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
2021-01-09 05:08:17.504 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@6b165367: (connection has passed maxLifetime)
2021-01-09 05:08:17.578 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@45f68f03
2021-01-09 05:08:29.606 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=10, active=0, idle=10, waiting=0)
.
.
2021-01-09 11:42:59.907 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=10, active=0, idle=10, waiting=0)
2021-01-09 11:42:59.907 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 11:43:04.584 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@3b711873: (connection has passed maxLifetime)
2021-01-09 11:43:04.587 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@35b6e0b5: (connection has passed maxLifetime)
2021-01-09 11:43:04.587 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 1
2021-01-09 11:43:04.644 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4ac53bd7
2021-01-09 11:43:04.733 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4402dcff
2021-01-09 11:43:04.733 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
.
.
2021-01-09 14:50:30.056 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=10, active=0, idle=10, waiting=0)
2021-01-09 14:50:30.056 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 14:50:37.520 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@4e009619: (connection has passed maxLifetime)
2021-01-09 14:50:37.608 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@66c98217
2021-01-09 14:50:52.216 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@3e0aefb: (connection has passed maxLifetime)
2021-01-09 14:50:52.220 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@d2740f7: (connection has passed maxLifetime)
2021-01-09 14:50:52.220 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 1
2021-01-09 14:50:52.284 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@5a94a52b
2021-01-09 14:50:52.375 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@54535009
2021-01-09 14:50:52.375 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)

But on that day, from 17:45 to 18:03, all connection addition but one gets elided, and thus total connections in hikari pool becomes 0. The one which was added, was removed after passing maxLifetime, and couldn't get added(at 17:53:27.091). I am sharing log of that time:

2021-01-09 17:45:37.135 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
2021-01-09 17:45:47.379 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@3e7ef8f0: (connection has passed maxLifetime)
2021-01-09 17:46:00.208 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:46:00.208 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:46:00.208 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:46:30.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:46:30.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:46:30.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:47:00.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:47:00.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:47:00.209 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
.(same stat)
.(same stat)
2021-01-09 17:51:30.212 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:51:30.212 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:51:30.212 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:52:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:52:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=9, active=0, idle=9, waiting=0)
2021-01-09 17:52:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:52:21.449 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 1
2021-01-09 17:52:21.450 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@6588afc6: (connection has passed maxLifetime)
2021-01-09 17:52:30.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:52:30.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:52:30.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:52:37.340 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 2
2021-01-09 17:52:37.340 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@6b4f5d07: (connection has passed maxLifetime)
2021-01-09 17:53:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=7, active=0, idle=7, waiting=0)
2021-01-09 17:53:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=7, active=0, idle=7, waiting=0)
2021-01-09 17:53:00.213 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:53:27.091 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@7a0cfa05
2021-01-09 17:53:30.214 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:53:30.214 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:53:30.214 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
.(same stat)
.(same stat)
2021-01-09 17:55:00.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:55:00.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=8, active=0, idle=8, waiting=0)
2021-01-09 17:55:00.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:55:21.807 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 2
2021-01-09 17:55:21.808 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@2a72573c: (connection has passed maxLifetime)
2021-01-09 17:55:24.141 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 3
2021-01-09 17:55:24.141 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@6f70c4b6: (connection has passed maxLifetime)
2021-01-09 17:55:24.463 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@aa42b2b: (connection has passed maxLifetime)
2021-01-09 17:55:24.463 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 4
2021-01-09 17:55:25.278 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 5
2021-01-09 17:55:25.278 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@72aedaad: (connection has passed maxLifetime)
2021-01-09 17:55:25.549 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 6
2021-01-09 17:55:25.549 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@1b92f81d: (connection has passed maxLifetime)
2021-01-09 17:55:26.077 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@610b2f60: (connection has passed maxLifetime)
2021-01-09 17:55:26.077 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 7
2021-01-09 17:55:30.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=2, active=0, idle=2, waiting=0)
2021-01-09 17:55:30.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=2, active=0, idle=2, waiting=0)
2021-01-09 17:55:30.215 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 17:55:30.696 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@4a5da873: (connection has passed maxLifetime)
2021-01-09 17:55:30.696 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 8
2021-01-09 17:56:00.216 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 17:56:00.216 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 17:56:00.216 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
.(same stat)
.(same stat)
2021-01-09 18:02:30.220 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:02:30.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:02:30.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 18:03:00.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:03:00.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:03:00.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 18:03:26.669 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 9
2021-01-09 18:03:26.669 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@7a0cfa05: (connection has passed maxLifetime)
2021-01-09 18:03:30.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=0, active=0, idle=0, waiting=0)
2021-01-09 18:03:30.221 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=0, active=0, idle=0, waiting=0)

At 18:11, somehow it managed to add a connection. But after passing maxLifeTime that connection was also removed and from then for three days no new connection had come into the hikari pool, thus total connection was 0 for these 3 days. Sharing that log too:

2021-01-09 18:11:30.227 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=0, active=0, idle=0, waiting=0)
2021-01-09 18:11:30.228 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 18:11:42.352 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:728 - HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@74cb0b34
2021-01-09 18:11:42.352 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After adding stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:12:00.228 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:12:00.228 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=1, active=0, idle=1, waiting=0)
.(same stat)
.(same stat)
2021-01-09 18:21:00.234 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:21:00.234 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - After cleanup  stats (total=1, active=0, idle=1, waiting=0)
2021-01-09 18:21:00.234 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:517 - HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-01-09 18:21:29.887 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 9
2021-01-09 18:21:29.887 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@74cb0b34: (connection has passed maxLifetime)
2021-01-09 18:21:30.235 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:421 - HikariPool-1 - Before cleanup stats (total=0, active=0, idle=0, waiting=0)

After restarting the application, hikari has now total 10 connections which is supposed to have. But I am suspecting at any time, it will create the previous scenario and will get the Add connection elided for every new connection addition as I am getting this now sometimes and it is adding connection after some times as well(just like previous scenario). Any idea, how to solve this issue? Why this strange behavior?

Edit:

As asked, sharing the hikari config for the application:

spring.datasource.hikari.connection-timeout=5000
spring.datasource.hikari.maximumPoolSize=50
spring.datasource.hikari.minimumIdle=10
spring.datasource.hikari.idleTimeout=599000
spring.datasource.hikari.leak-detection-threshold=540000
Mukit09
  • 2,956
  • 3
  • 24
  • 44
  • 1
    I have exactly the same problem (and it seems it is not only us: https://github.com/brettwooldridge/HikariCP/issues/1702 (reported month ago) and https://github.com/brettwooldridge/HikariCP/issues/1710 (reported 20 days ago)) I am using Amazon RDS Aurora PostgreSQL 10 database, Spring Boot 2.2.11 and Hikari 3.4.5 – Infinity Jan 19 '21 at 10:03
  • Could you share your Hikari configurations from application.properties file? so that everyone can understand your configuration and provide some solutions. – Lokesh Jan 20 '21 at 04:36
  • @Lokesh, shared man. – Mukit09 Jan 20 '21 at 06:46

1 Answers1

1

The message comes from this code:

   public void addBagItem(final int waiting) {
      final boolean shouldAdd = waiting - addConnectionQueueReadOnlyView.size() >= 0; // Yes, >= is intentional.
      if (shouldAdd) {
         addConnectionExecutor.submit(poolEntryCreator);
      }
      else {
         logger.debug("{} - Add connection elided, waiting {}, queue {}", poolName, waiting, addConnectionQueueReadOnlyView.size());
      }
   }

One of the places this is called is when the MaxLifetimeTask runs. When two connections reach max lifetime very closely in time, you will see this "elided" behavior.

Basically, the first expired connection will queue up a "PoolEntryCreator". The PoolEntryCreator will actually create as many connections as necessary to maintain the pool. So, when the second expired connection causes the above method to be called, the pool realizes that a PoolEntryCreator is already queued up. Therefore, enqueueing another one is unnecessary -- and is elided.

In your log above, we can see this here, for example:

2021-01-09 05:08:12.535 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@2f5f578e: (connection has passed maxLifetime)
2021-01-09 05:08:12.606 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase:134 - HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@65d1a1ad: (connection has passed maxLifetime)
2021-01-09 05:08:12.606 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool:342 - HikariPool-1 - Add connection elided, waiting 0, queue 1

I am not sure this has anything particularly to do with the issue you are seeing. What I do see as an issue is that the queue to add new connections keeps increasing.

At 17:52:21.449 we see that the queue depth is 1, at 17:55:21.807 it is 2, at 17:55:24.141 it is 3, and by 18:03:26.669 it is up to 9.

Adding a new (or few) connections should take milliseconds, or seconds at most, and yet the queue keeps piling up. This implies that the PoolEntryCreator created at 17:52:21.449 never completed (exited).

This to me seems like the heart of your issue. Why are new connections failing to be created? It is likely they are attempted, and then fail, and are retried, and the creation attempts continue on to infinity...

brettw
  • 10,664
  • 2
  • 42
  • 59