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

WF transaction client returns XAER_RMERR during abort after server with subordinate transaction fails

    XMLWordPrintable

Details

    • Bug
    • Status: Resolved (View Workflow)
    • Major
    • Resolution: Done
    • 10.1.0.Final, 14.0.0.Final, 15.0.0.Final, 16.0.0.Final
    • None
    • Transactions
    • None
    • Hide
      1. get Wildfly
      2. get [crashrec TS|git@gitlab.mw.lab.eng.bos.redhat.com:jbossqe-eap/tests-transactions.git]
      3. export JBOSS_HOME=path-to-wildfly
      4. get driver for PostgreSQL DB
      5. mvn clean verify -Dtest=TxPropagationJPACrashRecoveryTestCase#prepareHaltServer -Dds0.db=postgresql101 -Dds0.jdbc.driver.jar=postgresql-42.2.2.jar -Dds0.jdbc.driver.class=org.postgresql.Driver -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.driver.path=path-to-driver -Dds0.hibernate.dialect=org.hibernate.dialect.PostgreSQL82Dialect -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.url=jdbc:postgresql://postgres-101.rhev-ci-vms.eng.rdu2.redhat.com:5432/crashrec -Dds1.db=postgresql101 -Dds1.jdbc.driver.jar=postgresql-42.2.2.jar -Dds1.jdbc.driver.class=org.postgresql.Driver -Dds1.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds1.jdbc.driver.path=path-to-driver -Dds1.hibernate.dialect=org.hibernate.dialect.PostgreSQL82Dialect -Dds1.db.name=crashrec2 -Dds1.user=crashrec2 -Dds1.pass=crashrec2 -Dds1.jdbc.url=jdbc:postgresql://postgres-101.rhev-ci-vms.eng.rdu2.redhat.com:5432/crashrec2 -DfailIfNoTests=false -Dts.jbossts1.node.identifier=TWkA -Dts.jbossts2.node.identifier=RJSN -Dts.jbossts3.node.identifier=WYYJ

      You can use your own DB

      Show
      get Wildfly get [crashrec TS|git@gitlab.mw.lab.eng.bos.redhat.com:jbossqe-eap/tests-transactions.git] export JBOSS_HOME=path-to-wildfly get driver for PostgreSQL DB mvn clean verify -Dtest=TxPropagationJPACrashRecoveryTestCase#prepareHaltServer -Dds0.db=postgresql101 -Dds0.jdbc.driver.jar=postgresql-42.2.2.jar -Dds0.jdbc.driver.class=org.postgresql.Driver -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.driver.path=path-to-driver -Dds0.hibernate.dialect=org.hibernate.dialect.PostgreSQL82Dialect -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.url=jdbc:postgresql://postgres-101.rhev-ci-vms.eng.rdu2.redhat.com:5432/crashrec -Dds1.db=postgresql101 -Dds1.jdbc.driver.jar=postgresql-42.2.2.jar -Dds1.jdbc.driver.class=org.postgresql.Driver -Dds1.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds1.jdbc.driver.path=path-to-driver -Dds1.hibernate.dialect=org.hibernate.dialect.PostgreSQL82Dialect -Dds1.db.name=crashrec2 -Dds1.user=crashrec2 -Dds1.pass=crashrec2 -Dds1.jdbc.url=jdbc:postgresql://postgres-101.rhev-ci-vms.eng.rdu2.redhat.com:5432/crashrec2 -DfailIfNoTests=false -Dts.jbossts1.node.identifier=TWkA -Dts.jbossts2.node.identifier=RJSN -Dts.jbossts3.node.identifier=WYYJ You can use your own DB

    Description

      Scenario

      1. Server1 enlists dummy XA resource and make JPA call
      2. Server1 calls a EJB on Server2
      3. Server2 enlists dummy XA resource and make JPA call
      4. Server2 is halted at the beginning of dummy XA resource
      5. Transaction is supposed to be rolled back

      We can see following lines in the log of Server1

      2019-04-02 21:22:41,707 TRACE [com.arjuna.ats.jta] (default task-2) XAResourceRecord.topLevelAbort for XAResourceRecord < resource:Subordinate XAResource at http-remoting://127.0.0.1:8180, txid:< formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:-70ba203e:5ca3d272:2f, node_name=TWkA, branch_uid=0:ffff7f000001:-70ba203e:5ca3d272:35, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@531d7d94 >, record id=0:ffff7f000001:-70ba203e:5ca3d272:36
      2019-04-02 21:22:41,708 WARN  [com.arjuna.ats.jta] (default task-2) ARJUNA016045: attempted rollback of < formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:-70ba203e:5ca3d272:2f, node_name=TWkA, branch_uid=0:ffff7f000001:-70ba203e:5ca3d272:35, subordinatenodename=null, eis_name=unknown eis name > (Subordinate XAResource at http-remoting://127.0.0.1:8180) failed with exception code XAException.XAER_RMERR: javax.transaction.xa.XAException: WFTXN0026: Failed to send protocol message to remote peer
      	at org.wildfly.transaction.client.provider.remoting.TransactionClientChannel.rollback(TransactionClientChannel.java:98)
      	at org.wildfly.transaction.client.provider.remoting.RemotingRemoteTransactionPeer$1.rollback(RemotingRemoteTransactionPeer.java:149)
      	at org.wildfly.transaction.client.SubordinateXAResource.rollback(SubordinateXAResource.java:174)
      	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelAbort(XAResourceRecord.java:362)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3023)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.doAbort(BasicAction.java:3002)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Abort(BasicAction.java:1981)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1519)
      	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:1288)
      	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.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:75)
      	at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:88)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:261)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      	at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
      	at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:80)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
      	at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:618)
      	at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
      	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
      	at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:406)
      	at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:565)
      	at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:546)
      	at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:197)
      	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
      	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
      	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
      	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
      	at java.lang.Thread.run(Thread.java:748)
      Caused by: org.jboss.remoting3.NotOpenException: Writes closed
      	at org.jboss.remoting3.remote.RemoteConnectionChannel.openOutboundMessage(RemoteConnectionChannel.java:106)
      	at org.jboss.remoting3.remote.RemoteConnectionChannel.writeMessage(RemoteConnectionChannel.java:291)
      	at org.jboss.remoting3.util.MessageTracker.openMessage(MessageTracker.java:64)
      	at org.jboss.remoting3.util.InvocationTracker.allocateMessage(InvocationTracker.java:189)
      	at org.jboss.remoting3.util.InvocationTracker.allocateMessage(InvocationTracker.java:205)
      	at org.wildfly.transaction.client.provider.remoting.TransactionClientChannel.rollback(TransactionClientChannel.java:91)
      	... 58 more
      
      2019-04-02 21:22:41,709 WARN  [com.arjuna.ats.arjuna] (default task-2) ARJUNA012089: Top-level abort of action 0:ffff7f000001:-70ba203e:5ca3d272:2f received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD
      

      TLDR;
      Server2 is halted and Server1 gets XAER_RMERR. During abort/rollback Server2 is still down and Server1 gets XAER_RMERR. Result of this is that the transaction is in heuristic state and not rolled back.

      Based of the XA spec (http://pubs.opengroup.org/onlinepubs/009680699/toc.pdf) the XAER_RMFAIL (or XA_RETRY) is the correct XAException error code.

      XAER_RMERR
      a resource manager error occurred in the transaction branch

      XAER_RMFAIL
      resource manager unavailable

      XA_RETRY
      routine returned with no effect and may be reissued

      Attachments

        Issue Links

          Activity

            People

              ochaloup@redhat.com Ondrej Chaloupka (Inactive)
              istraka@redhat.com Ivan Straka
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: