GoogleCloudPlatform / GoogleCloudPlatform/cloud-spanner-r2dbc

r2dbc pool background eviction causes DatabaseClientReactiveAdapter to close

Open
#789 1 comment 1 reaction 0 assignees View on GitHub
enhancement P2
Dominant language
Java
Stars
60
Forks
31
PR merge metrics
No merged PRs in 30d

Description

When using `com.google.cloud:cloud-spanner-spring-data-r2dbc:1.2.2` and `com.google.cloud:cloud-spanner-r2dbc:1.3.0` there is a property pre-configured in r2dbc-pool (`spring.r2dbc.pool.max-idle-time`, default value is `30m`). This property configures how long a connection should be idle within the r2dbc connection pool before it is removed. The reactor pool is removing the idle connections from the pool, which calls the `close` method on `DatabaseClientReactiveAdapter` and sets `DatabaseClientReactiveAdapter.active` to `false`. When subsequent requests (including health checks) are sent to Spanner, the following exception is being thrown and there is no way to recover from it. This behavior can easily and quickly be triggered by setting `spring.r2dbc.pool.max-idle-time` to `30s` (or some other small duration).

```
io.r2dbc.spi.R2dbcNonTransientResourceException: Connection validation failed
at io.r2dbc.pool.Validation.lambda$validate$2(Validation.java:45) ~[r2dbc-pool-1.0.1.RELEASE.jar:1.0.1.RELEASE]
Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
Assembly trace from producer [reactor.core.publisher.FluxHandleFuseable] :
reactor.core.publisher.Flux.handle(Flux.java:6041)
io.r2dbc.pool.Validation.validate(Validation.java:38)
Error has been observed at the following site(s):
*__________Flux.handle ⇢ at io.r2dbc.pool.Validation.validate(Validation.java:38)
|_ Flux.then ⇢ at io.r2dbc.pool.Validation.validate(Validation.java:46)
*______Mono.thenReturn ⇢ at io.r2dbc.pool.ConnectionPool.getValidConnection(ConnectionPool.java:176)
|_ Mono.onErrorResume ⇢ at io.r2dbc.pool.ConnectionPool.lambda$null$5(ConnectionPool.java:140)
*____________Mono.then ⇢ at io.r2dbc.pool.ConnectionPool.lambda$null$3(ConnectionPool.java:140)
*_________Mono.flatMap ⇢ at io.r2dbc.pool.ConnectionPool.lambda$new$12(ConnectionPool.java:115)
*___________Mono.defer ⇢ at io.r2dbc.pool.ConnectionPool.(ConnectionPool.java:112)
|_ Mono.retry ⇢ at io.r2dbc.pool.ConnectionPool.(ConnectionPool.java:172)
*_______Mono.usingWhen ⇢ at org.springframework.boot.actuate.r2dbc.ConnectionFactoryHealthIndicator.validateWithConnectionValidation(ConnectionFactoryHealthIndicator.java:95)
|_ Mono.map ⇢ at org.springframework.boot.actuate.r2dbc.ConnectionFactoryHealthIndicator.validateWithConnectionValidation(ConnectionFactoryHealthIndicator.java:98)
|_ Mono.defaultIfEmpty ⇢ at org.springframework.boot.actuate.r2dbc.ConnectionFactoryHealthIndicator.doHealthCheck(ConnectionFactoryHealthIndicator.java:73)
Original Stack Trace:
at io.r2dbc.pool.Validation.lambda$validate$2(Validation.java:45) ~[r2dbc-pool-1.0.1.RELEASE.jar:1.0.1.RELEASE]
at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:179) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSupplier$MonoSupplierSubscription.request(MonoSupplier.java:145) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.request(FluxHandleFuseable.java:260) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoIgnoreElements$IgnoreElementsSubscriber.onSubscribe(MonoIgnoreElements.java:72) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onSubscribe(FluxHandleFuseable.java:164) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSupplier.subscribe(MonoSupplier.java:48) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.11.jar:3.5.11]
at io.r2dbc.pool.MonoDiscardOnCancel.subscribe(MonoDiscardOnCancel.java:50) ~[r2dbc-pool-1.0.1.RELEASE.jar:1.0.1.RELEASE]
at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.pool.AbstractPool$Borrower.deliver(AbstractPool.java:467) ~[reactor-pool-1.0.3.jar:1.0.3]
at reactor.pool.SimpleDequePool.lambda$drainLoop$9(SimpleDequePool.java:425) ~[reactor-pool-1.0.3.jar:1.0.3]
at reactor.core.publisher.FluxDoOnEach$DoOnEachSubscriber.onNext(FluxDoOnEach.java:154) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.FluxDoOnEach$DoOnEachFuseableSubscriber.onNext(FluxDoOnEach.java:281) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSubscribeOn$SubscribeOnSubscriber.onNext(MonoSubscribeOn.java:146) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2545) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSubscribeOn$SubscribeOnSubscriber.trySchedule(MonoSubscribeOn.java:189) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSubscribeOn$SubscribeOnSubscriber.onSubscribe(MonoSubscribeOn.java:134) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.publisher.MonoSubscribeOn$SubscribeOnSubscriber.run(MonoSubscribeOn.java:126) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:84) ~[reactor-core-3.5.11.jar:3.5.11]
at reactor.core.scheduler.WorkerTask.call(WorkerTask.java:37) ~[reactor-core-3.5.11.jar:3.5.11]
at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:317) ~[na:na]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[na:na]
at java.base/java.lang.Thread.run(Thread.java:1583) ~[na:na]
```

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.