Atomikos Forum

Hello,

we are using Atomkos with oracle and OpemMQ jms broker.
While generally everything work fine, we are sometimes annoyed by recurring messages in the logs:

10:23:17,193  INFO atomikos:85 - createCompositeTransaction ( 300000 ): created new ROOT transaction with id atomikos-account-transfer0000100015
10:23:21,873  INFO atomikos:85 - XAResource.commit ( 61746F6D696B6F732D6163636F756E742D7472616E7366657230303030313030303133:61746F6D696B6F732D6163636F756E742D7472616E7366657232 , false ) on resource openmqXaConnectionFactory_00 represented by XAResource instance com.sun.messaging.jmq.jmsclient.XAResourceImpl@646d6aa0
com.sun.messaging.jms.JMSException: [COMMIT_TRANSACTION_REPLY(47)] [C4036]: A broker error occurred. :[404] Unknown transaction 4763450433647558912 user=admin, broker=localhost:7676(33730)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.throwServerErrorException(ProtocolHandler.java:3982)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.commit(ProtocolHandler.java:3501)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.commit(ProtocolHandler.java:3428)
    at com.sun.messaging.jmq.jmsclient.XAResourceImpl.commit(XAResourceImpl.java:179)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:999)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:94)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:86)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:62)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:41)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:139)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:1070)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:88)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:75)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
10:23:21,889  WARN atomikos:82 - XA resource 'openmqXaConnectionFactory_00': commit for XID '61746F6D696B6F732D6163636F756E742D7472616E7366657230303030313030303133:61746F6D696B6F732D6163636F756E742D7472616E7366657232' raised -7: the XA resource has become unavailable
javax.transaction.xa.XAException
    at com.sun.messaging.jmq.jmsclient.XAResourceImpl.commit(XAResourceImpl.java:211)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:999)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:94)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:86)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:62)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:41)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:139)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:1070)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:88)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:75)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
Caused by: com.sun.messaging.jms.JMSException: [COMMIT_TRANSACTION_REPLY(47)] [C4036]: A broker error occurred. :[404] Unknown transaction 4763450433647558912 user=admin, broker=localhost:7676(33730)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.throwServerErrorException(ProtocolHandler.java:3982)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.commit(ProtocolHandler.java:3501)
    at com.sun.messaging.jmq.jmsclient.ProtocolHandler.commit(ProtocolHandler.java:3428)
    at com.sun.messaging.jmq.jmsclient.XAResourceImpl.commit(XAResourceImpl.java:179)
    ... 12 more
10:23:21,890  WARN atomikos:82 - Unexpected error in commit
com.atomikos.icatch.SysException: XA resource 'openmqXaConnectionFactory_00': commit for XID '61746F6D696B6F732D6163636F756E742D7472616E7366657230303030313030303133:61746F6D696B6F732D6163636F756E742D7472616E7366657232' raised -7: the XA resource has become unavailable
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:1039)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:94)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:86)
    at com.atomikos.icatch.imp.Propagator$PropagatorThread.run(Propagator.java:62)
    at com.atomikos.icatch.imp.Propagator.submitPropagationMessage(Propagator.java:41)
    at com.atomikos.icatch.imp.HeurHazardStateHandler.onTimeout(HeurHazardStateHandler.java:139)
    at com.atomikos.icatch.imp.CoordinatorImp.alarm(CoordinatorImp.java:1070)
    at com.atomikos.timing.PooledAlarmTimer.notifyListeners(PooledAlarmTimer.java:88)
    at com.atomikos.timing.PooledAlarmTimer.run(PooledAlarmTimer.java:75)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:619)
10:23:31,891  WARN atomikos:82 - openmqXaConnectionFactory_00: resource no longer available - recovery might be at risk!
10:23:31,892  WARN atomikos:82 - openmqXaConnectionFactory_00: resource no longer available - recovery might be at risk!
10:23:31,892  WARN atomikos:82 - XA resource 'openmqXaConnectionFactory_00': commit for XID '61746F6D696B6F732D6163636F756E742D7472616E7366657230303030313030303133:61746F6D696B6F732D6163636F756E742D7472616E7366657232' raised -7: the XA resource has become unavailable
javax.transaction.xa.XAException: openmqXaConnectionFactory_00: resource no longer available - recovery might be at risk!
    at com.atomikos.datasource.xa.XAResourceTransaction.throwXAExceptionForUnavailableResource(XAResourceTransaction.java:515)
    at com.atomikos.datasource.xa.XAResourceTransaction.testOrRefreshXAResourceFor2PC(XAResourceTransaction.java:487)
    at com.atomikos.datasource.xa.XAResourceTransaction.commit(XAResourceTransaction.java:994)
    at com.atomikos.icatch.imp.CommitMessage.send(CommitMessage.java:94)
    at com.atomikos.icatch.imp.PropagationMessage.submit(PropagationMessage.java:86)


This message appears sometimes in the logs in a loop.
A stop/restart of the application does not prevent it to reappear. Only deleting the tmlog file will, but then we fear leaving the system in an inconsistent state.

Investigating this issue more closely, I noticed that it happens after a crash, and both transactions are committed successfully; still, the warning loops in the logs.

1. It this normal?
2. How can we know when we can safely drop the tmlog file when this happens?

Thanks in advance for any insight on this.

No, this is not normal. The commits are failing... What backend are you using, and does it support XA?

We are using openMQ 4.3.0 as JMS broker and oracle 10 with driver OCI 11.2.0.2.0. Both are configured with XA:

ds.setXaDataSourceClassName("oracle.jdbc.xa.client.OracleXADataSource");

and
connectionFactory = beanFromJndi(connectionFactoryJndiName, XAConnectionFactory.class, jndiTemplate());        

atomikosConnectionFactoryBean.setXaConnectionFactory(connectionFactory);

as stated in the docs.
The commits work; I can follow in the debugger the 2pc being executed (first oracle, the openMQ in our application) and the messages are sent and the DB updated as they should after prepare/commit on the two XAResources.

The only problem (?) is the message recurring in the logs after the recovery.