Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-6392

JTS works incorrectly for JMS connection being interrupted at commit phase

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Blocker
    • 7.1.0.DR9
    • 7.1.0.DR6
    • Transactions
    • None
    • Regression
    • Hide 
      git clone http://git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.git
export JBOSS_HOME=... (downloadable at http://download.eng.brq.redhat.com/devel/candidates/JBEAP/)
mvn clean verify -am -pl jbossts -DfailIfNoTests=false -Djbossts.noJTA -Dtest=JMSProxyMessagingServerCrashRecoveryTestCase#prepareHalt
      Show
      git clone http: //git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.git export JBOSS_HOME=... (downloadable at http: //download.eng.brq.redhat.com/devel/candidates/JBEAP/) mvn clean verify -am -pl jbossts -DfailIfNoTests= false -Djbossts.noJTA -Dtest=JMSProxyMessagingServerCrashRecoveryTestCase#prepareHalt

    Description

      I do experience regression against DR5 (Narayana 5.3.3.Final) with current DR6 (Narayana 5.3.5.Final) release.

      The following scenario fails when JTS is used

      • prepare jms XA
      • stop connection to jms broker
      • prepare test XA
      • call commit on jms XA
        as connection is down we can experience XAException.XA_RETRY
      • commit test XA
        (the test XA is committed as XA_RETRY commands to finish the commit later which is made by recovery)
      • recovery: commit jms XA

      in 7.1.0.DR6 version the recovery does not commit but rollback which can cause data integrity failure.

      2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( getStatus ) nodeId=1 requestId=135
2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( getStatus ) nodeId=1 requestId=135
2016-10-11 17:03:32,194 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( getStatus ) nodeId=1 requestId=132
2016-10-11 17:03:32,194 DEBUG [com.arjuna.ats.jts] (Periodic Recovery) StatusChecker.getStatus(0:ffff7f000001:-687fd072:57fcfee8:4f) - stored status = CosTransactions::StatusNoTransaction
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::send_reply ( replay_completion ) nodeId=1 requestId=133
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionServerRequestInterceptorImpl::suspendContext ( replay_completion ) nodeId=1 requestId=133
2016-10-11 17:03:32,195 DEBUG [com.arjuna.ats.jts] (Thread-276) ResourceCompletor.rollback()
2016-10-11 17:03:32,195 TRACE [com.arjuna.ats.jts] (Periodic Recovery) InterpositionClientRequestInterceptorImpl::receive_reply ( replay_completion ) nodeId=1 requestId=130
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionClientRequestInterceptorImpl::send_request ( rollback ) nodeId=1 requestId=133
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.recover got status: CosTransactions::StatusRolledBack
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) ContextManager::current ()
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.doRecovery ( false )
2016-10-11 17:03:32,196 INFO  [com.arjuna.ats.jtax] (Periodic Recovery) ARJUNA024002: XA recovery rolling back < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Periodic Recovery) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request_service_contexts ( rollback ) nodeId=1 requestId=136
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jts] (Thread-276) InterpositionServerRequestInterceptorImpl::receive_request ( rollback ) nodeId=1 requestId=136
2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Periodic Recovery) Calling rollback:: xid=XidImpl (948004762 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [com.arjuna.ats.jtax] (Thread-276) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,196 TRACE [org.apache.activemq.artemis.core.client.impl.ClientSessionImpl] (Thread-276) Calling rollback:: xid=XidImpl (1942398309 bq:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.84.0.0.0.0.0.0.0.0 formatID:131072 gtxid:0.0.0.0.0.0.0.0.0.0.-1.-1.127.0.0.1.-105.-128.47.-114.87.-4.-2.-24.0.0.0.79.49 base64:AAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAAVAAAAAAAAAAAAAAAAAAAAAAAAP__fwAAAZeAL45X_P7oAAAATzECAgIA,clientXID=< 131072, 29, 36, 0000000000-1-1127001-105-12847-11487-4-2-240007949, 0000000000-1-1127001-105-12847-11487-4-2-240008400000000 >
2016-10-11 17:03:32,197 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Periodic Recovery) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
2016-10-11 17:03:32,240 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl] (Thread-3 (ActiveMQ-client-netty-threads-2140185711)) handling packet PACKET(SessionXAResponseMessage)[type=55, channelID=10, packetObject=SessionXAResponseMessage]
2016-10-11 17:03:32,241 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) HornetqObjectStore.remove_committed(0:ffff7f000001:-687fd072:57fcfee8:55, /CosTransactions/XAResourceRecord)
2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.journal.impl.JournalImpl] (Periodic Recovery) appendDeleteRecord::id=1, usedFile = JournalFileImpl: (jbossts-1.txlog id = 1, recordID = 1)
2016-10-11 17:03:32,241 TRACE [org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl] (Thread-276) Sending blocking PACKET(SessionXARollbackMessage)[type=56, channelID=10, packetObject=SessionXARollbackMessage]
2016-10-11 17:03:32,247 TRACE [com.arjuna.orbportability] (Periodic Recovery) RootOA::shutdownObject (Servant)
2016-10-11 17:03:32,248 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@4b366010, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@5db75d15}, transactionOriginNodeIdentifier='1'} 1476198202113 1476198212248 false
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check TestXAResourceRecovered(TestXAResourceCommon(id:473, xid:null, timeout:0, prepareReturn:0)) 1476198162076 1476198212248 true
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@16b79fd1 1476198161776 1476198212251 true
2016-10-11 17:03:32,251 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids isStale Check org.jboss.activemq.artemis.wildfly.integration.WildFlyActiveMQXAResourceWrapper@130c1cb1 1476198202161 1476198212251 false
2016-10-11 17:03:32,251 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) JTS XARecoveryModule.resourceInitiatedRecovery completed

      Attachments

        Issue Links

          is blocked by

          Bug - A problem that impairs or prevents the functions of the product. JBTM-2771 JTS XAResources that throw XA_RETRY or XAER_RMFAIL cannot be retried

          • Blocker - To be worked above all other priorities. This term is chosen when the severity of the issue is very high, has no workaround, or the effort for the change is comparatively low. Issues that may be very publicly visible and could generate significant media attention may also drive a higher priority.
          • Closed

          Component Upgrade - A task tracking an update to a bundled component or revision of component upstream of the project. JBEAP-7020 Upgrade Narayana to 5.4.0.Final

          • Blocker - To be worked above all other priorities. This term is chosen when the severity of the issue is very high, has no workaround, or the effort for the change is comparatively low. Issues that may be very publicly visible and could generate significant media attention may also drive a higher priority.
          • Verified

          Activity

            People

              thjenkin@redhat.com Tom Jenkinson
              ochaloup@redhat.com Ondrej Chaloupka (Inactive)
              Ondrej Chaloupka Ondrej Chaloupka (Inactive)
              Ondrej Chaloupka Ondrej Chaloupka (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: