如何正确配置 HikariCP 以处理必须保持活动状态的连接？

Question

我正在使用 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

侦听器可以正常工作，但一天或多天后出现以下错误：

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 或更改我的代码才能避免所描述的错误？希望能帮到你。

Answer 1

不是同一个问题，但我遇到了类似的问题。当我的数据库重新启动时，Hikari 无法关闭活动侦听器连接，整个通知停止工作。

我找到了一个可能的解决方案。 Hikari 死机时无法关闭连接的原因是因为您正在从此处的代理连接解包连接：

DataSourceUtils.getConnection(dataSource).unwrap(PGConnection::class.java)

在此之后，您将一个 notificationListener 附加到 PGConnection，因此它保持活动状态。

首先要避免 hikaripool 泄漏，您应该分离 2 个连接，并在初始化侦听器后关闭 hikariConnection。

private hikariConnection: Connection;

...

hikariConnection = DataSourceUtils.getConnection(dataSource)
val pgConnection: PGConnection = hikariConnection.unwrap(PGConnection::class.java)

... init the listener
hikariConnection.close()

并且在 PGNotificationListener.closed() 中，您必须重新初始化侦听器，从数据源获取新的连接。但要注意，在 Hikaripool 填充它的池时获取新连接（因为数据库中断只有几秒钟），可能会互相阻塞。我们通过在专用的新线程上获取新连接来解决它。

 override fun closed() {
            ... get a new PGConnection, and start listening for the notifications
    }

抱歉，如果它没有正确回答您的问题，但它可能对某些人有所帮助。

如何正确配置 HikariCP 以处理必须保持活动状态的连接？

How do I configure HikariCP correctly to work with connections that have to stay active?

spring-data

spring-data-jpa

kotlin

hikaricp

pgjdbc-ng