Atomikos Forum

MessageDrivenContainer and duirable topic

Hi,
I'm having issues trying to implement a simple MessageDrivenContainer (V 3.5.9) to read messages from a durable subscription. My problem is that its reading the message fine but its not removing the message from the topic after reading. 

I'm using Sonic (V 7.6) as the messaging server. 

I'm able to configure this behavior using Springs DMLC. I'm trying to compare performance of DMLC versus the MessageDriverConatiner.

Any help is much appreciated!

Here is my config:

    <bean id="sonicConnectionFactory" class="progress.message.jclient.xa.XATopicConnectionFactory">
        <property name="brokerURL">
            <value>localhost:2507</value>
        </property>
        <property name="clientID">
            <value>TPI_Outcomes</value>
        </property>
        <property name="defaultUser">
            <value>tom</value>
        </property>
        
    </bean>
    <bean id="atomikosConnectionFactoryBean"
    class="com.atomikos.jms.AtomikosConnectionFactoryBean">

        <property name="uniqueResourceName">
            <value>QUEUE_BROKER</value>
        </property>
        <property name="xaConnectionFactory">
            <ref bean="sonicConnectionFactory" />
        </property>
        <property name="poolSize" value="1" />
    </bean>

    <bean id="destination" class="progress.message.jclient.Topic">
        <constructor-arg>
            <value>tpi.outcomes.tom</value>
        </constructor-arg>
    </bean>

<!-- Configure the session pool for JMS. This will also manage the transactions
for incoming messages. -->
    <bean id="messageDrivenContainer"
    class="com.atomikos.jms.extra.MessageDrivenContainer"
    init-method="start" destroy-method="stop">
        <property name="atomikosConnectionFactoryBean">
            <ref bean="atomikosConnectionFactoryBean"/>
        </property>
        <property name="transactionTimeout">
            <value>120</value>
        </property>
        <property name="user">
            <value>tom</value>
        </property>
        <property name="password">
            <value>tom</value>
        </property>
        <property name="poolSize">
            <value>1</value>
        </property>
        <property name="destination">
            <ref bean="destination"/>
        </property>
        <property name="subscriberName">
            <value>tom</value>
        </property>
        <property name="messageListener">
            <ref bean="listener"/>
        </property>
        <property name="exceptionListener">
            <ref bean="eList"/>
        </property>
<!--    <property name="noLocal"><value>true</value></property> -->

    </bean>


Here is output from the log:

[12-Jan-2010 14:14:14 EST] [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory  - Returning cached instance of singleton bean 'eList'                                                           
[12-Jan-2010 14:14:14 EST] [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory  - Invoking init method  'start' on bean with name 'messageDrivenContainer'                                     
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING core version: 3.5.9                                                                                                                                                 
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_name = tm.out                                                                                                                     
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_count = 1                                                                                                                         
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.automatic_resource_registration = true                                                                                                         
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.client_demarcation = false                                                                                                                     
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.threaded_2pc = true                                                                                                                             
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.serial_jta_transactions = true                                                                                                                 
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_dir = ./                                                                                                                               
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_log_level = WARN                                                                                                                       
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_actives = 50                                                                                                                               
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.checkpoint_interval = 500                                                                                                                       
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.enable_logging = true                                                                                                                           
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.output_dir = ./                                                                                                                                 
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_name = tmlog                                                                                                                           
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_limit = -1                                                                                                                         
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_timeout = 300000                                                                                                                           
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.tm_unique_name = 127.0.0.2.tm                                                                                                                   
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory                                                                                     
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING java.naming.provider.url = rmi://localhost:1099                                                                                                                     
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory                                                                         
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.force_shutdown_on_vm_exit = false                                                                                                               
[12-Jan-2010 14:14:15 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.default_jta_timeout = 10000                                                                                                                     
[12-Jan-2010 14:14:15 EST] [main] DEBUG atomikos  - MessageConsumerSession: started new thread: Thread[Thread-1,5,main]                                                                                                       
[12-Jan-2010 14:14:15 EST] [Thread-1] INFO  atomikos  - MessageConsumerSession: Starting JMS listener thread.                                                                                                                 
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - MessageConsumerSession: JMS listener thread iterating...                                                                                                             
[12-Jan-2010 14:14:15 EST] [main] DEBUG atomikos  - MessageConsumerSession configured with [user=tom, password=tom, transactionTimeout=120, destination=tpi.outcomes.tom, notifyListenerOnClose= false, messageSelector=null, daemonThreads=false, messageListener=com.tom.MsgListenerImpl@49d8c528, exceptionListener=com.tom.EList@3677eaf8, connectionFactory=AtomikosConnectionFactoryBean 'QUEUE_BROKER']                                               
[12-Jan-2010 14:14:15 EST] [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory  - Finished creating instance of bean 'messageDrivenContainer'                                                   
[12-Jan-2010 14:14:15 EST] [Thread-1] WARN  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': createConnection ( user , password ) ignores authentication - returning default connection                             
[12-Jan-2010 14:14:15 EST] [Thread-1] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': createConnection()...                                                                                                   
[12-Jan-2010 14:14:15 EST] [Thread-1] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': init...                                                                                                                 
[12-Jan-2010 14:14:15 EST] [Thread-1] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': getReference()...                                                                                                       
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': getReference() returning Reference Class Name: com.atomikos.jms.AtomikosConnectionFactoryBean                           
Address Type: com.atomikos.serializable                                                                                                                                                                                       
AddressContents: ffffffac ffffffed 0 5 73 72 0 2e 63 6f 6d 2e 61 74 6f 6d 69 6b 6f 73 2e 6a 6d 73 2e 41 74 6f 6d 69 6b 6f  ...                                                                                               
Type: uniqueResourceName                                                                                                                                                                                                     
Content: QUEUE_BROKER                                                                                                                                                                                                         

[12-Jan-2010 14:14:15 EST] [Thread-1] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': initializing with [ xaConnectionFactory=progress.message.jclient.xa.XATopicConnectionFactory@f8622f3, xaConnectionFactoryClassName=null, uniqueResourceName=QUEUE_BROKER, maxPoolSize=1, minPoolSize=1, borrowConnectionTimeout=30, maxIdleTime=60, reapTimeout=0, maintenanceInterval=60, xaProperties=[], localTransactionMode=false]               
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - Configuration: adding resource QUEUE_BROKER                                                                                                                           
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - Installing recovery service on resource QUEUE_BROKER                                                                                                                 
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - QUEUE_BROKER: refreshing XAResource...                                                                                                                               
[12-Jan-2010 14:14:15 EST] [Thread-1] WARN  atomikos  - QUEUE_BROKER: refreshed XAResource                                                                                                                                   
[12-Jan-2010 14:14:15 EST] [Thread-1] DEBUG atomikos  - recovery initiated for resource QUEUE_BROKER with branchIdentifier 127.0.0.2.tm                                                                                       
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - endRecovery() done for resource QUEUE_BROKER                                                                                                                         
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - Configuration: added resource QUEUE_BROKER                                                                                                                           
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection pool 'QUEUE_BROKER': initializing...                                                                                                             
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos pooled connection for resource QUEUE_BROKER: registering listener atomikos connection pool 'QUEUE_BROKER'                                                   
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - TaskManager: initializing...                                                                                                                                         
[12-Jan-2010 14:14:16 EST] [Thread-1] INFO  atomikos  - THREADS: using JDK thread pooling...                                                                                                                                 
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor                                                                           
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@87e9ce2                                                                                                   
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:0                                                                                                                       
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': init done.                                                                                                             
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection pool 'QUEUE_BROKER': pool reached max size: 1                                                                                                     
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection pool 'QUEUE_BROKER': current size: 1/1                                                                                                           
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos pooled connection for resource QUEUE_BROKER: updating last time acquired                                                                                     
[12-Jan-2010 14:14:16 EST] [Thread-1] INFO  atomikos  - atomikos connection proxy for resource QUEUE_BROKER: calling toString on JMS driver...                                                                               
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection proxy for resource QUEUE_BROKER: toString returning progress.message.jimpl.xa.XAConnection@47570945                                               
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos pooled connection for resource QUEUE_BROKER: returning proxy progress.message.jimpl.xa.XAConnection@47570945                                                 
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection pool 'QUEUE_BROKER': got connection from pool, new size: 0/1                                                                                     
[12-Jan-2010 14:14:16 EST] [Thread-1] INFO  atomikos  - atomikos connection proxy for resource QUEUE_BROKER: calling toString on JMS driver...                                                                               
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection proxy for resource QUEUE_BROKER: toString returning progress.message.jimpl.xa.XAConnection@47570945                                               
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': createConnection() returning progress.message.jimpl.xa.XAConnection@47570945                                           
[12-Jan-2010 14:14:16 EST] [Thread-1] INFO  atomikos  - atomikos connection proxy for resource QUEUE_BROKER: calling start on JMS driver...                                                                                   
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - atomikos connection proxy for resource QUEUE_BROKER: start returning null                                                                                             
[12-Jan-2010 14:14:16 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                             
[12-Jan-2010 14:14:16 EST] [Thread-1] INFO  atomikos  - atomikos connection proxy for resource QUEUE_BROKER: creating XA-capable session...                                                                                   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - a SessionHandleState with 0 context(s): notifySessionBorrowed                                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - a TransactionContext: changing to state com.atomikos.datasource.xa.session.NotInBranchStateHandler@319da967                                                           
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - atomikos xa session proxy for resource QUEUE_BROKER: calling toString on JMS driver session...                                                                       
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos xa session proxy for resource QUEUE_BROKER: toString returning XASession                                                                                     
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos connection proxy for resource QUEUE_BROKER: returning XASession                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - atomikos xa session proxy for resource QUEUE_BROKER: calling createDurableSubscriber on JMS driver session XASession                                                 
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos xa session proxy for resource QUEUE_BROKER: createDurableSubscriber returning atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c                                                                                                                                                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: ACTIVE                                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@3175ade6                                                                                                   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:1                                                                                                                       
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000100023                                                                                                               
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - createCompositeTransaction ( 120000 ): created new ROOT transaction with id 127.0.0.2.tm0000100023                                                                   
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive ( 60000 )...                                                           
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive ( 60000 , null )...                                                     
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100023                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: detected transaction com.atomikos.icatch.imp.CompositeTransactionImp@4e2f2295   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: ACTIVE                                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@4e2f2295                                 
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: ACTIVE                                                                                                             
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - addParticipant ( XAResourceTransaction: 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31 ) for transaction 127.0.0.2.tm0000100023             
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - XAResourceTransaction: 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31: about to switch to XAResource                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - XAResourceTransaction 127.0.0.2.tm0000100023127.0.0.2.tm1: switched to XAResource                                                                                     
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - XAResource.start ( 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31 , XAResource.TMNOFLAGS ) on resource QUEUE_BROKER represented by XAResource instance                                                                                                                                                                                                                     
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - a TransactionContext: changing to state com.atomikos.datasource.xa.session.BranchEnlistedStateHandler@743fbbfc                                                       
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive returning progress.message.jimpl.TextMessage@548997d1                   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive() returning progress.message.jimpl.TextMessage@548997d1                 
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - MessageConsumerSession: Consuming message: progress.message.jimpl.TextMessage@548997d1                                                                               
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - MessageConsumerSession: Consumed message: progress.message.jimpl.TextMessage@548997d1                                                                                 
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100023                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100023                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] INFO  atomikos  - commit() done (by application) of transaction 127.0.0.2.tm0000100023                                                                                                 
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: PREPARING                                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@1b5b8520                                                                                   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:2                                                                                                                       
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@6c913dc1                                                                                   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:3                                                                                                                       
[12-Jan-2010 14:14:17 EST] [Atomikos:3] INFO  atomikos  - XAResource.end ( 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31 , XAResource.TMSUCCESS ) on resource QUEUE_BROKER represented by XAResource instance                                                                                                                                                                                                                     
[12-Jan-2010 14:14:17 EST] [Atomikos:3] DEBUG atomikos  - About to call prepare on XAResource instance:                                                                                                                       
[12-Jan-2010 14:14:17 EST] [Atomikos:3] INFO  atomikos  - XAResource.prepare ( 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31 ) returning OK on resource QUEUE_BROKER represented by XAResource instance                                                                                                                                                                                                                           
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: IN_DOUBT                                                                                                           
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: COMMITTING                                                                                                         
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.icatch.imp.Propagator$PropagatorThread@16edbe39                                                                                   
[12-Jan-2010 14:14:17 EST] [Atomikos:3] INFO  atomikos  - XAResource.commit ( 3132372E302E302E322E746D30303030313030303233:3132372E302E302E322E746D31 , false ) on resource QUEUE_BROKER represented by XAResource instance   
[12-Jan-2010 14:14:17 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 entering state: TERMINATED                                                                                                         
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 : stopping timer...                                                                                                               
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 : disposing statehandler TERMINATED...                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100023 : disposed.                                                                                                                       
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - JmsRequeueSynchronization: detected termination of transaction com.atomikos.icatch.imp.CompositeTransactionImp@4e2f2295                                               
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - a TransactionContext: changing to state com.atomikos.datasource.xa.session.NotInBranchStateHandler@9931579                                                           
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - JmsRequeueSynchronization: is in terminated state ? false                                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - MessageConsumerSession: JMS listener thread iterating...                                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000200023 entering state: ACTIVE                                                                                                             
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@1766bfd8                                                                                                   
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000200023                                                                                                               
[12-Jan-2010 14:14:18 EST] [Thread-1] INFO  atomikos  - createCompositeTransaction ( 120000 ): created new ROOT transaction with id 127.0.0.2.tm0000200023                                                                   
[12-Jan-2010 14:14:18 EST] [Thread-1] INFO  atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive ( 60000 )...                                                           
[12-Jan-2010 14:14:18 EST] [Thread-1] INFO  atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: receive ( 60000 , null )...                                                     
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000200023                                                                                         
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - atomikos TopicSubscriber proxy for progress.message.jimpl.DurableSubscriber@7d15d06c: detected transaction com.atomikos.icatch.imp.CompositeTransactionImp@30d58ce2   
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000200023 entering state: ACTIVE
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@30d58ce2
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000200023 entering state: ACTIVE
[12-Jan-2010 14:14:18 EST] [Thread-1] INFO  atomikos  - addParticipant ( XAResourceTransaction: 3132372E302E302E322E746D30303030323030303233:3132372E302E302E322E746D32 ) for transaction 127.0.0.2.tm0000200023
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - XAResourceTransaction: 3132372E302E302E322E746D30303030323030303233:3132372E302E302E322E746D32: about to switch to XAResource
[12-Jan-2010 14:14:18 EST] [Thread-1] DEBUG atomikos  - XAResourceTransaction 127.0.0.2.tm0000200023127.0.0.2.tm2: switched to XAResource
[12-Jan-2010 14:14:18 EST] [Thread-1] INFO  atomikos  - XAResource.start ( 3132372E302E302E322E746D30303030323030303233:3132372E302E302E322E746D32 , XAResource.TMNOFLAGS ) on resource QUEUE_BROKER represented by XAResource i
Tom Duerr Send private email
Tuesday, January 12, 2010
 
 
The log looks fine to me.

What does the log say for spring DMLC?
Guy Pardon Send private email
Wednesday, January 13, 2010
 
 
Hi Guy,


Thanks for the fast response.

I've refactored to use the Spring DMLC with a SingleConnectionFactory and not the Atomikos connection factory. This configuration allows the
message to be consumed from the topic, that is, received and removed.

Interstingly, If I  use the Atomikos connection factory (instead of SingleConnectionFactory)with the Spring DMLC then I have the original problem, then the message is recieved but not removed. Am I maybe missing some configuration option
on the  Atomikos connection factory that is causing this behavior ?


Here is my Spring DMLC configuration (Not using AtomikosConnectionFactoryBean):




<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.console_file_name">tm.out</prop>
            <prop key="com.atomikos.icatch.console_file_limit">524288</prop>
            <prop key="com.atomikos.icatch.console_file_count">1</prop>
        </props>
    </constructor-arg>
</bean>

<bean id="AtomikosUserTransaction" class="com.atomikos.icatch.jta.UserTransactionImp"
          depends-on="userTransactionService">
    <property name="transactionTimeout" value="30" />
</bean>

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


<bean id="transactionManager"
        class="org.springframework.transaction.jta.JtaTransactionManager"
        depends-on="userTransactionService">
    <property name="transactionManager" ref="AtomikosTransactionManager" />
    <property name="userTransaction" ref="AtomikosUserTransaction" />
</bean>


<bean id="sonicConnectionFactory" class="progress.message.jclient.xa.XATopicConnectionFactory">
    <property name="brokerURL">
        <value>localhost:2507</value>
    </property>
    <property name="clientID">
        <value>TPI_Outcomes</value>
    </property>
    <property name="defaultUser">
        <value>tom</value>
    </property>
        
</bean>
<bean id="connectionFactory"
    class="com.atomikos.jms.AtomikosConnectionFactoryBean"  init-method="init" >

    <property name="uniqueResourceName">
        <value>QUEUE_BROKER</value>
    </property>
    <property name="xaConnectionFactory">
        <ref bean="sonicConnectionFactory" />
    </property>
    <property name="poolSize" value="1" />
</bean>

<bean id="destination" class="progress.message.jclient.Topic">
    <constructor-arg>
        <value>tpi.outcomes.tom</value>
    </constructor-arg>
</bean>

<bean id="springConnectionFactory" class="org.springframework.jms.connection.SingleConnectionFactory">
    <property name="targetConnectionFactory" ref="sonicConnectionFactory" />
</bean>


<bean id="listenerContainer"
        class="org.springframework.jms.listener.DefaultMessageListenerContainer">
    <property name="connectionFactory" ref="springConnectionFactory" />
    <property name="destination" ref="destination" />
    <property name="messageListener" ref="listener" />
    <property name="pubSubDomain" value="true" />
    <property name="subscriptionDurable" value="true" />
    <property name="concurrentConsumers" value="1" />
    <property name="autoStartup">
        <value>true</value>
    </property>
    <property name="acceptMessagesWhileStopping" value="false" />

    <property name="durableSubscriptionName">
        <value>tom</value>
    </property>
    <property name="transactionManager" ref="transactionManager" />
    <property name="transactionTimeout" value="30" /> <!-- in seconds -->
    <property name="receiveTimeout" value="10000" />  <!-- in milliseconds -->
    <property name="sessionTransacted" value="true" />
        <!-- cacheLevel 3 is CACHE_CONSUMER -->
    <property name="cacheLevel" value="3" />  <!-- need this to make sonic subscription groups work properly -->
</bean>


Here is the log output:


[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING core version: 3.5.9                                                                                                                                                 
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_name = tm.out                                                                                                                     
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_count = 1                                                                                                                         
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.automatic_resource_registration = true                                                                                                         
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.client_demarcation = false                                                                                                                     
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.threaded_2pc = true                                                                                                                             
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.serial_jta_transactions = true                                                                                                                 
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_dir = ./                                                                                                                               
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_log_level = WARN                                                                                                                       
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_actives = 50                                                                                                                               
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.checkpoint_interval = 500                                                                                                                       
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.enable_logging = true                                                                                                                           
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.output_dir = ./                                                                                                                                 
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_name = tmlog                                                                                                                           
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_limit = 524288                                                                                                                     
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_timeout = 300000                                                                                                                           
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.tm_unique_name = 127.0.0.2.tm                                                                                                                   
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory                                                                                     
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING java.naming.provider.url = rmi://localhost:1099                                                                                                                     
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory                                                                         
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.force_shutdown_on_vm_exit = false                                                                                                               
[14-Jan-2010 10:40:31 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.default_jta_timeout = 10000                                                                                                                     
[14-Jan-2010 10:40:32 EST] [main] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': init...                                                                                                                     
[14-Jan-2010 10:40:32 EST] [main] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': getReference()...                                                                                                           
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': getReference() returning Reference Class Name: com.atomikos.jms.AtomikosConnectionFactoryBean                               
Address Type: com.atomikos.serializable                                                                                                                                                                                       
AddressContents: ffffffac ffffffed 0 5 73 72 0 2e 63 6f 6d 2e 61 74 6f 6d 69 6b 6f 73 2e 6a 6d 73 2e 41 74 6f 6d 69 6b 6f  ...                                                                                               
Type: uniqueResourceName                                                                                                                                                                                                     
Content: QUEUE_BROKER                                                                                                                                                                                                         

[14-Jan-2010 10:40:32 EST] [main] INFO  atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': initializing with [ xaConnectionFactory=progress.message.jclient.xa.XATopicConnectionFactory@b554d32, xaConnectionFactoryClas
sName=null, uniqueResourceName=QUEUE_BROKER, maxPoolSize=1, minPoolSize=1, borrowConnectionTimeout=30, maxIdleTime=60, reapTimeout=0, maintenanceInterval=60, xaProperties=[], localTransactionMode=false]                   
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - Configuration: adding resource QUEUE_BROKER                                                                                                                               
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - Installing recovery service on resource QUEUE_BROKER                                                                                                                     
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - QUEUE_BROKER: refreshing XAResource...                                                                                                                                   
[14-Jan-2010 10:40:32 EST] [main] WARN  atomikos  - QUEUE_BROKER: refreshed XAResource                                                                                                                                       
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - recovery initiated for resource QUEUE_BROKER with branchIdentifier 127.0.0.2.tm                                                                                           
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - endRecovery() done for resource QUEUE_BROKER                                                                                                                             
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - Configuration: added resource QUEUE_BROKER                                                                                                                               
[14-Jan-2010 10:40:32 EST] [main] DEBUG atomikos  - atomikos connection pool 'QUEUE_BROKER': initializing...                                                                                                                 
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - atomikos pooled connection for resource QUEUE_BROKER: registering listener atomikos connection pool 'QUEUE_BROKER'                                                       
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - TaskManager: initializing...                                                                                                                                             
[14-Jan-2010 10:40:33 EST] [main] INFO  atomikos  - THREADS: using JDK thread pooling...                                                                                                                                     
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor                                                                               
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@583e97df                                                                                                       
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:0                                                                                                                           
[14-Jan-2010 10:40:33 EST] [main] DEBUG atomikos  - AtomikosConnectionFactoryBean 'QUEUE_BROKER': init done.                                                                                                                 
[14-Jan-2010 10:40:33 EST] [main] INFO  org.springframework.jms.connection.SingleConnectionFactory  - Established shared JMS Connection: progress.message.jimpl.Connection@724eb043                                           
[14-Jan-2010 10:40:33 EST] [main] DEBUG org.springframework.jms.listener.DefaultMessageListenerContainer  - Established shared JMS Connection                                                                                 
[14-Jan-2010 10:40:33 EST] [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory  - Finished creating instance of bean 'listenerContainer'                                                       
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 entering state: ACTIVE                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@2db7ae22                                                                                       
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - ThreadFactory: creating new thread: Atomikos:1                                                                                                             
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000100001                                                                                                     
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] INFO  atomikos  - createCompositeTransaction ( 30000 ): created new ROOT transaction with id 127.0.0.2.tm0000100001                                                         
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG org.springframework.jms.listener.DefaultMessageListenerContainer  - Received message of type [class progress.message.jimpl.TextMessage] from consumer [progress.message.
jimpl.DurableSubscriber@31f9338f] of session []                                                                                                                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000100001                                                                               
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] INFO  atomikos  - commit() done (by application) of transaction 127.0.0.2.tm0000100001                                                                                       
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 entering state: COMMITTING                                                                                             
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 entering state: TERMINATED                                                                                             
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 : stopping timer...                                                                                                     
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 : disposing statehandler TERMINATED...                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 : disposed.                                                                                                             
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000200001 entering state: ACTIVE                                                                                                 
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@7fb6634c                                                                                       
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000200001                                                                                                     
[14-Jan-2010 10:40:34 EST] [listenerContainer-1] INFO  atomikos  - createCompositeTransaction ( 30000 ): created new ROOT transaction with id 127.0.0.2.tm0000200001
Tom Duerr Send private email
Thursday, January 14, 2010
 
 
Sorry, I needed to comment out the definition of the AtomikosConnectionFactory. Looked like it used it because it was defined.

I commented out and here is the new log:

[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING core version: 3.5.9                                                                                                                                                 
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_name = tm.out                                                                                                                     
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_count = 1                                                                                                                         
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.automatic_resource_registration = true                                                                                                         
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.client_demarcation = false                                                                                                                     
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.threaded_2pc = true                                                                                                                             
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.serial_jta_transactions = true                                                                                                                 
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_dir = ./                                                                                                                               
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_log_level = WARN                                                                                                                       
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_actives = 50                                                                                                                               
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.checkpoint_interval = 500                                                                                                                       
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.enable_logging = true                                                                                                                           
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.output_dir = ./                                                                                                                                 
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.log_base_name = tmlog                                                                                                                           
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.console_file_limit = 524288                                                                                                                     
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.max_timeout = 300000                                                                                                                           
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.tm_unique_name = 127.0.0.2.tm                                                                                                                   
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING java.naming.factory.initial = com.sun.jndi.rmi.registry.RegistryContextFactory                                                                                     
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING java.naming.provider.url = rmi://localhost:1099                                                                                                                     
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.service = com.atomikos.icatch.standalone.UserTransactionServiceFactory                                                                         
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.force_shutdown_on_vm_exit = false                                                                                                               
[14-Jan-2010 11:06:32 EST] [main] INFO  atomikos  - USING com.atomikos.icatch.default_jta_timeout = 10000                                                                                                                     
[14-Jan-2010 11:06:33 EST] [main] INFO  org.springframework.jms.connection.SingleConnectionFactory  - Established shared JMS Connection: progress.message.jimpl.Connection@2d20dbf3                                           
[14-Jan-2010 11:06:33 EST] [main] DEBUG org.springframework.jms.listener.DefaultMessageListenerContainer  - Established shared JMS Connection                                                                                 
[14-Jan-2010 11:06:33 EST] [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory  - Finished creating instance of bean 'listenerContainer'                                                       
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000100001 entering state: ACTIVE                                                                                                 
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - TaskManager: initializing...                                                                                                                               
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] INFO  atomikos  - THREADS: using JDK thread pooling...                                                                                                                       
[14-Jan-2010 11:06:33 EST] [listenerContainer-1] DEBUG atomikos  - THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000300001 : stopping timer...                                                                                                     
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000300001 : disposing statehandler TERMINATED...                                                                                 
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000300001 : disposed.                                                                                                             
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 entering state: ACTIVE                                                                                                 
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@351daa0e                                                                                       
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000400001                                                                                                     
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] INFO  atomikos  - createCompositeTransaction ( 30000 ): created new ROOT transaction with id 127.0.0.2.tm0000400001                                                         
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG org.springframework.jms.listener.DefaultMessageListenerContainer  - Received message of type [class progress.message.jimpl.TextMessage] from consumer [progress.message.jimpl.DurableSubscriber@1cad157f] of session []                                                                                                                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction()  returning instance with id 127.0.0.2.tm0000400001                                                                               
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] INFO  atomikos  - commit() done (by application) of transaction 127.0.0.2.tm0000400001                                                                                       
[14-Jan-2010 11:07:04 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 entering state: COMMITTING                                                                                             
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 entering state: TERMINATED                                                                                             
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 : stopping timer...                                                                                                     
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 : disposing statehandler TERMINATED...                                                                                 
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000400001 : disposed.                                                                                                             
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - getCompositeTransaction() returning NULL!                                                                                                                 
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Coordinator 127.0.0.2.tm0000500001 entering state: ACTIVE                                                                                                 
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@52234265                                                                                       
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] DEBUG atomikos  - Creating composite transaction: 127.0.0.2.tm0000500001                                                                                                     
[14-Jan-2010 11:07:05 EST] [listenerContainer-1] INFO  atomikos  - createCompositeTransaction ( 30000 ): created new ROOT transaction with id 127.0.0.2.tm0000500001
Tom Duerr Send private email
Thursday, January 14, 2010
 
 
By default Spring tries to commit on the JMS session - even with JTA/XA enabled so I think that explains why it works in the DMLC case.

The logs show a correct JTA/XA use case so this looks like a bug in Sonic IMHO. What version are you using? It might be helpful to ask their support...

Guy
Guy Pardon Send private email
Friday, January 15, 2010
 
 
Thanks Guy.

We're using 7.6. Think its the latest.

I may be wrong but I dont think this is a sonic bug. I can access the same server/topic with Spring and also with a standalone Sonic client. In any event, I'm not sure what to ask Sonic to look at. 

I would really like to do some speed tests with the MessageDrivenContainer.

Do you have any other thoughts on how to further debug ?


Thanks again,

Tom
Tom Duerr Send private email
Friday, January 15, 2010
 
 
It seems you are not using our connection factory but Spring/Sonic's instead. Consequently, the transaction is committing 'empty', no JMS or Atomikos/XA involved.

Best
Guy Pardon Send private email
Monday, January 25, 2010
 
 

This topic is archived. No further replies will be accepted.

Other recent topics Other recent topics