Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-6761

Wrong XAException return code when broker timeout is hit

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Minor
    • Resolution: Done
    • Affects Version/s: 10.0.0.Final
    • Fix Version/s: 12.0.0.Final
    • Component/s: JMS
    • Labels:
      None
    • Steps to Reproduce:
      Hide

      Crash recovery testsuite could be used to get the described behavior

      Show
      Crash recovery testsuite could be used to get the described behavior git clone http://git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.git cd jbossqe-eap-tests-transactions download and unzip EAP 7.0.0.GA export JBOSS_HOME=path/to/er7 mvn clean verify -am -pl jbossts -DfailIfNoTests=false -fn -Dtest=JMSBrokerTimeoutTestCase -Djbossts.noJTS

      Description

      By creating testcases for checking behavior of transaction timeout I've hit an issue of wrong error code being returned when broker transaction timeout is hit before TM transaction timeout expires.
      It uses XAER_PROTO instead of RBTIMEOUT.

      This issue does not cause data inconsistency.

      Scenario:

      • ejb sends a message to a queue
      • processing inside of the ejb takes long time
        • TM transaction timeout is set big enough to not hit the timeout
        • jms broker internal transaction timeout is smaller than time needed for processing ejb method
      • jms broker txn timeout occurs - broker local txn is rolled back
        • txn is removed from list of broker's local in-process transactions
      • TM calls XAResource.end
        • the call returns XAException.XAER_PROTO

      That's current implementation returns XAER_PROTO in this scenario but RBTIMEOUT would be more appropriate.

      From discussion with Narayana developers, RM should return the most specific error return code as possible. In this scenario it's RBTIMEOUT.

      Other notes from TM dev point of view:

      "[XA_RBTIMEOUT]
      The work represented by this transaction branch took too long."
      

      per XA spec page 39.

      The more complex question is, at what point can the resource manager forget about that branch (and therefore return NOTA to subsequent calls)?

      The XA spec says "After the transaction manager calls xa_end(), it should no longer consider the calling thread associated with that resource manager (although it must consider the resource manager part of the transaction branch when it prepares the branch.)"
      which implies the branch is still considered live at that point, a view corroborated by:

      "[XA_RB∗]
      The resource manager has dissociated the transaction branch from the thread of control and has marked rollback-only the work performed on behalf of ∗xid."
      

      Exception being thrown

      WARN  [com.arjuna.ats.jta] (Thread-0
      (ActiveMQ-client-global-threads-1468293951)) ARJUNA016056:
      TransactionImple.delistResource - caught exception during delist :
      XAException.XAER_PROTO: javax.transaction.xa.XAException
       at
      org.apache.activemq.artemis.core.protocol.core.impl.ActiveMQSessionContext.xaEnd(ActiveMQSessionContext.java:346)
       at
      org.apache.activemq.artemis.core.client.impl.ClientSessionImpl.end(ClientSessionImpl.java:1115)
       at
      org.apache.activemq.artemis.ra.ActiveMQRAXAResource.end(ActiveMQRAXAResource.java:112)
       at
      org.apache.activemq.artemis.service.extensions.xa.ActiveMQXAResourceWrapperImpl.end(ActiveMQXAResourceWrapperImpl.java:81)
       at
      com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.delistResource(TransactionImple.java:897)
       at
      org.jboss.jca.core.connectionmanager.listener.TxConnectionListener$TransactionSynchronization.beforeCompletion(TxConnectionListener.java:1063)
       at
      org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.invokeBefore(TransactionSynchronizer.java:438)
       at
      org.jboss.jca.core.connectionmanager.transaction.TransactionSynchronizer.beforeCompletion(TransactionSynchronizer.java:376)
       at
      org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.beforeCompletion(JCAOrderedLastSynchronizationList.java:130)
       at
      com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
       at
      com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:371)
       at
      com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
       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)
       at
      org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:71)
       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.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60)
       at
      org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:135)
       at
      org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73)
       at
      org.jboss.as.test.jbossts.crashrec.jms.mdb.JMSCrashMessageDrivenBean$$$endpoint1.afterDelivery(Unknown
      Source)
       at
      org.apache.activemq.artemis.ra.inflow.ActiveMQMessageHandler.onMessage(ActiveMQMessageHandler.java:321)
       at
      org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:932)
       at
      org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl.access$400(ClientConsumerImpl.java:47)
       at
      org.apache.activemq.artemis.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1045)
       at
      org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:100)
       at
      java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
       at
      java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
       at java.lang.Thread.run(Thread.java:745)
      

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  bayern39 Chen Maoqian
                  Reporter:
                  bayern39 Chen Maoqian
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  3 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: