Reputation: 1354
Spring Boot 2.1.2.
2 environments: local
(postgres 11) and qa
(docker swarm with postgres 10 and application)
After maxLifetime
passes, hikari recreates connections(closes old ones and creating new ones), but on qa
environment connections are not getting closed: checking with select * from pg_stat_activity wheredataname=...
and in logs we have:
2019-09-25 12:00:20.694 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@54d41592: (connection has passed maxLifetime)
2019-09-25 12:00:20.699 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@29e14ddb
2019-09-25 12:00:26.372 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@11684c62: (connection has passed maxLifetime)
2019-09-25 12:00:26.376 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@453f8d6c
2019-09-25 12:00:28.130 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@1b2ef2bc: (connection has passed maxLifetime)
2019-09-25 12:00:28.135 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4bf86bbb
2019-09-25 12:00:28.459 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@34fbeadd: (connection has passed maxLifetime)
2019-09-25 12:00:28.464 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4fc7e61c
2019-09-25 12:00:31.962 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@40771fc4: (connection has passed maxLifetime)
2019-09-25 12:00:31.966 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@ac56180
2019-09-25 12:00:35.600 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@65cae248: (connection has passed maxLifetime)
2019-09-25 12:00:35.607 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@33a8d959
2019-09-25 12:00:35.649 WARN 6 --- [ scheduling-1] c.z.h.p.PoolBase : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@15e91fa9 (This connection has been closed.). Possibly consider using a shorter maxLifetime value.
2019-09-25 12:00:35.650 WARN 6 --- [ scheduling-1] c.z.h.p.PoolBase : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@11d699cc (This connection has been closed.). Possibly consider using a shorter maxLifetime value.
2019-09-25 12:00:35.651 WARN 6 --- [ scheduling-1] c.z.h.p.PoolBase : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@3883b6a6 (This connection has been closed.). Possibly consider using a shorter maxLifetime value.
2019-09-25 12:00:35.652 WARN 6 --- [ scheduling-1] c.z.h.p.PoolBase : HikariPool-1 - Failed to validate connection org.postgresql.jdbc.PgConnection@230234a5 (This connection has been closed.). Possibly consider using a shorter maxLifetime value.
2019-09-25 12:00:35.657 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@15e91fa9: (connection is dead)
2019-09-25 12:00:35.657 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@11d699cc: (connection is dead)
2019-09-25 12:00:35.657 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@3883b6a6: (connection is dead)
2019-09-25 12:00:35.658 DEBUG 6 --- [nnection closer] c.z.h.p.PoolBase : HikariPool-1 - Closing connection org.postgresql.jdbc.PgConnection@230234a5: (connection is dead)
2019-09-25 12:00:35.674 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@3b85c924
2019-09-25 12:00:35.678 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@4b022f4e
2019-09-25 12:00:35.686 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@6aea9ecf
2019-09-25 12:00:35.691 DEBUG 6 --- [onnection adder] c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@1ffdf0da
Why connections are not getting closed?
Edit: Hikari config:
c.z.h.HikariConfig : HikariPool-1 - configuration:
c.z.h.HikariConfig : allowPoolSuspension.............false
c.z.h.HikariConfig : autoCommit......................true
c.z.h.HikariConfig : catalog.........................none
c.z.h.HikariConfig : connectionInitSql...............none
c.z.h.HikariConfig : connectionTestQuery.............none
c.z.h.HikariConfig : connectionTimeout...............30000
c.z.h.HikariConfig : dataSource......................none
c.z.h.HikariConfig : dataSourceClassName.............none
c.z.h.HikariConfig : dataSourceJNDI..................none
c.z.h.HikariConfig : dataSourceProperties............{password=<masked>}
c.z.h.HikariConfig : driverClassName................."org.postgresql.Driver"
c.z.h.HikariConfig : healthCheckProperties...........{}
c.z.h.HikariConfig : healthCheckRegistry.............none
c.z.h.HikariConfig : idleTimeout.....................600000
c.z.h.HikariConfig : initializationFailTimeout.......1
c.z.h.HikariConfig : isolateInternalQueries..........false
c.z.h.HikariConfig : jdbcUrl.........................jdbc:postgresql://postgres/db
c.z.h.HikariConfig : leakDetectionThreshold..........0
c.z.h.HikariConfig : maxLifetime.....................1800000
c.z.h.HikariConfig : maximumPoolSize.................10
c.z.h.HikariConfig : metricRegistry..................none
c.z.h.HikariConfig : metricsTrackerFactory...........none
c.z.h.HikariConfig : minimumIdle.....................10
c.z.h.HikariConfig : password........................<masked>
c.z.h.HikariConfig : poolName........................"HikariPool-1"
c.z.h.HikariConfig : readOnly........................false
c.z.h.HikariConfig : registerMbeans..................false
c.z.h.HikariConfig : scheduledExecutor...............none
c.z.h.HikariConfig : schema..........................none
c.z.h.HikariConfig : threadFactory...................internal
c.z.h.HikariConfig : transactionIsolation............default
c.z.h.HikariConfig : username........................"username"
c.z.h.HikariConfig : validationTimeout...............5000
c.z.h.HikariDataSource : HikariPool-1 - Starting...
c.z.h.p.HikariPool : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@53fd0d10
c.z.h.HikariDataSource : HikariPool-1 - Start completed.
o.f.c.i.d.DatabaseFactory : Database: jdbc:postgresql://postgres/db (PostgreSQL 10.10)
Upvotes: 8
Views: 18149
Reputation: 1354
Solved by setting maxLifetime
to 10 minutes.
Explanation: It turns out docker swarm somehow drops idle connection. So, when hikari closes connection, nothing reaches postgres, so from postgres standpoint there is still a connection. 10 minutes is less that default docker idle connection timeout, so connections are closed properly.
Upvotes: 14