Bug 1111141

During the bz cleanup I checked this bz and I didn't find way how to reproduce the problem. This problem didn't cause any data inegrity problem either and just meant a error message in log.
This was not spotted during 6.3.0 testing as I know.

Closing as not a bug.

In case that we would hit this in some future we would reopen this bz.

I've hit this during testing 6.4.0. The enhanced log is added here [1].
We did a short research on this and it seems that it could be caused by some synchronization issue on HornetQ side. Following description is only hypothesis.
There is used inVM connector when JTS implementation calls rollback in one thread (RequestProcessor-10). As rollback was already called on specific xid then hornetq is expected to return XAER_NOTA which happens. But meanwhile there is second thread (Periodic Recovery) which calls 'recover'. It seems that recover is not successful as needs to wait till rollback ends its work which takes some time and due to a timeout exception is thrown.


[1]
TRACE [com.arjuna.ats.jtax] (RequestProcessor-10) XAResourceRecord.rollback for < 131072, 29, 36, 0000000000-1-11016-7692-88-4-436184-11414-580006349, 0000000000-1-11016-7692-88-4-436184-11414-580006800000000 >
INFO  [org.jboss.as.test.jbossts.common.TestXAResourceRecoveryHelper] (Periodic Recovery) getXAResources()
DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@9da95e28, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@f4fb4d5d}, transactionOriginNodeIdentifier='1'}
DEBUG [com.arjuna.ats.jta] (Periodic Recovery) Found 0 xids in doubt
TRACE [com.arjuna.ats.arjuna] (Periodic Recovery) RecoveryXids updateIfEquivalentRM2 RecoveryOnlyEJBXAResource{receiverContext=EJBReceiverContext{clientContext=org.jboss.ejb.client.EJBClientContext@9da95e28, receiver=org.jboss.as.ejb3.remote.LocalEjbReceiver@f4fb4d5d}, transactionOriginNodeIdentifier='1'} 1418596148116
DEBUG [com.arjuna.ats.jta] (Periodic Recovery) xarecovery of HornetQXAResourceWrapper [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], csf=ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], delegate=DelegatingSession [session=ClientSessionImpl [name=7fbb1efd-83e0-11e4-8ca6-a59f5c248488, username=null, closed=false, factory = ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null], metaData=()]@5361c8f8], xaRecoveryConfigs=[XARecoveryConfig [transportConfiguration = [TransportConfiguration(name=7c6bf3f9-83e0-11e4-8ca6-a59f5c248488, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryConfiguration = null, username=null, password=****]], instance=441802302]
WARN  [org.hornetq.jms.server] (Periodic Recovery) HQ122013: Error in XA Recovery recover: javax.transaction.xa.XAException
 at org.hornetq.core.client.impl.ClientSessionImpl.recover(ClientSessionImpl.java:1693) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.core.client.impl.DelegatingSession.recover(DelegatingSession.java:446) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.jms.server.recovery.HornetQXAResourceWrapper.recover(HornetQXAResourceWrapper.java:84) [hornetq-jms-server-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass(XARecoveryModule.java:541) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:181) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:747) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
Caused by: HornetQException[errorType=CONNECTION_TIMEDOUT message=HQ119014: Timed out waiting for response when sending packet 61]
 at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:390) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.core.client.impl.ClientSessionImpl.recover(ClientSessionImpl.java:1682) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 ... 6 more
WARN  [com.arjuna.ats.jta] (Periodic Recovery) ARJUNA016027: JTS XARecoveryModule.xaRecovery got XA exception XAException.XAER_RMERR: javax.transaction.xa.XAException
 at org.hornetq.core.client.impl.ClientSessionImpl.recover(ClientSessionImpl.java:1693) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.core.client.impl.DelegatingSession.recover(DelegatingSession.java:446) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.jms.server.recovery.HornetQXAResourceWrapper.recover(HornetQXAResourceWrapper.java:84) [hornetq-jms-server-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.xaRecoveryFirstPass(XARecoveryModule.java:541) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.jta.recovery.arjunacore.XARecoveryModule.periodicWorkFirstPass(XARecoveryModule.java:181) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.doWorkInternal(PeriodicRecovery.java:747) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
 at com.arjuna.ats.internal.arjuna.recovery.PeriodicRecovery.run(PeriodicRecovery.java:375) [jbossjts-jacorb-4.17.26.Final-redhat-1.jar:4.17.26.Final-redhat-1]
Caused by: HornetQException[errorType=CONNECTION_TIMEDOUT message=HQ119014: Timed out waiting for response when sending packet 61]
 at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:390) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 at org.hornetq.core.client.impl.ClientSessionImpl.recover(ClientSessionImpl.java:1682) [hornetq-core-client-2.3.24.Final-redhat-1.jar:2.3.24.Final-redhat-1]
 ... 6 more
DEBUG [com.arjuna.ats.jtax] (RequestProcessor-10) XARecoveryResourceImple.notAProblem - no error with XAER_NOTA on  rollback