Atomikos Forum

hi all,

i'm trying hibernate + spring + jms with atomikos, following http://www.atomikos.com/Documentation/SpringIntegration and get this error when try to do rollback:

13:19:13,409 INFO  [SingleConnectionFactory] Established shared JMS Connection: ActiveMQConnection {id=ID:tayler-20506-1254755948051-0:1,clientId=null,started=false}
13:19:13,417 INFO  [atomikos] atomikos connection proxy for resource amq1: creating XA-capable session...
13:19:13,447 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling toString on JMS driver session...
13:19:13,447 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling toString on JMS driver session...
13:19:13,448 DEBUG [JmsTemplate] Executing callback on JMS Session: ActiveMQSession {id=ID:tayler-20506-1254755948051-0:1:2,started=false}
13:19:13,448 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling createQueue on JMS driver session...
13:19:13,480 INFO  [atomikos] atomikos xa session proxy for resource amq1: closing session atomikos xa session proxy for resource amq1 - is terminated ? true
13:19:13,480 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling close on JMS driver session...
13:19:13,501 DEBUG [DefaultListableBeanFactory] Returning cached instance of singleton bean 'org.springframework.transaction.interceptor.TransactionAttributeSourceAdvisor'
13:19:13,504 DEBUG [ClassPathXmlApplicationContext] Publishing event in context [org.springframework.context.support.ClassPathXmlApplicationContext@15f5897]: org.springframework.context.event.ContextRefreshedEvent[source=org.springframework.context.support.ClassPathXmlApplicationContext@15f5897: display name [org.springframework.context.support.ClassPathXmlApplicationContext@15f5897]; startup date [Mon Oct 05 13:19:03 ARST 2009]; root of context hierarchy]
13:19:13,505 DEBUG [JtaTransactionManager] Using transaction object [org.springframework.transaction.jta.JtaTransactionObject@fa706d]
13:19:13,508 DEBUG [JtaTransactionManager] Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
13:19:13,508 WARN  [atomikos] Attempt to create a transaction with a timeout that exceeds com.atomikos.icatch.max_timeout - truncating to: 300000
13:19:13,560 INFO  [atomikos] createCompositeTransaction ( 3000000 ): created new ROOT transaction with id 127.0.0.1.tm0000100044
13:19:13,568 DEBUG [TransactionSynchronizationManager] Initializing transaction synchronization
13:19:13,573 INFO  [atomikos] atomikos connection proxy for resource amq1: creating XA-capable session...
13:19:13,576 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling toString on JMS driver session...
13:19:13,576 INFO  [atomikos] atomikos connection proxy for resource amq1: calling start on JMS driver...
13:19:13,579 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.jms.connection.JmsResourceHolder@3a5a9c] for key [org.springframework.jms.connection.SingleConnectionFactory@514f7f] to thread [DefaultMessageListenerContainer-1]
13:19:13,579 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling createConsumer on JMS driver session ActiveMQSession {id=ID:tayler-20506-1254755948051-0:1:4,started=true}
13:19:13,655 INFO  [atomikos] atomikos MessageConsumer proxy for ActiveMQMessageConsumer { value=ID:tayler-20506-1254755948051-0:1:4:1, started=true }: receive ( 1000 )...
13:19:13,656 INFO  [atomikos] atomikos MessageConsumer proxy for ActiveMQMessageConsumer { value=ID:tayler-20506-1254755948051-0:1:4:1, started=true }: receive ( 1000 , null )...
13:19:13,666 INFO  [atomikos] addParticipant ( XAResourceTransaction: 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D31 ) for transaction 127.0.0.1.tm0000100044
13:19:13,666 INFO  [atomikos] XAResource.start ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D31 , XAResource.TMNOFLAGS ) on resource amq1 represented by XAResource instance org.apache.activemq.TransactionContext@a4edc4
13:19:13,677 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling toString on JMS driver session...
13:19:13,677 DEBUG [DefaultMessageListenerContainer] Received message of type [class org.apache.activemq.command.ActiveMQTextMessage] from consumer [atomikos MessageConsumer proxy for ActiveMQMessageConsumer { value=ID:tayler-20506-1254755948051-0:1:4:1, started=true }] of transactional session [ActiveMQSession {id=ID:tayler-20506-1254755948051-0:1:4,started=true}]
13:19:13,992 DEBUG [JtaTransactionManager] Using transaction object [org.springframework.transaction.jta.JtaTransactionObject@a2ba05]
13:19:13,993 DEBUG [JtaTransactionManager] Participating in existing transaction
13:19:13,993 DEBUG [TransactionInterceptor] Getting transaction for [be.util.IMsgProcessor.test]
13:19:14,010 DEBUG [SessionFactoryUtils] Opening Hibernate Session
13:19:14,069 DEBUG [SessionFactoryUtils] Registering Spring transaction synchronization for new Hibernate Session
13:19:14,073 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.orm.hibernate3.SessionHolder@1f528ab] for key [org.hibernate.impl.SessionFactoryImpl@40f7a8] to thread [DefaultMessageListenerContainer-1]
13:19:14,078 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1f528ab] for key [org.hibernate.impl.SessionFactoryImpl@40f7a8] bound to thread [DefaultMessageListenerContainer-1]
13:19:14,078 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1f528ab] for key [org.hibernate.impl.SessionFactoryImpl@40f7a8] bound to thread [DefaultMessageListenerContainer-1]
13:19:14,078 DEBUG [HibernateTemplate] Found thread-bound Session for HibernateTemplate
13:19:14,300 INFO  [atomikos] AtomikosDataSoureBean 'dataSource': getConnection ( null )...
13:19:14,300 INFO  [atomikos] AtomikosDataSoureBean 'dataSource': init...
13:19:14,301 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: calling toString...
13:19:14,301 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: calling toString...
Hibernate: insert into text (name) values (?)
13:19:14,304 INFO  [atomikos] addParticipant ( XAResourceTransaction: 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D32 ) for transaction 127.0.0.1.tm0000100044
13:19:14,304 INFO  [atomikos] XAResource.start ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D32 , XAResource.TMNOFLAGS ) on resource dataSource represented by XAResource instance com.mysql.jdbc.jdbc2.optional.MysqlXAConnection@779959
13:19:14,307 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: calling prepareStatement...
13:19:14,331 DEBUG [HibernateTemplate] Not closing pre-bound Hibernate Session after HibernateTemplate
13:19:14,332 DEBUG [TransactionInterceptor] Completing transaction for [be.util.IMsgProcessor.test] after exception: java.lang.RuntimeException
13:19:14,332 DEBUG [RuleBasedTransactionAttribute] Applying rules to determine whether transaction should rollback on java.lang.RuntimeException
13:19:14,332 DEBUG [RuleBasedTransactionAttribute] Winning rollback rule is: null
13:19:14,332 DEBUG [RuleBasedTransactionAttribute] No relevant rollback rule found: applying superclass default
13:19:14,332 DEBUG [JtaTransactionManager] Participating transaction failed - marking existing transaction as rollback-only
13:19:14,332 DEBUG [JtaTransactionManager] Setting JTA transaction rollback-only
13:19:14,334 INFO  [atomikos] setRollbackOnly() called for transaction 127.0.0.1.tm0000100044
13:19:14,335 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling getTransacted on JMS driver session...
13:19:14,335 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.jms.connection.JmsResourceHolder@3a5a9c] for key [org.springframework.jms.connection.SingleConnectionFactory@514f7f] bound to thread [DefaultMessageListenerContainer-1]
13:19:14,336 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling equals on JMS driver session...
13:19:14,337 INFO  [atomikos] atomikos xa session proxy for resource amq1: Calling commit/rollback is not allowed on a managed session!
13:19:14,337 INFO  [atomikos] atomikos MessageConsumer proxy for ActiveMQMessageConsumer { value=ID:tayler-20506-1254755948051-0:1:4:1, started=true }: close...
13:19:14,337 DEBUG [JtaTransactionManager] Triggering beforeCommit synchronization
13:19:14,339 DEBUG [SessionFactoryUtils] Flushing Hibernate Session on transaction synchronization
13:19:14,344 DEBUG [JtaTransactionManager] Triggering beforeCompletion synchronization
13:19:14,345 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.orm.hibernate3.SessionHolder@1f528ab] for key [org.hibernate.impl.SessionFactoryImpl@40f7a8] from thread [DefaultMessageListenerContainer-1]
13:19:14,345 DEBUG [SessionFactoryUtils] Closing Hibernate Session
13:19:14,345 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: isClosed()...
13:19:14,347 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: calling getWarnings...
13:19:14,347 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: calling clearWarnings...
13:19:14,347 INFO  [atomikos] atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.ConnectionWrapper@1dec1dd: close()...
13:19:14,348 INFO  [atomikos] XAResource.end ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D32 , XAResource.TMSUCCESS ) on resource dataSource represented by XAResource instance com.mysql.jdbc.jdbc2.optional.MysqlXAConnection@779959
13:19:14,352 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.jms.connection.JmsResourceHolder@3a5a9c] for key [org.springframework.jms.connection.SingleConnectionFactory@514f7f] from thread [DefaultMessageListenerContainer-1]
13:19:14,352 DEBUG [JtaTransactionManager] Initiating transaction commit
13:19:14,371 INFO  [atomikos] XAResource.end ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D31 , XAResource.TMSUCCESS ) on resource amq1 represented by XAResource instance org.apache.activemq.TransactionContext@a4edc4
13:19:14,374 INFO  [atomikos] XAResource.rollback ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D31 ) on resource amq1 represented by XAResource instance org.apache.activemq.TransactionContext@a4edc4
13:19:14,381 INFO  [atomikos] XAResource.rollback ( 3132372E302E302E312E746D30303030313030303434:3132372E302E302E312E746D32 ) on resource dataSource represented by XAResource instance com.mysql.jdbc.jdbc2.optional.MysqlXAConnection@779959
13:19:14,389 INFO  [atomikos] afterCompletion ( STATUS_ROLLEDBACK ) called  on Synchronization: org.hibernate.transaction.CacheSynchronization
13:19:14,390 DEBUG [JtaTransactionManager] Triggering afterCompletion synchronization
13:19:14,391 INFO  [atomikos] atomikos xa session proxy for resource amq1: closing session atomikos xa session proxy for resource amq1 - is terminated ? true
13:19:14,392 INFO  [atomikos] atomikos xa session proxy for resource amq1: calling close on JMS driver session...
13:19:14,393 DEBUG [TransactionSynchronizationManager] Clearing transaction synchronization
13:19:19,397 ERROR [DefaultMessageListenerContainer] Setup of JMS message listener invoker failed - trying to recover
org.springframework.transaction.UnexpectedRollbackException: JTA transaction unexpectedly rolled back (maybe due to a timeout); nested exception is javax.transaction.RollbackException: Transaction set to rollback only
Caused by:
javax.transaction.RollbackException: Transaction set to rollback only
    at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:311)
    at com.atomikos.icatch.jta.TransactionManagerImp.commit(TransactionManagerImp.java:608)
    at com.atomikos.icatch.jta.UserTransactionImp.commit(UserTransactionImp.java:168)
    at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:842)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:662)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:632)
    at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:248)
    at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:870)
    at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:810)
    at java.lang.Thread.run(Thread.java:619)

i would appreciate any help about this log, i can't see what it is wrong

thx
javier

Hi,

Did you try increasing the transaction timeout?

Guy

i've changed com.atomikos.icatch.default_jta_timeout and same problem.

what about "Attempt to create a transaction with a timeout that exceeds com.atomikos.icatch.max_timeout - truncating to"?

Hi,

com.atomikos.icatch.max_timeout has to be at least as large as you want the timeout to be...

HTH

thanks for reply

that timeout is fixed, but i think the problem is when it is doing "calling close on JMS driver session..."
what timeout or option do i need to check or modify?