Loading...

Type: Bug
Resolution: Done
Priority: Blocker
Fix Version/s: 7.1.0.ER2
Affects Version/s: 7.1.0.DR11
Component/s: EJB, Transactions
Labels:
None

CDW devel_ack:
CDW docs_ack:
CDW pm_ack:
CDW qa_ack:
CDW release:
Target Release:

7.1.0.GA
Steps to Reproduce:
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

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

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

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.txt
2017/06/20 9:47 AM
12 kB
Flavia Rainone
org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.txt
2017/06/20 8:42 AM
12 kB
Flavia Rainone
org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta-output.txt
2017/06/20 9:47 AM
379 kB
Flavia Rainone
org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta-output.txt
2017/06/20 8:42 AM
379 kB
Flavia Rainone
server1.log
2017/04/10 6:13 AM
329 kB
Daniel Simko
TEST-org.jboss.as.test.jbossts.crashrec.txpropagation.test.TxPropagationJPACrashRecoveryTestCase-jta.xml
2017/06/20 9:48 AM
399 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
2017/06/20 9:57 AM
406 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
2017/06/20 8:05 AM
405 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
2017/05/12 4:02 AM
468 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server.log
2017/05/12 4:02 AM
384 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server1.log
2017/02/02 10:33 AM
891 kB
Daniel Simko
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
2017/06/20 9:57 AM
451 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
2017/06/20 8:06 AM
450 kB
Flavia Rainone
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server2.log
2017/02/02 10:33 AM
1.32 MB
Daniel Simko
TxPropagationJPACrashRecoveryTestCase_commitHaltServer_jta_server-jbossts2.log
2017/06/19 6:06 AM
126 kB
Flavia Rainone
Hide
TxPropagationJPACrashRecoveryTestCase_commitHaltServer-postgres-ochaloup-passing.zip
2017/06/20 11:10 AM
104 kB
Ondrej Chaloupka
Extracting archive...
Show
TxPropagationJPACrashRecoveryTestCase_commitHaltServer-postgres-ochaloup-passing.zip
2017/06/20 11:10 AM
104 kB
Ondrej Chaloupka

blocks

JBEAP-3314 Fix transaction recovery failures involving remote EJB resource

Verified

is blocked by

JBEAP-9028 EJB client 4.x can't invoke EJBs if more than one connection in "remote.connections" property is set

Closed

JBEAP-10159 Sticky authentication is not working correctly

Closed

is related to

JBEAP-11809 TxPropagationJPACrashRecoveryTestCase#commitHaltServer fails intermitently

Closed

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

Closed

WFTC-27 Include In-flight Transaction recovery in remote channels

Open

relates to

WFTC-25 Failed transactions saved in the Narayana object store are not available during import

Resolved

EJBCLIENT-215 Spaces are not trimmed from connection names at jboss-ejb-client.properties

Resolved

WFTC-24 Failure to connect when dealing with transactions should return XAER_RMFAIL

Resolved

(1 is related to, 3 relates to)

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates