【问题标题】:Why "Add connection elided, waiting 0, queue n"?为什么“添加连接被忽略,等待 0,队列 n”?
【发布时间】:2021-04-17 06:42:36
【问题描述】:

我已阅读此社区上发布的an answer,但我想,我的问题不是那样的。

我每天早上 8 点都有一份工作。两分钟内我的工作就完成了。但我面临一个问题。关闭连接后(因为 maxLifetime 已通过),有时会忽略添加新连接。然后我得到 Add connection elided。但过了一段时间,它在 Hikari 池中添加了新的连接。我给出了这些场景的一些日志:

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)

但是在那一天,从 17:45 到 18:03,除了一个之外的所有连接都被忽略了,因此 hikari 池中的总连接数变为 0。添加的连接在超过 maxLifetime 后被删除,并且无法' t 被添加(在 17:53:27.091)。我正在分享当时的日志:

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)

在 18:11,不知何故,它设法添加了一个连接。但是在通过 maxLifeTime 之后,该连接也被删除,从那时起三天没有新的连接进入 hikari 池,因此这 3 天的总连接数为 0。也分享该日志:

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)

重新启动应用程序后,hikari 现在共有 10 个连接,这是应该的。但我随时怀疑,它会创建以前的场景,并且会为每个新的连接添加获得 Add connection elided,因为我现在有时会得到这个,并且它也会在一段时间后添加连接(就像之前的场景一样)。任何想法,如何解决这个问题?为什么会有这种奇怪的行为?

编辑:

按照要求,共享应用程序的 hikari 配置:

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

【问题讨论】:

标签: spring-boot hikaricp


【解决方案1】:

消息来自此代码:

   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());
      }
   }

调用它的地方之一是 MaxLifetimeTask 运行时。当两个连接在时间上非常接近地达到最大生命周期时,您将看到这种“被忽略”的行为。

基本上,第一个过期的连接会排队一个“PoolEntryCreator”。 PoolEntryCreator 实际上会根据需要创建尽可能多的连接来维护池。因此,当 second 过期连接导致调用上述方法时,池会意识到 PoolEntryCreator 已经排队。因此,将另一个入队是不必要的 - 并且被省略了。

在您上面的日志中,我们可以在这里看到这一点,例如:

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

我不确定这与您所看到的问题有什么特别的关系。我确实看到的一个问题是添加新连接的队列不断增加

在 17:52:21.449 我们看到队列深度是 1,在 17:55:21.807 它是 2,在 17:55:24.141 它是3,到 18:03:26.669 时达到 9

添加一个新的(或几个)连接应该需要几毫秒,或者最多几秒钟,但队列会不断堆积。这意味着在 17:52:21.449 创建的 PoolEntryCreator 从未完成(退出)。

对我来说,这似乎是您问题的核心。 为什么无法创建新的连接?很可能它们被尝试,然后失败,然后被重试,并且创建尝试继续无限......

【讨论】:

    猜你喜欢
    • 2020-12-02
    • 2021-06-17
    • 1970-01-01
    • 1970-01-01
    • 2021-11-06
    • 2019-03-22
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多