r2dbc / r2dbc-pool

Connection Pooling for Reactive Relational Database Connectivity
https://r2dbc.io
Apache License 2.0
332 stars 55 forks source link

After some kind of situation, PooledConnection never be released, any sql request will timeout #128

Closed leewp closed 3 years ago

leewp commented 3 years ago

Bug Report

Versions

Current Behavior

I used spring boot with spring data r2dbc build a service, approximately 5,000,000 requests(select and update) per day 。First, everything is ok, but after 3-7 days,any requests will time out ,from spring boot 2.3.x to now, every time the version is updated, I will try to see if it solves the problem . Until now(spring boot 2.5.0), the problem exist.

So I spent some time to study the source code of r2dbc-pool,then I found when problem happend,
the value of

connectionPool.getMetrics()

is alway

"idleSize": 0,
"acquiredSize": 10,
"allocatedSize": 10,
"pendingAcquireSize": 0,
"maxAllocatedSize": 10,

the acquired 10 connection never be released, so any sql request will be timeout.

Stack trace ``` org.springframework.dao.DataAccessResourceFailureException: Failed to obtain R2DBC Connection; nested exception is io.r2dbc.spi.R2dbcTimeoutException: Connection Acquisition timed out after 5000ms ```

It's easy to reproduce the problem in my production environment , spend some time, I found a way where the problem can be reproduced, I give the test conditions below.

Table schema

Input Code ``` CREATE TABLE `demo` ( `id` bigint NOT NULL AUTO_INCREMENT COMMENT 'id', `name` varchar(255) NOT NULL, PRIMARY KEY (`id`) ) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8mb4 COMMENT='demo table'; ```

Steps to reproduce

The following code is only used to simulate the problem ,It's just one kind of situation that reproduce the problem , and it's different from my production environment .

Maybe it's bug of spring data r2dbc, maybe it's bug of reactor

Input Code ```java DemoRepository.java //It is only used to simulate a certain situation and has no practical meaning @Query("select sleep(0.1)") Mono testSleep(); DemoController.java @GetMapping("testSleep") public Mono testSleep() { return demoRepository.testSleep().thenReturn("test"); } @GetMapping("poolInfo") public PoolInfo poolInfo() { return deviceService.getPoolInfo(); } PoolInfo.java @Getter @Builder public class PoolInfo { private int idleSize; private int acquiredSize; private int allocatedSize; private int pendingAcquireSize; private int maxAllocatedSize; } DeviceService.java @Autowired private ConnectionPool connectionPool; public PoolInfo getPoolInfo() { return connectionPool.getMetrics().map(poolMetrics -> PoolInfo .builder() .idleSize(poolMetrics.idleSize()) .allocatedSize(poolMetrics.allocatedSize()) .acquiredSize(poolMetrics.acquiredSize()) .pendingAcquireSize(poolMetrics.pendingAcquireSize()) .maxAllocatedSize(poolMetrics.getMaxAllocatedSize()) .build()) .get(); } application.yml spring: r2dbc: pool: max-idle-time: 10m max-life-time: 2h //The key point to reproduce the problem max-acquire-time: 1s // the use ab to test // ab -c 5000 -n 50000 -s 5 http://127.0.0.1:8096/demo/testSleep // after finished ab test //i found the response of http://127.0.0.1:8096/device/poolInfo is alway "idleSize": 4, "acquiredSize": 6, "allocatedSize": 10, "pendingAcquireSize": 0, "maxAllocatedSize": 10, ``` //the acquired 6 connection never be release (I refresh the brower more than 20 times) //maybe do ab test again, the acquiredSize will be 10 and never be released

Expected behavior/code

I expect the idleSize is 10 and acquiredSize is 0 when no sql request, but now I found some pooledConnection never be released

Possible Solution

I like reactive, like webflux, like r2dbc , but this problem caused my program to died(always timeout, can't read or save data) several times. for use r2dbc in my project, I found a solution suitable for my project , add a timer check in PooledConnection(PooledRef ref)

 // added for release check
//make sure the pooled connection  be closed, may be longer time will be better!
        checkReleaseDisposable = Mono.delay(Duration.ofMinutes(10))
                .filter(closed -> !this.closed)
                .doOnNext(aLong -> logger.info("after 10m, connection not be closed, now release it (use disposable)"))
                .flatMap(aLong -> this.release)
                .subscribe();

and dispose it when PooledConnection.release is subscribed

this.release = Mono.defer(() -> {
            return Validation.validate(this, ValidationDepth.LOCAL).then(Mono.defer(() -> {

                Mono<Void> cleanup = Mono.empty();
                if (this.inTransaction) {
                    cleanup = rollbackTransaction().onErrorResume(throwable -> Mono.empty()).then();
                }

                return cleanup.doOnSubscribe(ignore -> this.closed = true)
                        .then(this.ref.release())
                        // added for release check
                        //cancel the timer(delay) check, because it's already be released
                        .doFinally(signalType -> {
                            if (checkReleaseDisposable != null && !checkReleaseDisposable.isDisposed()) {
                                checkReleaseDisposable.dispose();
                            }
                        });

            })).onErrorResume(throwable -> ref.invalidate()).doOnSubscribe(subscription -> logger.debug("Releasing connection"));
        });

After 24h, I found some

after 10m, connection not be closed, now release it (use disposable)

in spring.log and the idleSize will often be 10, now it looks like no pooled connection never be release, I will report the result after 7 days

Additional context

leewp commented 3 years ago

sigh, connection pool acquired size will be -1

leewp commented 3 years ago

Now I use this.ref.release , not this.release, the program runs normally more than 48h

   Mono.delay(Duration.ofMinutes(2))
            .doOnSubscribe(subscription -> checkReleaseSubscription = subscription)
            .filter(closed -> !this.closed)
            .doOnNext(aLong -> logger.info("after 2m, connection not be closed, now release it (use subscription and ref.release)"))
            .flatMap(aLong -> this.ref.release())
            .subscribe();
leewp commented 3 years ago

Thanks, I learned a lot from r2dbc-pool, it's a great project.

With my modification, my program runs normally more than 7 days, It's work for me, and I will use r2dbc in my all new project.

Now I close this issue, when u want to fix it, or need my help, just open it.