Loading...

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 10.0.0.Final
Affects Version/s: 10.0.0.CR2
Component/s: JCA, Transactions
Labels:
None

Steps to Reproduce:
Hide

start server with configuration pointing to WSMQ

start receiving data from MDB and enlist one more resource to get XA doing 2PC

crash jvm server at the start of commit phase of 2PC

restart the server and see the warning

The exception should be seen when attached transaction log with unfinished transaction and xml configuration and the rar is used.

unzip the txn log to have directory structure like $JBOSS_HOME/standalone/data/tx-object-store/ShadowNoFileLockStore/...

copy standalone-full.wsq.xml to $JBOSS_HOME/standalone/configuration

copy rar archive to $JBOSS_HOME/standalone/deployments

run server like ./bin/standalone.sh -c standalone-full.wmq.xml

after start you can see the exception
Show
start server with configuration pointing to WSMQ start receiving data from MDB and enlist one more resource to get XA doing 2PC crash jvm server at the start of commit phase of 2PC restart the server and see the warning The exception should be seen when attached transaction log with unfinished transaction and xml configuration and the rar is used. unzip the txn log to have directory structure like $JBOSS_HOME/standalone/data/tx-object-store/ShadowNoFileLockStore/... copy standalone-full.wsq.xml to $JBOSS_HOME/standalone/configuration copy rar archive to $JBOSS_HOME/standalone/deployments run server like ./bin/standalone.sh -c standalone-full.wmq.xml after start you can see the exception
Git Pull Request:
https://github.com/wildfly/wildfly/pull/8529

There is a problem with recovering transaction started by MDB pointing to a WSMQ JMS resource.

If I do so then the recovery process fails with [1]

WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016043: Exception on attempting to restore XAResource: java.lang.ClassNotFoundException: com.ibm.mq.connector.xa.XARWrapper from [Module "org.jboss.jts:main" from local module loader @707f7052 (finder: local module finder @11028347 (roots: /home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/modules,/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/modules/system/layers/base))]
 at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:205)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:455)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:404)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:385)
 at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:130)
 at java.lang.Class.forName0(Native Method)
 at java.lang.Class.forName(Class.java:348)
 at java.io.ObjectInputStream.resolveClass(ObjectInputStream.java:626)
 at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1613)
 at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1518)
 at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1774)
 at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)
 at java.io.ObjectInputStream.readObject(ObjectInputStream.java:371)
 at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.restore_state(XAResourceRecord.java:969)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.restore_state(BasicAction.java:1118)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.activate(BasicAction.java:488)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.activate(BasicAction.java:451)
 at com.arjuna.ats.arjuna.recovery.RecoverAtomicAction.<init>(RecoverAtomicAction.java:50)
 at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.doRecoverTransaction(AtomicActionRecoveryModule.java:149)
 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:793)
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375)

WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012154: RecoverAtomicAction: transaction 0:ffff0a28048f:-470895ed:5624c495:34 not activated, unable to replay phase 2 commit. Check state has not already been completed.
InputObjectState Type  : /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction
InputObjectState Size  : 7204
InputObjectState Buffer: )
WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012379: ExpiredTransactionScanner - 0:ffff0a28048f:-470895ed:5624c495:34 is assumed complete and will be moved.

This means that instead of commiting the unfinished transaction the txn log is put to expired part of txn object store and the transaction on wsmq broker side is left in-doubt.

I'm attaching my configuration file.

[1] trace level on transaction manager log category

WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016043: Exception on attempting to restore XAResource: java.lang.ClassNotFoundException: com.ibm.mq.connector.xa.XARWrapper from [Module "org.jboss.jts:main" from local module loader @707f7052 (finder: local module finder @11028347 (roots: /home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/modules,/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/modules/system/layers/base))]
 at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:205)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:455)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:404)
 at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:385)
 at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:130)
 at java.lang.Class.forName0(Native Method)
 at java.lang.Class.forName(Class.java:348)
 at java.io.ObjectInputStream.resolveClass(ObjectInputStream.java:626)
 at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1613)
 at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1518)
 at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1774)
 at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)
 at java.io.ObjectInputStream.readObject(ObjectInputStream.java:371)
 at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.restore_state(XAResourceRecord.java:969)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.restore_state(BasicAction.java:1118)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.activate(BasicAction.java:488)
 at com.arjuna.ats.arjuna.coordinator.BasicAction.activate(BasicAction.java:451)
 at com.arjuna.ats.arjuna.recovery.RecoverAtomicAction.<init>(RecoverAtomicAction.java:50)
 at com.arjuna.ats.internal.arjuna.recovery.AtomicActionRecoveryModule.doRecoverTransaction(AtomicActionRecoveryModule.java:149)
 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:793)
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375)

DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) RecoverAtomicAction.replayPhase2 recovering 0:ffff0a28048f:-470895ed:5624c495:34 ActionStatus is ActionStatus.COMMITTED
WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012154: RecoverAtomicAction: transaction 0:ffff0a28048f:-470895ed:5624c495:34 not activated, unable to replay phase 2 commit. Check state has not already been completed.
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) StateManager::StateManager( 2, 0 )
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) BasicAction::BasicAction()
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.read_committed(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.read_state(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_SHADOW)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 10)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 11)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.currentState(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction) - returning StateStatus.OS_COMMITTED
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 11)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.openAndLock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a28048f_-470895ed_5624c495_34, FileLock.F_RDLCK, false)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.closeAndUnlock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a28048f_-470895ed_5624c495_34, java.io.FileInputStream@13c3edbd, null)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState(InputObjectState Uid   : 0:ffff0a28048f:-470895ed:5624c495:34
InputObjectState Type  : /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction
InputObjectState Size  : 7204
InputObjectState Buffer: )
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.write_committed(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.write_state(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired, 11)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.openAndLock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired/0_ffff0a28048f_-470895ed_5624c495_34, FileLock.F_WRLCK, true)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.createHierarchy(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired/0_ffff0a28048f_-470895ed_5624c495_34)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.closeAndUnlock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/Expired/0_ffff0a28048f_-470895ed_5624c495_34, null, java.io.FileOutputStream@322aab6a)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.remove_committed(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.remove_state(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_SHADOW)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 10)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 11)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.currentState(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction) - returning StateStatus.OS_COMMITTED
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) ShadowingStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, StateType.OS_ORIGINAL)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.genPathName(0:ffff0a28048f:-470895ed:5624c495:34, /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction, 11)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.openAndLock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a28048f_-470895ed_5624c495_34, FileLock.F_WRLCK, false)
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.closeAndUnlock(/home/ochaloup/jboss/jboss-eap-7.0.0.DR11-wsmq2/standalone/data/tx-object-store/ShadowNoFileLockStore/defaultStore/StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction/0_ffff0a28048f_-470895ed_5624c495_34, null, null)
WARN  [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012379: ExpiredTransactionScanner - 0:ffff0a28048f:-470895ed:5624c495:34 is assumed complete and will be moved.
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) XARecoveryModule state change BETWEEN_PASSES->SECOND_PASS

DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass
DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed
DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) XARecoveryModule state change SECOND_PASS->IDLE

DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE
DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off

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

standalone-full.wmq.xml
25 kB
2015/10/20 9:27 AM
tx-object-store.zip
6 kB
2015/10/20 9:27 AM

clones

JBEAP-1523 Can't recover transaction started by MDB on WSMQ when RAR is deployed as an archive

Closed

is blocked by

JBTM-2550 If a class cannot be deserialized safely, try to fallback and use the XARecoveryModule to locate an appropriate XAResource

Closed

WFLY-5714 Upgrade Narayana to 5.2.8.Final

Closed

WFLY-5908 Upgrade Narayana to 5.2.10.Final

Closed

WFLY-5909 Upgrade Narayana to 5.2.11.Final

Closed

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates