Behavior of AgroalDataSource After Transaction Timeout

[nakamura-to]

After a transaction is rolled back due to a timeout, AgroalDataSource returns a connection with auto-commit mode set to true. As a result, any transactions using that connection are committed.
Is this behavior intentional?

I would expect an exception to be thrown if any of the connection's methods are invoked after the timeout.

You can find reproducible code here.
The reproducible project was created by modifying the hibernate-orm-quickstart.

Below is the log output from executing the reproducible code.
It shows that the connection's auto-commit mode changes before and after the timeout.

2024-12-06 22:12:47,201 INFO  [org.acm.hib.orm.FruitResource] (executor-thread-1) create 1: autoCommit=false
2024-12-06 22:12:47,204 INFO  [org.acm.hib.orm.FruitResource] (executor-thread-1) create 2: autoCommit=false
2024-12-06 22:12:50,204 WARN  [com.arj.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX 0:ffff7f000001:c8dd:6752f84f:0 in state  RUN
2024-12-06 22:12:50,218 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff7f000001:c8dd:6752f84f:0 invoked while multiple threads active within it.
2024-12-06 22:12:50,223 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012381: Action id 0:ffff7f000001:c8dd:6752f84f:0 completed with multiple threads - thread executor-thread-1 was in progress with [email protected]/java.lang.Thread.sleep(Native Method)
org.acme.hibernate.orm.FruitResource.create(FruitResource.java:79)
org.acme.hibernate.orm.FruitResource_Subclass.create$$superforward(Unknown Source)
org.acme.hibernate.orm.FruitResource_Subclass$$function$$1.apply(Unknown Source)
io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:73)
io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:62)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:136)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
org.acme.hibernate.orm.FruitResource_Subclass.create(Unknown Source)
org.acme.hibernate.orm.FruitResource_ClientProxy.create(Unknown Source)
org.acme.hibernate.orm.FruitResource$quarkusrestinvoker$create_95ea833d51de5176fe249c0804b01a9e6f9ece1c.invoke(Unknown Source)
org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:637)
org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675)
org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654)
org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594)
org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[email protected]/java.lang.Thread.run(Thread.java:840)


2024-12-06 22:12:50,226 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000001:c8dd:6752f84f:0 aborting with 1 threads active!
2024-12-06 22:12:50,229 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff7f000001:c8dd:6752f84f:0
2024-12-06 22:12:52,211 INFO  [org.acm.hib.orm.FruitResource] (executor-thread-1) create 3: autoCommit=true
2024-12-06 22:12:52,213 INFO  [org.acm.hib.orm.FruitResource] (executor-thread-1) create 4: autoCommit=true
2024-12-06 22:12:52,239 WARN  [com.arj.ats.arjuna] (executor-thread-1) ARJUNA012077: Abort called on already aborted atomic action 0:ffff7f000001:c8dd:6752f84f:0
2024-12-06 22:12:52,243 ERROR [org.acm.hib.orm.FruitResource] (executor-thread-1) Failed to handle request: jakarta.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffff7f000001:c8dd:6752f84f:0
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1297)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:104)
	at io.quarkus.narayana.jta.runtime.NotifyingTransactionManager.commit(NotifyingTransactionManager.java:70)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:406)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:171)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
	at org.acme.hibernate.orm.FruitResource_Subclass.create(Unknown Source)
	at org.acme.hibernate.orm.FruitResource_ClientProxy.create(Unknown Source)
	at org.acme.hibernate.orm.FruitResource$quarkusrestinvoker$create_95ea833d51de5176fe249c0804b01a9e6f9ece1c.invoke(Unknown Source)
	at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
	at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
	at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:637)
	at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654)
	at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)

[quarkus-bot[bot]]

/cc @barreiro (agroal), @yrodiere (agroal)

[yrodiere]

We'll need @barreiro to tell us if it's intentional or not.

Out of curiosity, what are the consequences for you exactly? This auto-commit will fail anyway, right? Are you just bothered by the unnecessary error logs, or are there other consequences?

[nakamura-to]

Thank you for your response.
The auto-commit doesn’t fail.
All operations using the connection in auto-commit mode are being committed.
Ideally, I would expect them to fail with an error instead of being committed.

[yrodiere]

The auto-commit doesn’t fail.
All operations using the connection in auto-commit mode are being committed.
Ideally, I would expect them to fail with an error instead of being committed.

I see. That's definitely worrying. Can you please open an issue?

@barreiro I think the problem is that after the current transaction times out, getConnection returns a new connection that is not involved in the transaction (and perhaps that's why autocommit is enabled?).
We should probably find some way of having getConnection fail in that case, instead... ?

[nakamura-to]

Thanks.
I have opened issue #45087.