[JBoss JIRA] (WFLY-5543) Can't recover transaction started by MDB on WSMQ when RAR is deployed as an archive
10:43 a.m.
[
https://issues.jboss.org/browse/WFLY-5543?page=com.atlassian.jira.plugin....
]
Ondřej Chaloupka edited comment on WFLY-5543 at 10/29/15 11:42 AM:
-------------------------------------------------------------------
[~mmusgrov] ok, you're right. that was probably my wrong assumption where the
exception was put out of. Nevertheless from my debugging it seems to me quite strange as
I've got only {{EJBXAResourceDeserializer}} deserializer and no one else and that one
seemed to me was tried to be used for deserialization of IBM xaresource. But I could be
easily wrong here. [~zhfeng] what do you have experience here?
Then I did some testing on my machine and I can say that I got exception {{method
'xa_recover' has failed with errorCode '-7'}} as well. Just I got this
exception only when I'm shutting down my WFLY server (not during recovery). This is
what I can get
{code}
16:36:35,449 WARN [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012281:
ShadowingStore::read_state() - no type name given for object state
0:ffff0a105b01:35345c2a:5617033b:26
16:36:35,451 WARN [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016027: Local
XARecoveryModule.xaRecovery got XA exception XAException.XAER_RMFAIL:
javax.transaction.xa.XAException: The method 'xa_recover' has failed with
errorCode '-7' due to the resource being closed.
at com.ibm.mq.jmqi.JmqiXAResource.recover(JmqiXAResource.java:806)
at com.ibm.mq.connector.xa.XARWrapper.recover(XARWrapper.java:470)
at
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:185)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:744)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:435)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:219)
at
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:793)
at
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375)
{code}
There is interesting similarity with exception
https://bugzilla.redhat.com/show_bug.cgi?id=1129891 (aka
https://issues.jboss.org/browse/JBTM-1810). I'm not sure here if it's relevant or
only a coincidence.
Then I can say that it seems that setting security domain does not help and I can still
get exception
{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.DR13/modules,/home/ochaloup/jboss/jboss-eap-7.0.0.DR13/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.WARN [com.arjuna.ats.arjuna] (Periodic Recovery)
ARJUNA012379: ExpiredTransactionScanner - 0:ffff0a28048f:-470895ed:5624c495:34 is assumed
complete and will be moved.
{code}
my resource adapter is configured as
{code}
<resource-adapters>
<resource-adapter id="wmq.jmsra.rar">
<archive>
wmq.jmsra.rar
</archive>
<transaction-support>XATransaction</transaction-support>
<connection-definitions>
<connection-definition
class-name="com.ibm.mq.connector.outbound.ManagedConnectionFactoryImpl"
jndi-name="java:/JmsXA" use-java-context="false"
pool-name="JMS_XAQCF">
<config-property name="channel">
CH
</config-property>
<config-property name="hostName">
dev120.mw.lab.eng.bos.redhat.com
</config-property>
<config-property name="transportType">
CLIENT
</config-property>
<config-property name="queueManager">
QM
</config-property>
<config-property name="port">
1414
</config-property>
<security>
<application/>
</security>
<!--<recovery>
<recover-credential>
<user-name>mqm</user-name>
<password>mqm</password>
</recover-credential>
</recovery>-->
<recovery>
<recover-credential>
<security-domain>mqm</security-domain>
</recover-credential>
</recovery>
</connection-definition>
</connection-definitions>
<admin-objects>
<admin-object
class-name="com.ibm.mq.connector.outbound.MQQueueProxy"
jndi-name="java:jboss/crashRecoveryQueue" enabled="true"
pool-name="IBMMQ_RECOVERY_QUEUE">
<config-property name="baseQueueName">
QRECOVERY.TS
</config-property>
<config-property name="baseQueueManagerName">
QM
</config-property>
</admin-object>
<admin-object
class-name="com.ibm.mq.connector.outbound.MQQueueProxy"
jndi-name="java:jboss/MDBTriggerQueue" enabled="true"
pool-name="IBMMQ_MDB_QUEUE">
<config-property name="baseQueueName">
QRECOVERY.MDB.TS
</config-property>
<config-property name="baseQueueManagerName">
QM
</config-property>
</admin-object>
</admin-objects>
</resource-adapter>
...
<security-domain name="mqm">
<authentication>
<login-module code="ConfiguredIdentity"
flag="required">
<module-option name="principal"
value="mqm"/>
<module-option name="userName"
value="mqm"/>
<module-option name="password"
value="mqm"/>
<module-option name="password-stacking"
value="useFirstPass"/>
</login-module>
</authentication>
</security-domain>
{code}
Then I have another intersting observation and it's that it seems that the problem is
only for up-to-down recovery. Bottom-up seems to work as it returns the in-doubt
transactions sitting on server
{code}
./bin/standalone.sh -c standalone-full.wmq.xml
-Dcom.arjuna.ats.arjuna.recovery.periodicRecoveryPeriod=20
{code}
and log contains
{code}
2015-10-29 16:40:24,196 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of
XAResourceWrapperImpl@603cdb89[xaResource=com.ibm.mq.connector.xa.XARWrapper(a)7ea3f0bf
pad=false overrideRmValue=null productName=WebSphere MQ productVersion=%I% %E% %U%
jndiName=java:/JmsXA]
2015-10-29 16:40:24,344 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 1 xids in
doubt
2015-10-29 16:40:24,344 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Recovered: <
131077, 32, 36, 0000000000-1-11016911535292428623359000388312087122,
0000000000-1-110169115352924286233590003900000000 >
2015-10-29 16:40:24,344 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids new
recoveryXids
XAResourceWrapperImpl@603cdb89[xaResource=com.ibm.mq.connector.xa.XARWrapper(a)7ea3f0bf
pad=false overrideRmValue=null productName=WebSphere MQ productVersion=%I% %E% %U%
jndiName=java:/JmsXA] 1446133224344
2015-10-29 16:40:24,345 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
InputObjectState::InputObjectState()
2015-10-29 16:40:24,346 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
FileSystemStore.allObjUids(EISNAME, InputObjectState Uid : 0:0:0:0:0
InputObjectState Type : null
InputObjectState Size : 0
InputObjectState Buffer: , -1)
2015-10-29 16:40:24,346 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
OutputObjectState::OutputObjectState()
{code}
was (Author: ochaloup):
[~mmusgrov] ok, you're right. that was probably my wrong assumption where the
exception was put out of. Nevertheless from my debugging it seems to me quite strange as
I've got only {{EJBXAResourceDeserializer}} deserializer and no one else and that one
seemed to me was tried to be used for deserialization of IBM xaresource. But I could be
easily wrong here. [~zhfeng] what do you have experience here?
Then I did some testing on my machine and I can say that I got exception {{method
'xa_recover' has failed with errorCode '-7'}} as well. Just I got this
exception only when I'm shutting down my WFLY server (not during recovery). This is
what I can get
{code}
16:36:35,449 WARN [com.arjuna.ats.arjuna] (Periodic Recovery) ARJUNA012281:
ShadowingStore::read_state() - no type name given for object state
0:ffff0a105b01:35345c2a:5617033b:26
16:36:35,451 WARN [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016027: Local
XARecoveryModule.xaRecovery got XA exception XAException.XAER_RMFAIL:
javax.transaction.xa.XAException: The method 'xa_recover' has failed with
errorCode '-7' due to the resource being closed.
at com.ibm.mq.jmqi.JmqiXAResource.recover(JmqiXAResource.java:806)
at com.ibm.mq.connector.xa.XARWrapper.recover(XARWrapper.java:470)
at
org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:185)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:744)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:435)
at
com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:219)
at
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:793)
at
com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375)
There is interesting similarity with exception
https://bugzilla.redhat.com/show_bug.cgi?id=1129891 (aka
https://issues.jboss.org/browse/JBTM-1810). I'm not sure here if it's relevant or
only a coincidence.
Then I can say that it seems that setting security domain does not help and I can still
get exception
{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.DR13/modules,/home/ochaloup/jboss/jboss-eap-7.0.0.DR13/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.WARN [com.arjuna.ats.arjuna] (Periodic Recovery)
ARJUNA012379: ExpiredTransactionScanner - 0:ffff0a28048f:-470895ed:5624c495:34 is assumed
complete and will be moved.
{code}
my resource adapter is configured as
{code}
<resource-adapters>
<resource-adapter id="wmq.jmsra.rar">
<archive>
wmq.jmsra.rar
</archive>
<transaction-support>XATransaction</transaction-support>
<connection-definitions>
<connection-definition
class-name="com.ibm.mq.connector.outbound.ManagedConnectionFactoryImpl"
jndi-name="java:/JmsXA" use-java-context="false"
pool-name="JMS_XAQCF">
<config-property name="channel">
CH
</config-property>
<config-property name="hostName">
dev120.mw.lab.eng.bos.redhat.com
</config-property>
<config-property name="transportType">
CLIENT
</config-property>
<config-property name="queueManager">
QM
</config-property>
<config-property name="port">
1414
</config-property>
<security>
<application/>
</security>
<!--<recovery>
<recover-credential>
<user-name>mqm</user-name>
<password>mqm</password>
</recover-credential>
</recovery>-->
<recovery>
<recover-credential>
<security-domain>mqm</security-domain>
</recover-credential>
</recovery>
</connection-definition>
</connection-definitions>
<admin-objects>
<admin-object
class-name="com.ibm.mq.connector.outbound.MQQueueProxy"
jndi-name="java:jboss/crashRecoveryQueue" enabled="true"
pool-name="IBMMQ_RECOVERY_QUEUE">
<config-property name="baseQueueName">
QRECOVERY.TS
</config-property>
<config-property name="baseQueueManagerName">
QM
</config-property>
</admin-object>
<admin-object
class-name="com.ibm.mq.connector.outbound.MQQueueProxy"
jndi-name="java:jboss/MDBTriggerQueue" enabled="true"
pool-name="IBMMQ_MDB_QUEUE">
<config-property name="baseQueueName">
QRECOVERY.MDB.TS
</config-property>
<config-property name="baseQueueManagerName">
QM
</config-property>
</admin-object>
</admin-objects>
</resource-adapter>
...
<security-domain name="mqm">
<authentication>
<login-module code="ConfiguredIdentity"
flag="required">
<module-option name="principal"
value="mqm"/>
<module-option name="userName"
value="mqm"/>
<module-option name="password"
value="mqm"/>
<module-option name="password-stacking"
value="useFirstPass"/>
</login-module>
</authentication>
</security-domain>
{code}
Then I have another intersting observation and it's that it seems that the problem is
only for up-to-down recovery. Bottom-up seems to work as it returns the in-doubt
transactions sitting on server
{code}
./bin/standalone.sh -c standalone-full.wmq.xml
-Dcom.arjuna.ats.arjuna.recovery.periodicRecoveryPeriod=20
{code}
and log contains
{code}
2015-10-29 16:40:24,196 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of
XAResourceWrapperImpl@603cdb89[xaResource=com.ibm.mq.connector.xa.XARWrapper(a)7ea3f0bf
pad=false overrideRmValue=null productName=WebSphere MQ productVersion=%I% %E% %U%
jndiName=java:/JmsXA]
2015-10-29 16:40:24,344 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 1 xids in
doubt
2015-10-29 16:40:24,344 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Recovered: <
131077, 32, 36, 0000000000-1-11016911535292428623359000388312087122,
0000000000-1-110169115352924286233590003900000000 >
2015-10-29 16:40:24,344 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids new
recoveryXids
XAResourceWrapperImpl@603cdb89[xaResource=com.ibm.mq.connector.xa.XARWrapper(a)7ea3f0bf
pad=false overrideRmValue=null productName=WebSphere MQ productVersion=%I% %E% %U%
jndiName=java:/JmsXA] 1446133224344
2015-10-29 16:40:24,345 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
InputObjectState::InputObjectState()
2015-10-29 16:40:24,346 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
FileSystemStore.allObjUids(EISNAME, InputObjectState Uid : 0:0:0:0:0
InputObjectState Type : null
InputObjectState Size : 0
InputObjectState Buffer: , -1)
2015-10-29 16:40:24,346 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery)
OutputObjectState::OutputObjectState()
{code}
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: JCA, Transactions
Affects Versions: 10.0.0.CR2
Reporter: Ondřej Chaloupka
Assignee: Amos Feng
Priority: Blocker
Fix For: 10.0.0.Final
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}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
3358
days inactive
3358
days old
0 comments
1 participants
participants (1)
-
Ondřej Chaloupka (JIRA)