Spring Boot 2.4.0 と Spring Boot Data JPA を使用して PostgreSQL に接続し、JPA ベースのリポジトリで典型的な読み取りおよび書き込み操作を実行しています。データベースは他のサービスでも使用されるため、LISTEN/NOTIFY 機能 ( https://www.postgresql.org/docs/9.1/sql-listen.html ) を使用して、PostgeSQL からの変更について通知を受けます。このためcom.impossibl.postgres.jdbc.PGDriverに、デフォルトのドライバーの代わりにドライバーを使用し、次のコードを使用して、Spring がデータベースへの変更をリッスンするようにします。
@Service
class PostgresChangeListener(
val dataSource: HikariDataSource,
@Qualifier("dbToPGReceiverQueue") val postgresQueue: RBlockingQueue<String>
) {
init {
listenToNotifyMessage()
}
final fun listenToNotifyMessage() {
val notificationListener = object:PGNotificationListener {
override fun notification(processId: Int, channelName: String, payload: String) {
log.info("Received change from PostgresQL: $processId, $channelName, $payload")
postgresQueue.add(payload)
}
override fun closed() {
log.debug("Connection to Postgres lost! Try to reconnect...")
listenToNotifyMessage()
}
}
try {
val connection = DataSourceUtils.getConnection(dataSource).unwrap(PGConnection::class.java)
connection.addNotificationListener(notificationListener)
connection.createStatement().use { statement -> statement.execute("LISTEN change_notifier;") }
} catch (e: SQLException) {
throw RuntimeException(e)
}
}
}
これは、ここで説明されているリスナーの Kotlin のような実装です: https://impossibl.github.io/pgjdbc-ng/docs/current/user-guide/#extensions-notifications
リスナーは機能しますが、1 日以上後に次のエラーが発生します。
2021-03-03 06:33:00.185 WARN 1 --- [nio-8080-exec-8] o.s.b.a.jdbc.DataSourceHealthIndicator : DataSource health check failed
org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30001ms.
...
問題を見つけるために、 https://github.com/brettwooldridge/HikariCP/issues/1111#issuecomment-569552070で推奨されているように、Hikari からのログを有効にしました。ログの抜粋の出力を次に示します。
2021-03-02 21:31:59.055 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
...
2021-03-02 21:31:59.055 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
2021-03-02 22:00:53.139 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@201ab69f: (connection has passed maxLifetime)
2021-03-02 22:00:53.162 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@f2ffd1ea
2021-03-02 22:00:54.709 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@3bb847ef: (connection has passed maxLifetime)
2021-03-02 22:00:54.730 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@fd5932d7
2021-03-02 22:00:59.110 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
2021-03-02 22:00:59.111 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-03-02 22:01:04.782 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@1d081266: (connection has passed maxLifetime)
2021-03-02 22:01:04.803 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@e0b396bc
2021-03-02 22:01:09.295 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@a2b0bd29: (connection has passed maxLifetime)
2021-03-02 22:01:09.313 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@ca9c8226
2021-03-02 22:01:10.075 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@ec8746aa: (connection has passed maxLifetime)
2021-03-02 22:01:10.093 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@aff2bfd8
2021-03-02 22:01:12.820 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@a7e0fc39: (connection has passed maxLifetime)
2021-03-02 22:01:12.840 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@d637554
2021-03-02 22:01:15.099 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@dadcba66: (connection has passed maxLifetime)
2021-03-02 22:01:15.119 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@e29805ef
2021-03-02 22:01:21.558 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@762f0753: (connection has passed maxLifetime)
2021-03-02 22:01:21.576 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@d5b8d008
2021-03-02 22:01:23.351 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@5e4721b0: (connection has passed maxLifetime)
2021-03-02 22:01:23.370 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@a8606b56
2021-03-02 22:01:29.111 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
2021-03-02 22:01:29.111 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-03-02 22:01:59.112 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
...
私にとってはログは正しいように見えますが、しばらくするとアクティブな接続がますます増加します...
...
2021-03-03 06:31:29.664 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=9, idle=1, waiting=0)
2021-03-03 06:31:48.687 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : HikariPool-1 - Closing connection com.impossibl.postgres.jdbc.PGDirectConnection@4fa5ec41: (connection is dead)
2021-03-03 06:31:48.707 DEBUG 1 --- [onnection adder] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.impossibl.postgres.jdbc.PGDirectConnection@693052fe
2021-03-03 06:31:48.709 DEBUG 1 --- [nnection closer] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-03-03 06:31:59.665 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=10, idle=0, waiting=1)
2021-03-03 06:31:59.665 DEBUG 1 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Fill pool skipped, pool is at sufficient level.
2021-03-03 06:32:20.199 DEBUG 1 --- [io-8080-exec-10] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Timeout failure stats (total=10, active=10, idle=0, waiting=2)
2021-03-03 06:32:20.208 WARN 1 --- [io-8080-exec-10] o.s.b.a.jdbc.DataSourceHealthIndicator : DataSource health check failed
org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
...
...説明されているエラーメッセージになるまで。
説明されているエラーを回避するには、どのように Hikari を正しく構成するか、コードを変更する必要があるのだろうか? お役に立てれば幸いです。