ARJUNA016027 error using the MQ Resource Adapter in JBoss

Solution Verified - Updated -

Environment

  • Red Hat JBoss Enterprise Application Platform (EAP)
    • 6.1.1
  • Java Connector Architecture (JCA)
  • MQ version 7.0.1.10 Resource Adapter
  • during periodic recovery scans

Issue

-

2013-10-22 16:24:37,083 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016027: Local XARecoveryModule.xaRecovery got XA exception XAException.XAER_INVAL: javax.transaction.xa.XAException: The method 'xa_recover' has failed with errorCode '-5'.
        at com.ibm.mq.jmqi.JmqiXAResource.recover(JmqiXAResource.java:745)
        at com.ibm.mq.connector.RecoveryXAResource.recover(RecoveryXAResource.java:448)
        at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:177)
        at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:692) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
        at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:417) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
        at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:194) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
        at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:789) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
        at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]

Resolution

File: 70699.499.000.7.0.1.10-WS-MQ-JavaVM-LAIC97579.zip was supplied by IBM to correct this issue. IBM will need contacted for details.

Diagnostic Steps

Based upon the recover[1] method and the TMENDRSCAN [2] value of 8388608. It looks like the resource adapter is properly handling the TMSTARTRSCAN 16777216 but doesn't recognize how to handle the end of the recovery scan. [3] shows the process, note the begin and end scans at 09:10:21,030 and 09:10:32,452.

Aside from the call stack, I don't have visibility into how the resource adapter is trying to handle or what a -5 errorCode represents.

RULE whatResource
CLASS com.ibm.mq.connector.RecoveryXAResource
METHOD recover
IF TRUE
DO traceStack("---------------------------------> RecoveryXAResource.recover(" + $1 +")\n");
ENDRULE

[1]
http://docs.oracle.com/javaee/7/api/javax/transaction/xa/XAResource.html#recover%28int%29

[2]
http://docs.oracle.com/javaee/7/api/constant-values.html#javax.transaction.xa.XAResource.TMENDRSCAN

[3]

09:10:21,020 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
09:10:21,021 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - first pass
09:10:21,021 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) InputObjectState::InputObjectState()
09:10:21,021 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) FileSystemStore.allObjUids(/StateManager/AbstractRecord/XAResourceRecord, InputObjectState Uid   : 0:0:0:0:0
InputObjectState Type  : null
InputObjectState Size  : 0
InputObjectState Buffer: , -1)
09:10:21,021 TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) OutputObjectState::OutputObjectState()
09:10:21,024 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@1204815e, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@65c94b8f}, transactionOriginNodeIdentifier='1'}
09:10:21,025 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
09:10:21,025 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of XAResourceWrapperImpl@77ffa55[xaResource=com.ibm.mq.connector.RecoveryXAResource@630be64b pad=false overrideRmValue=null productName=Java Message Service productVersion=7.0.1.10-k701-110-130204 jndiName=null]
09:10:21,026 INFO  [stdout] (Periodic Recovery) Rule.execute called for whatResource_8
09:10:21,027 INFO  [stdout] (Periodic Recovery) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper
09:10:21,028 INFO  [stdout] (Periodic Recovery) calling activated() for helper class org.jboss.byteman.rule.helper.Helper
09:10:21,028 INFO  [stdout] (Periodic Recovery) Default helper activated
09:10:21,029 INFO  [stdout] (Periodic Recovery) calling installed(whatResource) for helper classorg.jboss.byteman.rule.helper.Helper
09:10:21,029 INFO  [stdout] (Periodic Recovery) Installed rule using default helper : whatResource
09:10:21,030 INFO  [stdout] (Periodic Recovery) whatResource execute
09:10:21,030 INFO  [stdout] (Periodic Recovery) ---------------------------------> RecoveryXAResource.recover(16777216)
09:10:21,031 INFO  [stdout] (Periodic Recovery) com.ibm.mq.connector.RecoveryXAResource.recover(RecoveryXAResource.java:-1)
09:10:21,031 INFO  [stdout] (Periodic Recovery) org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:177)
09:10:21,031 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass(XARecoveryModule.java:531)
09:10:21,031 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:168)
09:10:21,032 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:743)
09:10:21,032 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371)
09:10:22,446 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
09:10:22,447 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
09:10:32,447 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) Periodic recovery second pass at Tue, 5 Nov 2013 09:10:32
09:10:32,447 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass
09:10:32,448 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
09:10:32,448 DEBUG [com.arjuna.ats.txoj] (Periodic Recovery) TORecoveryModule - second pass
09:10:32,448 DEBUG [com.arjuna.ats.arjuna] (Periodic Recovery)  
09:10:32,448 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule - second pass
09:10:32,448 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed
09:10:32,448 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 0 Xids to recover on this pass.
09:10:32,449 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Have 0 Xids to recover on this pass.
09:10:32,449 INFO  [stdout] (Periodic Recovery) Rule.execute called for whatResource_8
09:10:32,449 INFO  [stdout] (Periodic Recovery) whatResource execute
09:10:32,452 INFO  [stdout] (Periodic Recovery) ---------------------------------> RecoveryXAResource.recover(8388608)
09:10:32,452 INFO  [stdout] (Periodic Recovery) com.ibm.mq.connector.RecoveryXAResource.recover(RecoveryXAResource.java:-1)
09:10:32,452 INFO  [stdout] (Periodic Recovery) org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:177)
09:10:32,453 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:692)
09:10:32,453 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:417)
09:10:32,453 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:194)
09:10:32,453 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:789)
09:10:32,454 INFO  [stdout] (Periodic Recovery) com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371)
09:10:33,752 WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016027: Local XARecoveryModule.xaRecovery got XA exception XAException.XAER_INVAL: javax.transaction.xa.XAException: The method 'xa_recover' has failed with errorCode '-5'.
    at com.ibm.mq.jmqi.JmqiXAResource.recover(JmqiXAResource.java:745)
    at com.ibm.mq.connector.RecoveryXAResource.recover(RecoveryXAResource.java:448)
    at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.recover(XAResourceWrapperImpl.java:177)
    at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoverySecondPass(XARecoveryModule.java:692) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
    at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.bottomUpRecovery(XARecoveryModule.java:417) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
    at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkSecondPass(XARecoveryModule.java:194) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
    at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:789) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]
    at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:371) [jbossjts-jacorb-4.17.7.Final-redhat-4.jar:4.17.7.Final-redhat-4]

09:10:33,755 DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments