jboss 7.1.0, javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!

[varsha.g]

Hi,

       I have deployed the my  MDB on server jboss 7.1.0

           MDB will through the following exception after the some time,

     14:43:18,855 WARN  [com.arjuna.ats.arjuna] (Thread-2 (HornetQ-client-global-threads-14059119)) ARJUNA012077: Abort called on already aborted atomic action 0:ffff0a0000a0:2ada82a:4f45fbd7:17d

     14:43:18,856 WARN  [org.hornetq.ra.inflow.HornetQMessageHandler] (Thread-2 (HornetQ-client-global-threads-14059119)) Unable to call after delivery: javax.resource.spi.LocalTransactionException:               javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!

    at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:88)

    at sun.reflect.GeneratedMethodAccessor462.invoke(Unknown Source) [:1.6.0_26]

    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_26]

    at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_26]

    at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60)

    at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136)

    at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73)

    at $Proxy13.afterDelivery(Unknown Source)    at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:287) [hornetq-ra-2.2.11.Final.jar:]

    at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:983) [hornetq-core-2.2.11.Final.jar:]

    at org.hornetq.core.client.impl.ClientConsumerImpl.access$400(ClientConsumerImpl.java:48) [hornetq-core-2.2.11.Final.jar:]

    at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1113) [hornetq-core-2.2.11.Final.jar:]

    at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100) [hornetq-core-2.2.11.Final.jar:]

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_26]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_26]

    at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_26]

Caused by: javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!

    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1155) [jbossjts-4.16.2.Final.jar:]

    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117) [jbossjts-4.16.2.Final.jar:]

    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)

    at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72)

    ... 15 more

And Also

13:58:15,605 WARN  [com.mchange.v2.async.ThreadPoolAsynchronousRunner] (Timer-1) com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1c3298e -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!

13:58:15,677 WARN  [com.mchange.v2.async.ThreadPoolAsynchronousRunner] (Timer-1) com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@1c3298e -- APPARENT DEADLOCK!!! Complete Status:

###########################################################################################################################################################################

Here is my MDB

@MessageDriven(

        activationConfig = {

                @ActivationConfigProperty(propertyName = "destinationType", propertyValue = "javax.jms.Queue"),

                @ActivationConfigProperty(propertyName = "destination", propertyValue = "queue/test")       

        })

public class MessageDrivenBean implements MessageListener {

    /**

     * Default constructor.

     */

    public MessageDrivenBean() {

        // TODO Auto-generated constructor stub

    }

    /**

     * @see MessageListener#onMessage(Message)

     */

    public void onMessage(Message message) {

        Logger log=LoggerFactory.getLogger(MessageDrivenBean.class);

        Serializable seObj = null;

        FeedbackMessageBean tmsg = null;

        try {

            seObj = ((ObjectMessage) message).getObject();

        } catch (JMSException e1) {

            // TODO Auto-generated catch block

            e1.printStackTrace();

        }

        tmsg = (FeedbackMessageBean) seObj;

}

}

    I want to fetch and process the message from the queue one-by-one .However my execution for fetching out this message is running successfully but in between i got some

     exception like this : javax.transaction.RollbackException: ARJUNA016063: The transaction is not active!

    I  set  max MDB pool size to 1.

    I am not getting the exact cause for this exception?

    anyone has any clues?

[jbertram]

Typically errors like this where a component (in this case the HornetQ JCA RA) tries to work with a transaction and is told, "The transaction is not active!" are caused by a transaction timeout.  When a transaction times out the transaction manager rolls it back asynchronously and then when a compontent tries to access the transaction again (e.g. to commit it or roll it back) it won't be able to according to the JTA spec.  Are there any other warnings in your log prior to this?  In any case, clearly something has caused the transaction to be aborted before the HornetQ JCA RA invokes afterDelivery because the log says, "Abort called on already aborted atomic action 0:ffff0a0000a0:2ada82a:4f45fbd7:17d."

[varsha.g]

Hi Justin

           prior warnings are the only

14:43:08,080 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff0a0000a0:2ada82a:4f45fbd7:17d in state  RUN

14:43:08,081 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff0a0000a0:2ada82a:4f45fbd7:17d invoked while multiple threads active within it.

14:43:08,082 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff0a0000a0:2ada82a:4f45fbd7:17d aborting with 1 threads active!

14:43:08,086 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff0a0000a0:2ada82a:4f45fbd7:17d

          so how to resolve this exception ?

[jbertram]

These WARN statements from the transaction manager (specifically the transaction reaper thread) indicate that your transaction as timed out.  The default transaction timeout in AS7 is 5 minutes as set here (300 seconds = 5 minutes):

  <coordinator-environment default-timeout="300"/>

It looks to me like your MDB is taking longer than 5 minutes to process the message therefore its transaction is timing out.  Can you confirm this (e.g. using logging statements)?

[varsha.g]

Thanks Justin

                        I have printed the debug statement and  analyze the excution for MDB, its not taking  5 min to complete its excution. it took around 2-3 min. 

MDB is fetching out next message   successfully but in between some time i got some exception.

[jbertram]

Are you setting a custom transaction timeout using activation configuration properties?  If not, turn on DEBUG logging for "com.arjuna" like this:

  <logger category="com.arjuna">

    <level name="DEBUG"/>

  </logger>

I think that will show exactly what the transaction manager is doing (e.g. how long it expects the timeout to be, when exactly it starts the transaction, etc.).

[nuno.godinhomatos]

Hi Justin,

This post is from 2012, but I would appear that in 2017, there still issues such as this laying around.

This bug is specific to JBoss and Wildfly at least in the way that I am aware that can be reproduced.

In weblogic the following business case works without problem.

See bellow a stack trace from Wildfly 10, that uses the same transaction manager.

And this stack trace is related pricesely to this issue.

Wildfly 10 + Eclipselink 2.6.4 - @Observes(during = TransactionPhase.AFTER_SUCCESS) - Get stale entity - Stack Overflow

In particular, we have app using oracle XA driver.

We have some business logic that fires an even and commits a transaction.

The bussiness logic of the successful transaction fires(event).

And then we have a @Singleton ejb, that is observing the event.

at TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)

    atOverride

    public void observeEventThatIsBreakingWildfly(

           atObserves(during = TransactionPhase.AFTER_SUCCESS)

----

The code of this singleton EJB is completely dead when it observes on success.

We can see that the main business logic transaction is at this phase:

  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:545)

  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)

What will happen in this situation is a catastrophic error.

First of all, the application server will not open any new transaction context for the observing method.

It seems to try to be re-use the transaction context of the succesful and finished transaction.

The only work-around for this is to inject into the singleton EJB  some other auxiliary helper EJB to be successful opening a new transaciton context.

Second point is that, not only this exception takes place, but worst of all, we enter an infinite cycle of never ending exceptions.

The code of ARUNA is forver retrying to publish the event and forever being publmed by a closed transaction context.

The application server is dead on its feet, until we kill the process.

On weblogic, the same scenario works flawlessly, without any need to even delcare transaciton requires new on the observer method of the singleton.

NOTE:

It most probably is relevant to mention that we are using EclipseLink here.

Third point, even more important than point number 2 - since point number two has a work-around.

The third point is that even when we use the work-around an inject a new EJB to open a new jta tnrasction context, we will be reading stale entities.

As if the successful transaction that published the event had not completed.

In this case, the dirties work-around to be able to handle on stale data while observing on success is to for the entityManger.refreh(staleEntity).

This very dirty work-around will only be applicable if we know in our observer method exactly which entities were changed and are stale.

I will have to try to run the same business logic without making using of an XA JDBC drivier.

It might be that solves all the problems.

Many thanks.

2017-06-16 20:43:06,341 ERROR [org.jboss.as.ejb3] (thread: default task-6) WFLYEJB0064:

Failed to set transaction for rollback only: com.arjuna.ats.jta.exceptions.InactiveTransactionException:

ARJUNA016102: The transaction is not active! Uid is 0:ffffc0a8012b:34ef478b:594425a3:4bb

  at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.setRollbackOnly(TransactionImple.java:331)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.setRollbackOnly(CMTTxInterceptor.java:362)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleInCallerTx(CMTTxInterceptor.java:167)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:256)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:329)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)

  at org.jboss.as.ejb3.concurrency.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:110)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)

  at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)

  at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)

  at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

  at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)

  at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)

  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

  at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)

  at APPLICATION_CODE$$$view30.notifySOME_STATE_FailureChange(Unknown Source)

    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

  at java.lang.reflect.Method.invoke(Method.java:498)

  at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:436)

  at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:127)

  at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)

  at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:100)

  at APPLICATION_CODE$1409415751$Proxy$_$$_Weld$EnterpriseProxy$.notifySOME_STATE_FailureChange(Unknown Source)

  at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

  at java.lang.reflect.Method.invoke(Method.java:498)

  at org.jboss.weld.injection.StaticMethodInjectionPoint.invoke(StaticMethodInjectionPoint.java:88)

  at org.jboss.weld.injection.StaticMethodInjectionPoint.invoke(StaticMethodInjectionPoint.java:78)

  at org.jboss.weld.injection.MethodInvocationStrategy$SimpleMethodInvocationStrategy.invoke(MethodInvocationStrategy.java:129)

  at org.jboss.weld.event.ObserverMethodImpl.sendEvent(ObserverMethodImpl.java:309)

  at org.jboss.weld.event.ObserverMethodImpl.sendEvent(ObserverMethodImpl.java:287)

  at org.jboss.weld.event.ObserverMethodImpl.notify(ObserverMethodImpl.java:265)

  at org.jboss.weld.event.DeferredEventNotification$1.execute(DeferredEventNotification.java:69)

  at org.jboss.weld.event.DeferredEventNotification$RunInRequest.run(DeferredEventNotification.java:101)

  at org.jboss.weld.event.DeferredEventNotification.run(DeferredEventNotification.java:75)

  at org.jboss.weld.event.TransactionSynchronizedRunnable.afterCompletion(TransactionSynchronizedRunnable.java:54)

  at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)

  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:545)

  at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)

  at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)

  at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)

  at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)

  at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)

[nuno.godinhomatos]

There is a statement that is false in what I said above, as I finished typing about the error, and went back to visit the server log.

I could see that the infinite loop of stack traces trying to notify observer had stopped.

In fact, it seems that there is an application server internal retry mechanism to notify observers of events.

The last log statement I had on my log was the following:

2017-06-16 21:00:24,736 ERROR [org.jboss.weld.Event] (thread: default task-6) WELD-000401: Failure while notifying an observer of event null

So in fact, the observer keeps on failing for a limited amount of exceptions.

Perhaps for 100 or so exceptions.

After which the notification of the event stops.

Of course, if this event were being triggered often enough, the observers would all be going into the explained error.

And indeed yes, the app server would be trashed.

There is quite an important bug to be fixed on this area.

Many thanks.

[nuno.godinhomatos]

Run the same test case using normal non xa data source.

Essentially making use of the Last Resource Commit Optimization of the app server.

The same pseudo infinite loop of exceptions has taken place.

This is an indication to me that on Wildfly at least, observing transactions on success is a very problematic point.

Many thanks.

[jbertram]

This thread is not a place to discuss transaction issues in general.  This thread is about a timeout happening while consuming a JMS message within a JTA transaction.  From all appearances the timeout is being reported and handled properly and there is no bug. 

Your issue appears to be completely different.  Please create a new thread about your specific issue rather than commenting on an unrelated thread which hasn't seen activity in nearly half a decade.

[nuno.godinhomatos]

Noted, although this post from a decade ago, was in fact the first result that was handed over by google to my search by exception.

Hence here we are.
I have already created the appropriate JIRA issue on the wildly JIRA.

Although, on the topic of transaction and mdbs ..

Transaction management is in "general" a "generic problem". The source code behind managing a JTA transaction, whether or not the entry point is an MDB/EJB or  Stateles/Singleton/EJB will not greatly differ. Both layers of an APP server are going to drink from the same fountain.

Of course the resource adapters that have the responsibility of opening up and issuing the commit/rollback of these global transactions are not the same, but in any case they will be using the same Javax transaction apis. The exception in the thread is not specific to MdBs, it is specific to any context layer, regardless of entry point technologic, where the container has the responsibility to manage a transaction.

But you are right it would have been better to open a new thread, and the JIRA task is open.
Kindest regards.

[daniel.netti]

Hi Nuno, I believe that I've almost the same problem that you.
Since JBoss 4.3 we'd ARJUNA problems.

In the JBoss 4 and 5 we solve this problems by using non XA datasources.

Could you please send me the new thread link?

I'd like to participate of this discussion.

Sorry about my bad English.

[jaikiran]

Daniel Benetti wrote:

Could you please send me the new thread link?

I'd like to participate of this discussion.

Hi Daniel,

Please go ahead and create a separate discussion of your own in the relevant forum and describe the issue you are running into including the exact versions of the server you are using and any exception stacktraces that you see.

[daniel.netti]

Hi Jaikiran

Thank you 4 your response.

Cloud you tell me which is the relevant forum to start this thread?

I believe that don't use a XA connection in the datasource does not solve the problem in wildfly.

Thanks

[jaikiran]

Daniel Benetti wrote:

Cloud you tell me which is the relevant forum to start this thread?

I believe that don't use a XA connection in the datasource does not solve the problem in wildfly.

Since you indicate that you are using WildFly, please start a new discussion in the WildFly forum here WildFly . As noted in my previous reply, include all relevant details. If at some point it turns out to be not related to WildFly, one of us with relevant permissions will move it to the right forum.