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

Recovery doesn't work when transaction is propagated thru EJB remoting

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Blocker
    • 7.1.0.ER2
    • 7.1.0.DR11
    • EJB, Transactions
    • None
    • Hide 
      git clone http://git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.gitexport JBOSS_HOME=... (downloadable at http://download.eng.brq.redhat.com/devel/candidates/JBEAP/)

      DS_PROPS="-Dds0.db=postgresql -Dds0.jdbc.driver.url=http://www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.driver.jar=postgresql-driver.jar -Dds1.db=postgresql -Dds1.jdbc.driver.url=http://www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds1.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds1.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds1.db.name=crashrec2 -Dds1.user=crashrec2 -Dds1.pass=crashrec2 -Dds1.jdbc.driver.jar=postgresql-driver.jar"

      mvn clean verify -am -pl jbossts -fn -Djbossts.noJTS $DS_PROPS -Dtest=TxPropagationJPACrashRecoveryTestCase#commitHaltServer
      Show
      git clone http: //git.app.eng.bos.redhat.com/git/jbossqe-eap-tests-transactions.gitexport JBOSS_HOME=... (downloadable at http://download.eng.brq.redhat.com/devel/candidates/JBEAP/) DS_PROPS= "-Dds0.db=postgresql -Dds0.jdbc.driver.url=http: //www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds0.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds0.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds0.db.name=crashrec -Dds0.user=crashrec -Dds0.pass=crashrec -Dds0.jdbc.driver.jar=postgresql-driver.jar -Dds1.db=postgresql -Dds1.jdbc.driver.url=http://www.qa.jboss.com/jdbc-drivers-products/EAP/7.1.0/postgresql94/jdbc4/postgresql-9.4.1209.jar -Dds1.jdbc.xa-class=org.postgresql.xa.PGXADataSource -Dds1.jdbc.url=jdbc:postgresql://gen-vm006.mw.lab.eng.bos.redhat.com:5432/crashrec -Dds1.db.name=crashrec2 -Dds1.user=crashrec2 -Dds1.pass=crashrec2 -Dds1.jdbc.driver.jar=postgresql-driver.jar" mvn clean verify -am -pl jbossts -fn -Djbossts.noJTS $DS_PROPS -Dtest=TxPropagationJPACrashRecoveryTestCase#commitHaltServer

    Description

      We have test where tx is propagated (thru EJB remoting) from one server to another. We halt second server during 2PC and then start it again. The transaction should be recovered by TM. The scenario is like:

      1. enlist and use 2 XA resources on server 1
      2. call an ejb on server 2
      3. enlist and use 2 XA resources on server 2
      4. prepare phase - preparing all 4 resources on both servers
      5. commit phase starts
      6. crash JVM of server 2
      7. start server 2 once again
      8. run recovery

      Recovery ends on NPE.

      First server log:

      2017-02-02 15:17:33,802 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) BasicAction::phase2Commit() for action-id 0:ffff7f000001:1ef56039:58933eec:21
2017-02-02 15:17:33,802 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) BasicAction::doCommit (XAResourceRecord < resource:RecoveryOnlySerializedEJBXAResource{ejbReceiverNodeName='jbossts2'}, txid:< formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:1ef56039:58933eec:21, node_name=PJrQ, branch_uid=0:ffff7f000001:1ef56039:58933eec:23, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@e7bfebe >)
2017-02-02 15:17:33,802 TRACE [com.arjuna.ats.jta] (Periodic Recovery) XAResourceRecord.topLevelCommit for XAResourceRecord < resource:RecoveryOnlySerializedEJBXAResource{ejbReceiverNodeName='jbossts2'}, txid:< formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:1ef56039:58933eec:21, node_name=PJrQ, branch_uid=0:ffff7f000001:1ef56039:58933eec:23, subordinatenodename=null, eis_name=unknown eis name >, heuristic: TwoPhaseOutcome.FINISH_OK com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord@e7bfebe >, record id=0:ffff7f000001:1ef56039:58933eec:24
2017-02-02 15:17:33,802 DEBUG [org.jboss.ejb.client.txn] (Periodic Recovery) RecoveryOnlySerializedEJBXAResource{ejbReceiverNodeName='jbossts2'} sending commit request for Xid < formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:1ef56039:58933eec:21, node_name=PJrQ, branch_uid=0:ffff7f000001:1ef56039:58933eec:23, subordinatenodename=null, eis_name=unknown eis name > to EJB receiver with node name jbossts2 during recovery. One phase? false
2017-02-02 15:17:36,834 TRACE [org.jboss.ejb.client.remoting.ChannelAssociation] (default task-44) Received message with header 0x6
2017-02-02 15:17:36,983 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016036: commit on < formatId=131077, gtrid_length=32, bqual_length=36, tx_uid=0:ffff7f000001:1ef56039:58933eec:21, node_name=PJrQ, branch_uid=0:ffff7f000001:1ef56039:58933eec:23, subordinatenodename=null, eis_name=unknown eis name > (RecoveryOnlySerializedEJBXAResource{ejbReceiverNodeName='jbossts2'}) failed with exception $XAException.XAER_RMFAIL: javax.transaction.xa.XAException
	at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.sendCommit(RemotingConnectionEJBReceiver.java:507)
	at org.jboss.ejb.client.RecoveryOnlySerializedEJBXAResource.commit(RecoveryOnlySerializedEJBXAResource.java:63)
	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:514)
	at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2890)
	at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2806)
	at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1871)
	at com.arjuna.ats.arjuna.recovery.RecoverAtomicAction.replayPhase2(RecoverAtomicAction.java:71)
	at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.doRecoverTransaction(AtomicActionRecoveryModule.java:152)
	at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.processTransactionsStatus(AtomicActionRecoveryModule.java:253)
	at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.periodicWorkSecondPass(AtomicActionRecoveryModule.java:109)
	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:811)
	at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:377)
Caused by: java.lang.NullPointerException
	at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionCommitTask.manageTransaction(XidTransactionCommitTask.java:73)
	at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionManagementTask.run(XidTransactionManagementTask.java:68)
	at org.jboss.as.ejb3.remote.protocol.versionone.TransactionRequestHandler.processMessage(TransactionRequestHandler.java:139)
	at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:212)
	at org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:77)
	at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:158)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.lambda$handleMessageData$3(RemoteConnectionChannel.java:434)
	at org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:789)
	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)
	at ...asynchronous invocation...(Unknown Source)
	at org.jboss.ejb.client.remoting.InvocationExceptionResponseHandler$MethodInvocationExceptionResultProducer.getResult(InvocationExceptionResponseHandler.java:96)
	at org.jboss.ejb.client.remoting.RemotingConnectionEJBReceiver.sendCommit(RemotingConnectionEJBReceiver.java:503)
	... 11 more

      Server 2:

      2017-02-02 15:17:36,696 TRACE [com.arjuna.ats.arjuna] (default task-7)  Restored heuristic decision of TwoPhaseOutcome.PREPARE_OK 0
2017-02-02 15:17:36,696 TRACE [com.arjuna.ats.jta] (default task-7) TransactionImple.getStatus: javax.transaction.Status.STATUS_UNKNOWN
2017-02-02 15:17:36,696 TRACE [com.arjuna.ats.jta] (default task-7) TransactionImpleManager.suspend
2017-02-02 15:17:36,696 TRACE [com.arjuna.ats.jta] (default task-7) TransactionImpleManager.suspend
2017-02-02 15:17:36,696 ERROR [org.jboss.as.ejb3.remote] (default task-7) WFLYEJB0155: Error during transaction management of transaction id XidTransactionID [485048484850484848535048484848484848484848484848484848484848484870707070557048484848484949697053544851575356575151696967484848484848504953485265555053495052484848484848484848484848484848484848484870707070557048484848484949697053544851575356575151696967484848484848505148484848484848484848484848484848]: java.lang.NullPointerException
	at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionCommitTask.manageTransaction(XidTransactionCommitTask.java:73)
	at org.jboss.as.ejb3.remote.protocol.versionone.XidTransactionManagementTask.run(XidTransactionManagementTask.java:68)
	at org.jboss.as.ejb3.remote.protocol.versionone.TransactionRequestHandler.processMessage(TransactionRequestHandler.java:139)
	at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:212)
	at org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:77)
	at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:158)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.lambda$handleMessageData$3(RemoteConnectionChannel.java:434)
	at org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:789)
	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)

2017-02-02 15:17:37,300 TRACE [com.arjuna.ats.arjuna] (default task-8) InputObjectState::InputObjectState()

      It seems to me that regression was caused by this commit: https://github.com/wildfly/wildfly/commit/32afade7748d158c9b91502d86af85d9054d936c

      Attachments

        1. org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.txt
          12 kB
          Flavia Rainone
        2. org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.txt
          12 kB
          Flavia Rainone
        3. org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta-output.txt
          379 kB
          Flavia Rainone
        4. org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta-output.txt
          379 kB
          Flavia Rainone
        5. server1.log
          329 kB
          Daniel Simko
        6. TEST-org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.xml
          399 kB
          Flavia Rainone
        7. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
          406 kB
          Flavia Rainone
        8. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
          405 kB
          Flavia Rainone
        9. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
          468 kB
          Flavia Rainone
        10. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
          384 kB
          Flavia Rainone
        11. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server1.log
          891 kB
          Daniel Simko
        12. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
          451 kB
          Flavia Rainone
        13. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
          450 kB
          Flavia Rainone
        14. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
          1.32 MB
          Daniel Simko
        15. TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server-jbossts2.log
          126 kB
          Flavia Rainone

        Issue Links

          blocks

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-3314 Fix transaction recovery failures involving remote EJB resource

          • Critical - To be worked on immediately following BLOCKER issues.
          • Verified
          is blocked by

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-9028 EJB client 4.x can't invoke EJBs if more than one connection in "remote.connections" property is set

          • 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

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-10159 Sticky authentication is not working correctly

          • 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
          is related to

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-11809 TxPropagationJPACrashRecoveryTestCase#commitHaltServer fails intermitently

          • 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

          Bug - A problem that impairs or prevents the functions of the product. WFLY-11937 WF transaction client returns XAER_RMERR during abort after server with subordinate transaction fails

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed

          Bug - A problem that impairs or prevents the functions of the product. WFTC-27 Include In-flight Transaction recovery in remote channels

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Open
          relates to

          Bug - A problem that impairs or prevents the functions of the product. WFTC-25 Failed transactions saved in the Narayana object store are not available during import

          • Critical - To be worked on immediately following BLOCKER issues.
          • Resolved

          Bug - A problem that impairs or prevents the functions of the product. EJBCLIENT-215 Spaces are not trimmed from connection names at jboss-ejb-client.properties

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Resolved

          Bug - A problem that impairs or prevents the functions of the product. WFTC-24 Failure to connect when dealing with transactions should return XAER_RMFAIL

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Resolved

          Activity

            People

              flaviarnn Flavia Rainone
              dsimko Daniel Simko (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: