Enlisted connection used without active transaction after Migration to Quarkus 2.0.0

Describe the bug

After migrated to the newest Version(2.0.0) we see a lot of the following exceptions in our logs:

2021-07-06 14:48:02,148 WARN  [com.arj.ats.jta] (QuarkusQuartzScheduler_Worker-3) ARJUNA016039: onePhaseCommit on < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff7f000101:b391:60e45102:0, node_name=quarkus, branch_uid=0:ffff7f000101:b391:60e45102:3, subordinatenodename=null, eis_name=0 > (io.agroal.narayana.LocalXAResource@1fae3ec5) failed with exception XAException.XA_RBROLLBACK: javax.transaction.xa.XAException: Error trying to transactionCommit local transaction: Enlisted connection used without active transaction
	at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:140)
	at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:134)
	at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:72)
	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:702)
	at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2400)
	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1502)
	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:97)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass.commit$$superforward1(CDIDelegatingTransactionManager_Subclass.zig:386)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass$$function$$6.apply(CDIDelegatingTransactionManager_Subclass$$function$$6.zig:24)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.proceed(InvocationInterceptor.java:62)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:49)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(InvocationInterceptor_Bean.zig:521)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)

2021-07-06 14:48:02,157 INFO  [org.qua.cor.JobRunShell] (QuarkusQuartzScheduler_Worker-3) Job io.quarkus.scheduler.Scheduler.1_io.gec.test.control.GiftController_ScheduledInvoker_schedule_c3705fc8cd7ee35acd13c98d8d089325355c7af1 threw a JobExecutionException: : org.quartz.JobExecutionException: io.quarkus.arc.ArcUndeclaredThrowableException: Error invoking subclass method [See nested exception: io.quarkus.arc.ArcUndeclaredThrowableException: Error invoking subclass method]
	at io.quarkus.quartz.runtime.QuartzScheduler$InvokerJob.execute(QuartzScheduler.java:409)
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: io.quarkus.arc.ArcUndeclaredThrowableException: Error invoking subclass method
	at io.gec.test.control.GiftController_Subclass.doTransactionalStuff(GiftController_Subclass.zig:299)
	at io.gec.test.control.GiftController.schedule(GiftController.java:32)
	at io.gec.test.control.GiftController_Subclass.schedule$$superforward1(GiftController_Subclass.zig:214)
	at io.gec.test.control.GiftController_Subclass$$function$$2.apply(GiftController_Subclass$$function$$2.zig:33)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.proceed(InvocationInterceptor.java:62)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:49)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(InvocationInterceptor_Bean.zig:521)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at io.gec.test.control.GiftController_Subclass.schedule(GiftController_Subclass.zig:369)
	at io.gec.test.control.GiftController_ClientProxy.schedule(GiftController_ClientProxy.zig:188)
	at io.gec.test.control.GiftController_ScheduledInvoker_schedule_c3705fc8cd7ee35acd13c98d8d089325355c7af1.invokeBean(GiftController_ScheduledInvoker_schedule_c3705fc8cd7ee35acd13c98d8d089325355c7af1.zig:48)
	at io.quarkus.arc.runtime.BeanInvoker.invoke(BeanInvoker.java:20)
	at io.quarkus.quartz.runtime.QuartzScheduler$InvokerJob.execute(QuartzScheduler.java:407)
	... 2 more
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1307)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:97)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass.commit$$superforward1(CDIDelegatingTransactionManager_Subclass.zig:386)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass$$function$$6.apply(CDIDelegatingTransactionManager_Subclass$$function$$6.zig:24)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.proceed(InvocationInterceptor.java:62)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor.monitor(InvocationInterceptor.java:49)
	at io.quarkus.arc.runtime.devconsole.InvocationInterceptor_Bean.intercept(InvocationInterceptor_Bean.zig:521)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager_Subclass.commit(CDIDelegatingTransactionManager_Subclass.zig:983)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:313)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:164)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:100)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:32)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:53)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:26)
	at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(TransactionalInterceptorRequired_Bean.zig:340)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at io.gec.test.control.GiftController_Subclass.doTransactionalStuff(GiftController_Subclass.zig:278)
	... 17 more
	Suppressed: javax.transaction.xa.XAException: Error trying to transactionCommit local transaction: Enlisted connection used without active transaction
		at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:140)
		at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:134)
		at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:72)
		at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:702)
		at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2400)
		at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1502)
		at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
		at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
		at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
		... 40 more
	Caused by: java.sql.SQLException: Enlisted connection used without active transaction
		at io.agroal.pool.ConnectionHandler.verifyEnlistment(ConnectionHandler.java:352)
		at io.agroal.pool.ConnectionHandler.transactionCommit(ConnectionHandler.java:321)
		at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:69)
		... 46 more

Expected behavior

No Exception should occur on the Console Log

Actual behavior

With Version 1.13.7 of Quarkus no Exception is thrown on the Console Log With Version 2.0.0 of Quarkus the above mentioned Exceptions are thrown on the Console Log

To Reproduce

Clone Project: https://github.com/KaiSuchomel/quarkus-without-active-transaction-issue

Start Database: docker run -d -e POSTGRES_USER=hibernate -e POSTGRES_PASSWORD=hibernate -e POSTGRES_DB=hibernate_db -e POSTGRES_PORT=5432 --name mydb -p 5432:5432 postgres
Start Kafka docker-compose up
start quarkus mvn clean quarkus:dev

Switch Quarkus Version via pom.xml (current the 2.0.0 Version ist set)

        <quarkus.platform.version>2.0.0.Final</quarkus.platform.version>
        <!--<quarkus.platform.version>1.13.7.Final</quarkus.platform.version>-->

mvn -Dquarkus.platform.version=1.13.6.Final clean quarkus:dev

Configuration

see application.properties at linked project

Environment (please complete the following information):

Output of `uname -a` or `ver`

Linux 5.4.0-77-generic #86-Ubuntu SMP Thu Jun 17 02:35:03 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Output of `java -version`

openjdk version “14.0.1” 2020-04-14 OpenJDK Runtime Environment (build 14.0.1+7) OpenJDK 64-Bit Server VM (build 14.0.1+7, mixed mode, sharing)

GraalVM version (if different from Java)

Quarkus version or git rev

1.13.7 vs 2.0.0

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

mvn

Issue Analytics

State:
Created 2 years ago
Comments:21 (10 by maintainers)

Top GitHub Comments

1reaction

cescoffiercommented, Aug 17, 2021

I looked into it a bit more. The reproducer sends a message that is processed asynchronously. Messages sent using an emitter are always handled asynchronously - see https://quarkus.io/blog/reactive-messaging-emitter/. However, the transaction ends at the end of the method so, before the message being processed. This is not correct and the error message is telling that the object is touched outside of a transaction. It may have been working before because the transaction was still “active” (delay, or timing being slightly different), but it was wrong.

The solution is to make the @Transactional method returns a CompletionStage<Void> so the transaction is committed when the message is acknowledged.

So, it works if you update the code to:

@Transactional
    public CompletionStage<Void> doTransactionalStuff(Gift aProducedGift) {
        System.err.println("GiftController.doTransactionalStuff: " + aProducedGift);
        CompletableFuture<Void> acked = new CompletableFuture<>();
        Message<String> m = Message.of(aProducedGift.toString(), Metadata.of(OutgoingKafkaRecordMetadata.<String>builder()
                    .withKey(UUID.randomUUID().toString()).build()), () -> {
                        acked.complete(null); return CompletableFuture.completedStage(null);
                    }, t -> {
                        acked.completeExceptionally(t);
                        return CompletableFuture.completedFuture(null);
                    });
        em.persist(aProducedGift);
        emitter.send(m);
        return acked;
    }

I would recommend using records instead of a Message so it would simplify that code:

@Channel("giftsOut")
@OnOverflow(OnOverflow.Strategy.BUFFER)
@Broadcast
Emitter<Record<String, String>> emitter;

@Transactional
public CompletionStage<Void> doTransactionalStuff(Gift aProducedGift) {
    Record<String, String> record = Record.of(UUID.randomUUID().toString(), aProducedGift.toString());    
    em.persist(aProducedGift);
    return emitter.send(record);
}

0reactions

wicksimcommented, Sep 16, 2021

It is called from a REST-Resource. So i guess changing to reactive-based Resources would save that problem?

Top Results From Across the Web

"Enlisted connection used without active transaction" during ...

Describe the bug Hi guys! I've found out recently that not all of my transactions are committed. The small investigation led me to...

Random "Enlisted connection used without active transaction ...

In my Quarkus app I get Enlisted connection used without active transaction errors around once a day (on a public API used quite...

Enlisted connection used without active transaction

I think it means that you have started using the EntityManager inside a transaction, then you have used it with no TX active...

Using Transactions in Quarkus

The easiest way to define your transaction boundaries is to use the @Transactional annotation on your entry method ( javax.transaction.Transactional ). @ ...

Service Mesh OpenShift Container Platform 4.10

This release of Red Hat OpenShift Service Mesh adds new features and enhancements, and is supported on OpenShift Container Platform 4.9 or later....