1

我正在使用带有 Spring Boot Data JPA 的 Spring Boot 2.4.0 连接到 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 或更改我的代码以避免所描述的错误？我希望你能帮忙。

4

1 回答 1

4

不是同一个问题，但我有一个类似的问题。当我的数据库重新启动时，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
    }

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

于 2021-04-22T08:50:20.617 回答