GV

GeezerVison

The World Wide Web, restored to 800 pixels of glory.

Home|About|Gaming cabinet|Archives|How it works|Starter sites

On this site

  • Sign in
  • ActionsCI/CD and automation
  • CodespacesCloud development environments
  • All Features
  • Documentation
  • Training
  • Certifications
  • Build with Copilot
  • Customize Copilot
  • Integrations
  • Trending repos
  • GitHub Sponsors
  • Developer articles
  • Enterprises

This view

  • Original page
  • New address

GeezerVison is showing github.com — [r2dbc-mysql] Occasional error when acquiring a new connection from the connection pool · Issue #421 · jasync-sql/jasync-sql

[r2dbc-mysql] Occasional error when acquiring a new connection from the connection pool #421

New issue
Copy link
New issue
Copy link
Open
Open
[r2dbc-mysql] Occasional error when acquiring a new connection from the connection pool#421
Copy link

Description

@knuclechan
knuclechan
opened on Nov 8, 2023
Issue body actions

Bug Report

I am using r2dbc-pool with jasync-mysql and spring. The application is a web application.
I have been experienced error when getting database connection occasionally. I suspect that it is due to the reactor subscription being cancelled. (Eg. web connection is closed)

Versions

jasync-mysql-2.2.4
jasync-pool-2.2.4
r2dbc-pool 1.0.1
r2dbc-spi 1.0.0
reactor-pool-1.0.1
spring-r2dbc 6.0.11
java 17.0.1

Current Behavior

When creating a new connection, it will set the transaction isolation level
When borrowing a connection, it will test the connection by running a query select 1
But occasionly it strangely test the connection twice and run into ConnectionStillRunningQueryException error

And You can see in the log, the connection

  1. Set isolation level
  2. Test connection
  3. Test connection again (without waiting for the first test to finish)
  4. ConnectionStillRunningQueryException error

ps. I have retry logic if it fails to acquire connection. You may ignore that in the log

From the stacktrace, I notice a line
at io.r2dbc.pool.MonoDiscardOnCancel.subscribe(MonoDiscardOnCancel.java:50) ~[r2dbc-pool-1.0.1.RELEASE.jar!/:1.0.1.RELEASE]
which may indicate the second test is triggered by a cancel subscription.
I suspect that, when the reactor subscription is cancelled, it will test the connection before returning it to the pool. But as there's running query there, it causes a concurrent running issue.

The init code of the ConnectionFactory

ConnectionFactoryOptions.Builder builder = ConnectionFactoryOptions.builder()
				.option(DRIVER, "pool")
				.option(PROTOCOL, "mysql")
				.option(HOST, host)
				.option(PORT, port)
				.option(USER, username)
				.option(PASSWORD, password)
				.option(DATABASE, schema)
				.option(Option.valueOf("applicationName"), this.getClass().getSimpleName())
				.option(Option.valueOf("initialSize"), initialSize)
				.option(Option.valueOf("maxSize"), maxSize)
				.option(Option.valueOf("backgroundEvictionInterval"), Duration.ofMinutes(1))
				.option(Option.valueOf("minIdle"), initialSize)
				.option(Option.valueOf("maxIdleTime"), maxIdleTime)
				.option(Option.valueOf("maxAcquireTime"), Duration.ofMillis(2000L))
				.option(Option.valueOf("maxLifeTime"), Duration.ofHours(4L))
				.option(Option.<Function<? super Connection, ? extends Publisher<Void>>>valueOf("postAllocate"), this::initIsolationLevel)
				.option(Option.valueOf("validationDepth"), ValidationDepth.REMOTE)
				.option(Option.valueOf("validationQuery"), "select 1");
Detailed Log and Stack Trace
2023-11-01 12:22:52	
11-01 04:22:52 DEBUG - <mysql-connection-63> Connected to database (?:)
2023-11-01 12:22:52	
11-01 04:22:52 TRACE - <mysql-connection-63> sendQuery() - SET SESSION TRANSACTION ISOLATION LEVEL READ COMMITTED (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - <mysql-connection-63> sendQuery() - select 1 (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - <mysql-connection-63> sendQuery() - select 1 (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - close connection <mysql-connection-63> (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - send quit message <mysql-connection-63> (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - close channel <mysql-connection-63> (?:)
2023-11-01 12:22:53	
11-01 04:22:53 DEBUG - <mysql-connection-63> - client got disconnected with no running query (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - close connection <mysql-connection-63> (?:)
2023-11-01 12:22:53	
11-01 04:22:53 TRACE - channel was closed <mysql-connection-63> (?:)
2023-11-01 12:22:53	
11-01 04:22:53 ERROR - Error when getting database connection. Will retry 1 (?:)
org.springframework.dao.DataAccessResourceFailureException: Failed to obtain R2DBC Connection
	at org.springframework.r2dbc.connection.ConnectionFactoryUtils.lambda$getConnection$0(ConnectionFactoryUtils.java:90) ~[spring-r2dbc-6.0.11.jar!/:6.0.11]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoError] :

Error has been observed at the following site(s):
	*__Mono.onErrorMap ⇢ at org.springframework.r2dbc.connection.ConnectionFactoryUtils.getConnection(ConnectionFactoryUtils.java:90)
	|_        Mono.map ⇢ at org.springframework.r2dbc.core.DefaultDatabaseClient.inConnection(DefaultDatabaseClient.java:113)
	*___Mono.usingWhen ⇢ at org.springframework.r2dbc.core.DefaultDatabaseClient.inConnection(DefaultDatabaseClient.java:116)
	|_ Mono.onErrorMap ⇢ at org.springframework.r2dbc.core.DefaultDatabaseClient.inConnection(DefaultDatabaseClient.java:128)
Original Stack Trace:
		at org.springframework.r2dbc.connection.ConnectionFactoryUtils.lambda$getConnection$0(ConnectionFactoryUtils.java:90) ~[spring-r2dbc-6.0.11.jar!/:6.0.11]
		at reactor.core.publisher.Mono.lambda$onErrorMap$28(Mono.java:3783) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:94) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onError(MonoFlatMap.java:180) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxRetry$RetrySubscriber.onError(FluxRetry.java:95) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.onError(FluxTimeout.java:219) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at io.r2dbc.pool.MonoDiscardOnCancel$MonoDiscardOnCancelSubscriber.onError(MonoDiscardOnCancel.java:98) ~[r2dbc-pool-1.0.1.RELEASE.jar!/:1.0.1.RELEASE]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onError(MonoIgnoreThen.java:278) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:231) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onComplete(MonoIgnoreThen.java:203) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onComplete(FluxDoFinally.java:128) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onComplete(FluxDoFinally.java:128) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreElements$IgnoreElementsSubscriber.onComplete(MonoIgnoreElements.java:89) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.apply(MonoCompletionStage.java:126) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.apply(MonoCompletionStage.java:71) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[?:?]
		at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911) ~[?:?]
		at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?]
		at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[?:?]
		at com.github.jasync.sql.db.mysql.MySQLConnection$close$lambda$2$$inlined$onCompleteAsync$1.accept(FutureUtils.kt:110) ~[jasync-mysql-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.mysql.MySQLConnection$close$lambda$2$$inlined$onCompleteAsync$1.accept(FutureUtils.kt:92) ~[jasync-mysql-2.2.4.jar!/:?]
		at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[?:?]
		at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?]
		at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:482) ~[?:?]
		at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: com.github.jasync.r2dbc.mysql.JasyncDatabaseException: Unknown exception
	at com.github.jasync.r2dbc.mysql.JasyncStatement.mapException(JasyncStatement.kt:261) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoError] :

Error has been observed at the following site(s):
	*_____Flux.onErrorMap ⇢ at reactor.kotlin.core.publisher.FluxExtensionsKt.onErrorMap(FluxExtensions.kt:172)
	|_       Flux.flatMap ⇢ at io.r2dbc.pool.Validation.validate(Validation.java:33)
	|_          Flux.then ⇢ at io.r2dbc.pool.Validation.validate(Validation.java:33)
	*_____Mono.thenReturn ⇢ at io.r2dbc.pool.ConnectionPool.getValidConnection(ConnectionPool.java:176)
	*___________Mono.then ⇢ at io.r2dbc.pool.ConnectionPool.lambda$null$5(ConnectionPool.java:137)
	|_ 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.timeout ⇢ at io.r2dbc.pool.ConnectionPool.lambda$new$12(ConnectionPool.java:157)
	|_  Mono.contextWrite ⇢ at io.r2dbc.pool.ConnectionPool.lambda$new$12(ConnectionPool.java:157)
	|_    Mono.onErrorMap ⇢ at io.r2dbc.pool.ConnectionPool.lambda$new$12(ConnectionPool.java:168)
	*__________Mono.defer ⇢ at io.r2dbc.pool.ConnectionPool.<init>(ConnectionPool.java:112)
	|_         Mono.retry ⇢ at io.r2dbc.pool.ConnectionPool.<init>(ConnectionPool.java:172)
	|_       Mono.flatMap ⇢ at org.springframework.r2dbc.connection.ConnectionFactoryUtils.lambda$doGetConnection$4(ConnectionFactoryUtils.java:118)
	*________Mono.flatMap ⇢ at org.springframework.r2dbc.connection.ConnectionFactoryUtils.doGetConnection(ConnectionFactoryUtils.java:104)
	|_ Mono.onErrorResume ⇢ at org.springframework.r2dbc.connection.ConnectionFactoryUtils.doGetConnection(ConnectionFactoryUtils.java:139)
Original Stack Trace:
		at com.github.jasync.r2dbc.mysql.JasyncStatement.mapException(JasyncStatement.kt:261) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement.access$mapException(JasyncStatement.kt:30) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement$execute$4.invoke(JasyncStatement.kt:122) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement$execute$4.invoke(JasyncStatement.kt:120) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at reactor.kotlin.core.publisher.FluxExtensionsKt.onErrorMap$lambda-1(FluxExtensions.kt:172) ~[reactor-kotlin-extensions-1.2.2.jar!/:1.2.2]
		at reactor.core.publisher.Flux.lambda$onErrorMap$28(Flux.java:7236) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Flux.lambda$onErrorResume$29(Flux.java:7289) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:94) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onError(FluxMapFuseable.java:142) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:161) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMapMany.subscribeOrReturn(MonoFlatMapMany.java:49) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4480) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:240) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onComplete(MonoIgnoreThen.java:203) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.complete(Operators.java:137) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoEmpty.subscribe(MonoEmpty.java:46) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		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.8.jar!/:3.5.8]
		at reactor.pool.AbstractPool$Borrower.deliver(AbstractPool.java:467) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.lambda$drainLoop$8(SimpleDequePool.java:372) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.scheduler.ImmediateScheduler.schedule(ImmediateScheduler.java:52) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.pool.SimpleDequePool.drainLoop(SimpleDequePool.java:372) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.pendingOffer(SimpleDequePool.java:604) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.doAcquire(SimpleDequePool.java:298) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.AbstractPool$Borrower.request(AbstractPool.java:430) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.request(MonoFlatMap.java:194) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.request(Operators.java:2305) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.request(SerializedSubscriber.java:151) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.request(FluxContextWrite.java:136) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2341) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onSubscribe(FluxOnErrorResume.java:74) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onSubscribe(FluxContextWrite.java:101) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.onSubscribe(SerializedSubscriber.java:65) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.onSubscribe(FluxTimeout.java:154) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:117) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.pool.SimpleDequePool$QueueBorrowerMono.subscribe(SimpleDequePool.java:722) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxRetry$RetrySubscriber.resubscribe(FluxRetry.java:117) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxRetry$RetrySubscriber.onError(FluxRetry.java:101) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:295) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:280) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:419) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorReturn$ReturnSubscriber.onNext(FluxOnErrorReturn.java:162) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:271) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:286) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
		at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
		at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
		at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
		at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: com.github.jasync.sql.db.exceptions.ConnectionStillRunningQueryException: <<mysql-connection-63>> - There is a query still being run here - race -> false
	at com.github.jasync.sql.db.mysql.MySQLConnection.validateIsReadyForQuery(MySQLConnection.kt:502) ~[jasync-mysql-2.2.4.jar!/:?]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoFlatMapMany] :
	reactor.core.publisher.Mono.flatMapMany(Mono.java:3117)
	com.github.jasync.r2dbc.mysql.JasyncStatement.execute(JasyncStatement.kt:95)
Error has been observed at the following site(s):
	*__Mono.flatMapMany ⇢ at com.github.jasync.r2dbc.mysql.JasyncStatement.execute(JasyncStatement.kt:95)
	|_         Flux.map ⇢ at com.github.jasync.r2dbc.mysql.JasyncStatement.execute(JasyncStatement.kt:111)
Original Stack Trace:
		at com.github.jasync.sql.db.mysql.MySQLConnection.validateIsReadyForQuery(MySQLConnection.kt:502) ~[jasync-mysql-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.mysql.MySQLConnection.sendQueryDirect(MySQLConnection.kt:407) ~[jasync-mysql-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.ConcreteConnectionBase$sendQuery$1.invoke(ConcreteConnectionBase.kt:59) ~[jasync-common-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.ConcreteConnectionBase$sendQuery$1.invoke(ConcreteConnectionBase.kt:58) ~[jasync-common-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.interceptor.ConnectionInterceptorHelperKt.wrapQueryWithInterceptors(ConnectionInterceptorHelper.kt:13) ~[jasync-common-2.2.4.jar!/:?]
		at com.github.jasync.sql.db.ConcreteConnectionBase.sendQuery(ConcreteConnectionBase.kt:58) ~[jasync-common-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement$execute$2.invoke(JasyncStatement.kt:108) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement$execute$2.invoke(JasyncStatement.kt:95) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at com.github.jasync.r2dbc.mysql.JasyncStatement.execute$lambda$3(JasyncStatement.kt:95) ~[jasync-r2dbc-mysql-2.2.4.jar!/:?]
		at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:152) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMapMany.subscribeOrReturn(MonoFlatMapMany.java:49) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4480) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:240) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onComplete(MonoIgnoreThen.java:203) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.complete(Operators.java:137) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoEmpty.subscribe(MonoEmpty.java:46) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		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.8.jar!/:3.5.8]
		at reactor.pool.AbstractPool$Borrower.deliver(AbstractPool.java:467) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.lambda$drainLoop$8(SimpleDequePool.java:372) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.scheduler.ImmediateScheduler.schedule(ImmediateScheduler.java:52) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.pool.SimpleDequePool.drainLoop(SimpleDequePool.java:372) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.pendingOffer(SimpleDequePool.java:604) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.SimpleDequePool.doAcquire(SimpleDequePool.java:298) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.pool.AbstractPool$Borrower.request(AbstractPool.java:430) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.request(MonoFlatMap.java:194) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.request(Operators.java:2305) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.request(SerializedSubscriber.java:151) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.request(FluxContextWrite.java:136) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2341) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onSubscribe(FluxOnErrorResume.java:74) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onSubscribe(FluxContextWrite.java:101) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.onSubscribe(SerializedSubscriber.java:65) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.onSubscribe(FluxTimeout.java:154) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:117) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.pool.SimpleDequePool$QueueBorrowerMono.subscribe(SimpleDequePool.java:722) ~[reactor-pool-1.0.1.jar!/:1.0.1]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxRetry$RetrySubscriber.resubscribe(FluxRetry.java:117) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxRetry$RetrySubscriber.onError(FluxRetry.java:101) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoError.subscribe(MonoError.java:53) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.handleTimeout(FluxTimeout.java:295) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutMainSubscriber.doTimeout(FluxTimeout.java:280) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxTimeout$TimeoutTimeoutSubscriber.onNext(FluxTimeout.java:419) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.FluxOnErrorReturn$ReturnSubscriber.onNext(FluxOnErrorReturn.java:162) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:271) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:286) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) ~[reactor-core-3.5.8.jar!/:3.5.8]
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
		at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
		at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
		at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
		at java.base/java.lang.Thread.run(Thread.java:840) [?:?]

Activity

  1. oshai commented on Nov 8, 2023

    @oshai
    oshai
    on Nov 8, 2023
    Contributor
    More actions

    looks like something that is related to r2dbc pool itself. maybe it queries the connection periodically and it conflict with getting a connection?

  2. TywinLanni commented on Nov 12, 2026

    @TywinLanni
    TywinLanni
    on Nov 12, 2026
    More actions

    Hi everyone! Any news on this issue? We’re also getting the same connection pool error in Postgres.

    It reproduces as follows: a transaction is opened with a call to a Postgres function inside. The function doesn’t finish within the query timeout. The connection used by the function is returned to the pool. An attempt to roll back the transaction hits this connection, where the function is still running.

    jasync-postgres-2.2.4
    Java 21

    <<postgres-connection-3>> - There is a query still being run here - race -> false is the error text.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions

      You are visitor 01402520 — GeezerVison does not store the pages you look up.
      Best viewed with Netscape Navigator 4.7 or Internet Explorer 6 at 800×600. No cookies required.