GoogleCloudPlatform / GoogleCloudPlatform/cloud-spanner-r2dbc
r2dbc pool background eviction causes DatabaseClientReactiveAdapter to close
- 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
Assessment
This issue has not been assessed yet.