Atomikos Forum

I think the problem is similar to this topic default82df.html?community.6.1184.6

I'm usuing SonicMQ 8.0 and Transaction Essentials 3.7.0.

MessageDrivenContainer generates the onMessage event but it will not acknowledge the mq server properly. After restarting the application messages will be redelivered. I don't use spring and this is the code adapted from the jms examples:

public class Main
    implements MessageListener
{
  public static void main(String[] args)
      throws Exception
  {
    XAQueueConnectionFactory xaQueueConnectionFactory = new progress.message.jclient.xa.XAQueueConnectionFactory("tcp://localhost:2506");
    ((progress.message.jclient.xa.XAQueueConnectionFactory) xaQueueConnectionFactory).setDefaultUser("user");
    ((progress.message.jclient.xa.XAQueueConnectionFactory) xaQueueConnectionFactory).setDefaultPassword("user");

    AtomikosConnectionFactoryBean factory = new AtomikosConnectionFactoryBean();
    factory.setXaConnectionFactory(xaQueueConnectionFactory);
    factory.setUniqueResourceName("SonicMQ");

    final MessageDrivenContainer mdc = new MessageDrivenContainer();
    mdc.setPoolSize(1);
    mdc.setClientID("client");
    mdc.setTransactionTimeout(10000);
    mdc.setNotifyListenerOnClose(true);
    mdc.setDestinationName("queue");
    mdc.setAtomikosConnectionFactoryBean(factory);
    mdc.setMessageListener(new Main());

    mdc.start();
  }

  @Override
  public void onMessage(Message message)
  {
    try
    {
      System.out.println("Got message: " + message + ", id: " + message.getJMSMessageID());
    }
    catch(JMSException e)
    {
      e.printStackTrace();
    }
  }
}

Properties:

266 [main] INFO atomikos - USING core version: 3.7.0
266 [main] INFO atomikos - USING com.atomikos.icatch.console_file_name = tm.out
266 [main] INFO atomikos - USING com.atomikos.icatch.console_file_count = 1
266 [main] INFO atomikos - USING com.atomikos.icatch.automatic_resource_registration = true
266 [main] INFO atomikos - USING com.atomikos.icatch.client_demarcation = false
266 [main] INFO atomikos - USING com.atomikos.icatch.threaded_2pc = false
266 [main] INFO atomikos - USING com.atomikos.icatch.serial_jta_transactions = true
266 [main] INFO atomikos - USING com.atomikos.icatch.log_base_dir = C:\xa_log_store
266 [main] INFO atomikos - USING com.atomikos.icatch.console_log_level = DEBUG
266 [main] INFO atomikos - USING com.atomikos.icatch.max_actives = 50
266 [main] INFO atomikos - USING com.atomikos.icatch.checkpoint_interval = 500
266 [main] INFO atomikos - USING com.atomikos.icatch.enable_logging = true
266 [main] INFO atomikos - USING com.atomikos.icatch.output_dir = C:\xa_log_store\logs
266 [main] INFO atomikos - USING com.atomikos.icatch.log_base_name = tmlog
266 [main] INFO atomikos - USING com.atomikos.icatch.console_file_limit = -1
282 [main] INFO atomikos - USING com.atomikos.icatch.max_timeout = 300000
282 [main] INFO atomikos - USING com.atomikos.icatch.tm_unique_name = 10.10.10.10.tm
282 [main] INFO atomikos - USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory
282 [main] INFO atomikos - USING java.naming.provider.url = rmi://localhost:1099
282 [main] INFO atomikos - USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory
282 [main] INFO atomikos - USING com.atomikos.icatch.force_shutdown_on_vm_exit = false
282 [main] INFO atomikos - USING com.atomikos.icatch.default_jta_timeout = 20000

Logs:

1094 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: ACTIVE
1094 [Thread-1] INFO atomikos - registerSynchronization ( com.atomikos.jms.ConsumerProducerSupport$JmsRequeueSynchronization@d9ef8c59 ) for transaction 10.10.10.10.tm0000100210
1094 [Thread-1] DEBUG atomikos - a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@d9ef8c59
1094 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: ACTIVE
1094 [Thread-1] INFO atomikos - addParticipant ( XAResourceTransaction: 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31 ) for transaction 10.10.10.10.tm0000100210
1094 [Thread-1] DEBUG atomikos - XAResourceTransaction: 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31: about to switch to XAResource
1094 [Thread-1] DEBUG atomikos - XAResourceTransaction 10.10.10.10.tm000010021010.10.10.10.tm1: switched to XAResource
1094 [Thread-1] INFO atomikos - XAResource.start ( 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31 , XAResource.TMNOFLAGS ) on resource SonicMQ represented by XAResource instance
1109 [Thread-1] DEBUG atomikos - a TransactionContext: changing to state com.atomikos.datasource.xa.session.BranchEnlistedStateHandler@b0ce8f
Got message: progress.message.jimpl.TextMessage@669756a, id: ID:ffffffffcbed081a:9290006:132AA65E525
13984 [Thread-1] DEBUG atomikos - atomikos MessageConsumer proxy for progress.message.jimpl.QueueReceiver@1081d2e: receive returning progress.message.jimpl.TextMessage@669756a
13984 [Thread-1] DEBUG atomikos - atomikos MessageConsumer proxy for progress.message.jimpl.QueueReceiver@1081d2e: receive() returning progress.message.jimpl.TextMessage@669756a
13984 [Thread-1] INFO atomikos - MessageConsumerSession: Consuming message: progress.message.jimpl.TextMessage@669756a
13984 [Thread-1] DEBUG atomikos - MessageConsumerSession: Consumed message: progress.message.jimpl.TextMessage@669756a
13984 [Thread-1] DEBUG atomikos - getCompositeTransaction()  returning instance with id 10.10.10.10.tm0000100210
13984 [Thread-1] DEBUG atomikos - getCompositeTransaction()  returning instance with id 10.10.10.10.tm0000100210
13984 [Thread-1] INFO atomikos - commit() done (by application) of transaction 10.10.10.10.tm0000100210
13984 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: PREPARING
14015 [Thread-1] INFO atomikos - XAResource.end ( 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31 , XAResource.TMSUCCESS ) on resource SonicMQ represented by XAResource instance
14062 [Thread-1] DEBUG atomikos - About to call prepare on XAResource instance:
14062 [Thread-1] INFO atomikos - XAResource.prepare ( 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31 ) returning OK on resource SonicMQ represented by XAResource instance
14062 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: IN_DOUBT
14062 [Thread-1] DEBUG atomikos - prepare() of Coordinator  10.10.10.10.tm0000100210 returning YES vote
14062 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: COMMITTING
14124 [Thread-1] INFO atomikos - XAResource.commit ( 31302E3231342E33342E3136382E746D30303030313030323130:31302E3231342E33342E3136382E746D31 , false ) on resource SonicMQ represented by XAResource instance
14202 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 entering state: TERMINATED
14202 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 : stopping timer...
14202 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 : disposing statehandler TERMINATED...
14202 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000100210 : disposed.
14202 [Thread-1] DEBUG atomikos - JmsRequeueSynchronization: detected termination of transaction com.atomikos.icatch.imp.CompositeTransactionImp@d9ef8c59
14202 [Thread-1] DEBUG atomikos - a TransactionContext: changing to state com.atomikos.datasource.xa.session.NotInBranchStateHandler@9e29fb
14218 [Thread-1] DEBUG atomikos - JmsRequeueSynchronization: is in terminated state ? false
14218 [Thread-1] DEBUG atomikos - MessageConsumerSession: JMS listener thread iterating...
14218 [Thread-1] DEBUG atomikos - getCompositeTransaction() returning NULL!
14218 [Thread-1] DEBUG atomikos - getCompositeTransaction() returning NULL!
14218 [Thread-1] WARN atomikos - Attempt to create a transaction with a timeout that exceeds com.atomikos.icatch.max_timeout - truncating to: 300000
14218 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000200210 entering state: ACTIVE
14218 [Thread-1] DEBUG atomikos - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@1d64c37
14218 [Thread-1] DEBUG atomikos - Creating composite transaction: 10.10.10.10.tm0000200210
14218 [Thread-1] INFO atomikos - createCompositeTransaction ( 10000000 ): created new ROOT transaction with id 10.10.10.10.tm0000200210
14218 [Thread-1] INFO atomikos - atomikos MessageConsumer proxy for progress.message.jimpl.QueueReceiver@1081d2e: receive ( 5000000 )...
14218 [Thread-1] INFO atomikos - atomikos MessageConsumer proxy for progress.message.jimpl.QueueReceiver@1081d2e: receive ( 5000000 , null )...
14218 [Thread-1] DEBUG atomikos - getCompositeTransaction()  returning instance with id 10.10.10.10.tm0000200210
14218 [Thread-1] DEBUG atomikos - atomikos MessageConsumer proxy for progress.message.jimpl.QueueReceiver@1081d2e: detected transaction com.atomikos.icatch.imp.CompositeTransactionImp@dba464f8
14234 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000200210 entering state: ACTIVE
14234 [Thread-1] INFO atomikos - registerSynchronization ( com.atomikos.jms.ConsumerProducerSupport$JmsRequeueSynchronization@dba464f8 ) for transaction 10.10.10.10.tm0000200210
14234 [Thread-1] DEBUG atomikos - a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@dba464f8
14234 [Thread-1] DEBUG atomikos - Coordinator 10.10.10.10.tm0000200210 entering state: ACTIVE
14234 [Thread-1] INFO atomikos - addParticipant ( XAResourceTransaction: 31302E3231342E33342E3136382E746D30303030323030323130:31302E3231342E33342E3136382E746D32 ) for transaction 10.10.10.10.tm0000200210
14234 [Thread-1] DEBUG atomikos - XAResourceTransaction: 31302E3231342E33342E3136382E746D30303030323030323130:31302E3231342E33342E3136382E746D32: about to switch to XAResource
14234 [Thread-1] DEBUG atomikos - XAResourceTransaction 10.10.10.10.tm000020021010.10.10.10.tm2: switched to XAResource
14234 [Thread-1] INFO atomikos - XAResource.start ( 31302E3231342E33342E3136382E746D30303030323030323130:31302E3231342E33342E3136382E746D32 , XAResource.TMNOFLAGS ) on resource SonicMQ represented by XAResource instance
14234 [Thread-1] DEBUG atomikos - a TransactionContext: changing to state com.atomikos.datasource.xa.session.BranchEnlistedStateHandler@109fd93

This looks like an issue with SonicMQ that has been fixed in the 3.6 branch (currently only available to support customers).

This explains a lot. I will try it out. Thanks.