]
Ondřej Chaloupka commented on WFLY-5543:
----------------------------------------
[~jesper.pedersen] mentioned that the documentation
says that resource adapter needs to be repacked to contain file {{mqetclient.jar}}. I have
to admit that rar archive that we use does not contain that. But I have tried the run with
the repacked rar archive and there is no change in behavior. I rather think that there is
an issue in our documentation.
In case that the file {{com.ibm.mqetclient.jar}} would be needed it could be find in
repository
under
branch master.
What I can say XA transactions works fine for outbound connection, even recovery, even
withouth {{mqetclient.jar}}. The troubles came when MDB is in play. Non-MDB scenario is
the same just there is only ejb bean sending messages to a queue and jvm is crashed at
some point of time
{code}
rm -rf jbossts/target && mkdir -p jbossts/target && cp -r
~/jms/eap-tests-wsmq jbossts/target/
mvn verify -am -pl jbossts -DfailIfNoTests=false
-Dtest=JMSCrashRecoveryRemoteTestCase#commitHaltAtPhaseBeginning -Djbossts.noJTS
-Dmessaging.remote -Dibmmq.remote -Dno.cleanup
{code}
The same trouble happens for the MDB scenario when WSMQ 8 is used. There is the same
class loading issue
{code}
rm -rf jbossts/target && mkdir -p jbossts/target && cp -r
~/jms/eap-tests-wsmq jbossts/target/
mvn verify -am -pl jbossts -DfailIfNoTests=false
-Dtest=JMSMdbCrashRecoveryRemoteTestCase#commitHaltAtPhaseBeginning -Djbossts.noJTS
-Dmessaging.remote -Dibmmq.remote -Dibmmq8 -Dno.cleanup
{code}
It's probably only coincidence but we have another issue with MDB where rar(?) does
not provide enough information to recovery to finish txn: issue
Can't recover transaction started by MDB on WSMQ when RAR is
deployed as an archive
-----------------------------------------------------------------------------------
Key: WFLY-5543
URL:
https://issues.jboss.org/browse/WFLY-5543
Project: WildFly
Issue Type: Bug
Components: Transactions
Affects Versions: 10.0.0.CR2
Reporter: Ondřej Chaloupka
Assignee: Amos Feng
Priority: Blocker
Fix For: 10.0.0.CR4
Attachments: standalone-full.wmq.xml, tx-object-store.zip
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]
{code}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.
{code}
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
{code}
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
{code}