Atomikos Forum

Hi everyone,

we have an issue with the Atomikos Essential edition.

Frameworks and versions used:
* Atomikos Essential Edition: 3.9.3
* ActiveMQ (Client and Server side): 5.9.1
* Spring version: 4.0.5.RELEASE

We have the following sequence:
 1. Start the ActiveMQ broker
 2. Start the application, all works fine
 3. Stop the ActiveMQ broker

At this point we get the following exceptions from Atomikos in an endless way:
<code>
2014-06-12 11:28:42 tpe-1 com.atomikos.datasource.xa.XAResourceTransaction WARN  - XA resource 'connectionFactoryOut': commit for XID '6170695F3134303235363533313236323230303334383030303031:6170695F31343032353635333132363232333438' raised -7: the XA resource has become unavailable
javax.transaction.xa.XAException: The JMS connection has failed: java.io.EOFException
    at org.apache.activemq.TransactionContext.toXAException(TransactionContext.java:793)
    at org.apache.activemq.TransactionContext.commit(TransactionContext.java:590)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:733)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:72)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:83)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:79)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:58)
    at com.atomikos.icatch.imp.CoordinatorStateHandler.commitFromWithinCallback(CoordinatorStateHandler.java:582)
    at com.atomikos.icatch.imp.ActiveStateHandler$6.doCommit(ActiveStateHandler.java:301)
    at com.atomikos.icatch.imp.CoordinatorStateHandler.commitWithAfterCompletionNotification(CoordinatorStateHandler.java:852)
    at com.atomikos.icatch.imp.ActiveStateHandler.commit(ActiveStateHandler.java:296)
    at com.atomikos.icatch.imp.CoordinatorImp.commit(CoordinatorImp.java:707)
    at com.atomikos.icatch.imp.CoordinatorImp.terminate(CoordinatorImp.java:968)
    at com.atomikos.icatch.imp.CompositeTerminatorImp.commit(CompositeTerminatorImp.java:82)
    at com.atomikos.icatch.imp.CompositeTransactionImp.commit(CompositeTransactionImp.java:336)
    at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:190)
    at com.atomikos.icatch.jta.TransactionManagerImp.commit(TransactionManagerImp.java:436)
    at com.atomikos.icatch.jta.UserTransactionImp.commit(UserTransactionImp.java:107)
    at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1021)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150)
    at net.sprd.messaging.test.data_generator.SenderThread$1.run(SenderThread.java:42)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.activemq.ConnectionFailedException: The JMS connection has failed: java.io.EOFException
    at org.apache.activemq.ActiveMQConnection.checkClosedOrFailed(ActiveMQConnection.java:1483)
    at org.apache.activemq.TransactionContext.commit(TransactionContext.java:551)
    ... 26 more
Caused by: java.io.EOFException
    at java.io.DataInputStream.readInt(DataInputStream.java:392)
    at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:275)
    at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:221)
    at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:213)
    at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
    ... 1 more
2014-06-12 11:28:42 tpe-1 com.atomikos.icatch.imp.CommitMessage WARN  - Unexpected error in commit
com.atomikos.icatch.SysException: XA resource 'connectionFactoryOut': commit for XID '6170695F3134303235363533313236323230303334383030303031:6170695F31343032353635333132363232333438' raised -7: the XA resource has become unavailable
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:773)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:72)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:83)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:79)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:58)
    at com.atomikos.icatch.imp.CoordinatorStateHandler.commitFromWithinCallback(CoordinatorStateHandler.java:582)
    at com.atomikos.icatch.imp.ActiveStateHandler$6.doCommit(ActiveStateHandler.java:301)
    at com.atomikos.icatch.imp.CoordinatorStateHandler.commitWithAfterCompletionNotification(CoordinatorStateHandler.java:852)
    at com.atomikos.icatch.imp.ActiveStateHandler.commit(ActiveStateHandler.java:296)
    at com.atomikos.icatch.imp.CoordinatorImp.commit(CoordinatorImp.java:707)
    at com.atomikos.icatch.imp.CoordinatorImp.terminate(CoordinatorImp.java:968)
    at com.atomikos.icatch.imp.CompositeTerminatorImp.commit(CompositeTerminatorImp.java:82)
    at com.atomikos.icatch.imp.CompositeTransactionImp.commit(CompositeTransactionImp.java:336)
    at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:190)
    at com.atomikos.icatch.jta.TransactionManagerImp.commit(TransactionManagerImp.java:436)
    at com.atomikos.icatch.jta.UserTransactionImp.commit(UserTransactionImp.java:107)
    at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1021)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150)
    at net.sprd.messaging.test.data_generator.SenderThread$1.run(SenderThread.java:42)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
</code>


Atomikos doesn't stop to commit the transaction nor tries to make a rollback.

When we start the ActiveMQ broker again the exceptions changes to the following:
<code>
2014-06-12 11:08:38 Atomikos:2 org.apache.activemq.TransactionContext WARN  - commit of: XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834] failed with: javax.jms.JMSException: Transaction 'XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834]' has not been started.
javax.jms.JMSException: Transaction 'XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834]' has not been started.
    at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54)
    at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1408)
    at org.apache.activemq.TransactionContext.syncSendPacketWithInterruptionHandling(TransactionContext.java:757)
    at org.apache.activemq.TransactionContext.commit(TransactionContext.java:557)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:733)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:72)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:83)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:79)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:58)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:131)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:933)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:112)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:99)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834]' has not been started.
    at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:368)
    at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252)
    at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:112)
    at org.apache.activemq.broker.util.LoggingBrokerPlugin.commitTransaction(LoggingBrokerPlugin.java:213)
    at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:112)
    at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:459)
    at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)
    at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)
    at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:145)
    at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
    at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
    at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
    at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
    at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
    at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
    ... 1 more
2014-06-12 11:08:38 Atomikos:2 com.atomikos.datasource.xa.XAResourceTransaction WARN  - XA resource 'connectionFactoryOut': commit for XID '6170695F3134303235363430393634343430303338343030303031:6170695F31343032353634303936343434333834' raised -3: the XA resource detected an internal error
javax.transaction.xa.XAException: Transaction 'XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834]' has not been started.
    at org.apache.activemq.TransactionContext.toXAException(TransactionContext.java:782)
    at org.apache.activemq.TransactionContext.commit(TransactionContext.java:590)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:733)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:72)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:83)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:79)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:58)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:131)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:933)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:112)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:99)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: javax.transaction.xa.XAException: Transaction 'XID:[1096044365,globalId=6170695f3134303235363430393634343430303338343030303031,branchId=6170695f31343032353634303936343434333834]' has not been started.
    at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:368)
    at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252)
    at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:112)
    at org.apache.activemq.broker.util.LoggingBrokerPlugin.commitTransaction(LoggingBrokerPlugin.java:213)
    at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:112)
    at org.apache.activemq.broker.TransportConnection.processCommitTransactionTwoPhase(TransportConnection.java:459)
    at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:102)
    at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)
    at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:145)
    at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
    at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
    at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:270)
    at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
    at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
    at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
    ... 1 more
2014-06-12 11:08:38 Atomikos:2 com.atomikos.icatch.imp.CommitMessage WARN  - Unexpected error in commit
com.atomikos.icatch.SysException: XA resource 'connectionFactoryOut': commit for XID '6170695F3134303235363430393634343430303338343030303031:6170695F31343032353634303936343434333834' raised -3: the XA resource detected an internal error
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:773)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:72)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:83)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:79)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:58)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:131)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:933)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:112)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:99)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
</code>

The exceptions are thrown also in an endless loop and are logged continuously.

Our configuration is as follow:
<code>
<bean id="userTransactionService" class="com.atomikos.icatch.config.UserTransactionServiceImp" init-method="init" destroy-method="shutdownForce">
    <constructor-arg>
    <props>
        <prop key="com.atomikos.icatch.service">com.atomikos.icatch.standalone.UserTransactionServiceFactory</prop>
        <prop key="com.atomikos.icatch.output_dir">${atomikos.outputDir}</prop>
        <prop key="com.atomikos.icatch.console_file_name">api_#{timestamp}.out</prop>
        <prop key="com.atomikos.icatch.console_log_level">DEBUG</prop>
        <prop key="com.atomikos.icatch.tm_unique_name">api_#{timestamp}</prop>
        <prop key="com.atomikos.icatch.threaded_2pc">false</prop>
        <prop key="com.atomikos.icatch.max_actives">10</prop>
        <prop key="com.atomikos.icatch.max_timeout">1000</prop>
        <prop key="com.atomikos.icatch.default_jta_timeout">1000</prop>
        <prop key="com.atomikos.icatch.enable_logging">true</prop>
        <prop key="com.atomikos.icatch.serial_jta_transactions">false</prop>

        <prop key="com.atomikos.icatch.log_base_name">api#{timestamp}</prop>
        <prop key="com.atomikos.icatch.log_base_dir">/tmp/atomikos</prop>
        <prop key="com.atomikos.icatch.checkpoint_interval">5000</prop>
    </props>
    </constructor-arg>
</bean>

<bean id="jmsTemplate" class="org.springframework.jms.core.JmsTemplate">
    <property name="connectionFactory" ref="connectionFactoryOut" />
    <property name="defaultDestination" ref="outQueue" />
    <property name="sessionTransacted" value="true" />
</bean>

<bean id="connectionFactoryOut" class="com.atomikos.jms.AtomikosConnectionFactoryBean" init-method="init" destroy-method="close">
    <property name="uniqueResourceName" value="connectionFactoryOut" />
    <property name="xaConnectionFactory" ref="xaConnectionFactoryOut" />
    <property name="minPoolSize" value="5" />
    <property name="maxPoolSize" value="100" />
    <property name="reapTimeout" value="1000" />
</bean>

<bean id="xaConnectionFactoryOut" class="org.apache.activemq.ActiveMQXAConnectionFactory">
    <property name="brokerURL" value="tcp://localhost:61616" />
    <property name="userName" value="testUser" />
    <property name="password" value="testPassword" />
</bean>

<bean id="outQueue" class="org.apache.activemq.command.ActiveMQQueue" autowire="constructor">
    <constructor-arg name="name" value="router_business_events_in" />
</bean>

<bean id="transactionManagerTemplate" class="org.springframework.transaction.support.TransactionTemplate">
    <constructor-arg name="transactionManager" ref="transactionManager" />
</bean>

<!-- Transaction Manager -->
<bean id="transactionManager" class="org.springframework.transaction.jta.JtaTransactionManager">
    <property name="transactionManager" ref="atomikosTransactionManager" />
    <property name="userTransaction" ref="atomikosUserTransaction" />
</bean>

<bean id="atomikosTransactionManager" class="com.atomikos.icatch.jta.UserTransactionManager" init-method="init" depends-on="userTransactionService" destroy-method="close">
    <property name="forceShutdown" value="true" />
</bean>

<bean id="atomikosUserTransaction" class="com.atomikos.icatch.jta.UserTransactionImp">
    <property name="transactionTimeout" value="299" />
</bean>
</code>


We have made a little investigation and debugging in the source code of Atomikos. We found that the retry mechanism is located in the <code>Propagator</code> class. When all retries are consumed the call will return to "HeurHazardStateHandler" class. There is a "replayStack" that becomes empty but the "harzards_" Vector not. This handler will be called by an Atomikos thread again and because "hazards_" is not empty the retry will be made again for ever.

Can anyone help us with this problem?

Looks like the shutdown order of your components is not right. Make sure that the transaction manager shuts down before your pools do.

Hi,

thank you for your answer but we don't want to shutdown the components. This issue appears during runtime.

OK I noticed your remarks on the hazards only now, sorry.

This is either a known bug / fix or a new fix to be produced by us. Both options are available as part of our support subscription. Please consider subscribing since this way you also fund our present and future open source work...

Thanks

We have seen similar issues with our apps that are using Atomikos and ActiveMQ, although mainly during a failover scenario. I believe it is a bug in ActiveMQ. It appears that Red Hat recently added a fix to the next version of A-MQ (the paid support version):

https://issues.jboss.org/browse/ENTMQ-758

We've recently fixed a similar bug via a workaround in our codebase and can do the same if any issue remains. There is no need to purchase ActiveMQ support for this one.