Transaction boundaries on Spring Integration with ActiveMQ and an a channel backed with an Message Store

Question

I'am working on an application using spring-integration and ActiveMQ to integrate a main server and several "client" applications.

The main goal is to develop and small client with an embedded ActiveMQ broker, the embedded broker is started by this client application in order to receive JMS messages from several third parties applications on the same site. The client application is connected to the server through an JMS connection with a main installation of an ActiveMQ Server(this already exists). I need to provide the client with an off-line capability, it means that if the client is disconnected it should store the messages received from the third clients on the same site and send them when the server is online again. All seems to work right when there is no transactionality involved, but I'am having problems about the transaction boundaries of the channels configured in spring-integration.

The main flow is :

Third Clients on same site -> Our Client on Site Application -> Reformat Message and add information on the messageTranslator -> Store on the remoteChannel -> Send to the Main Server

This is my on Site Client configuration:

The embedded ActiveMQ broker in the client app:

<bean id="broker1" class="org.apache.activemq.xbean.BrokerFactoryBean">
    <property name="config" value="classpath:activemq/activemq.xml" />
    <property name="start" value="true" />
</bean>

The connection Factories; remoteConnectionFactory is the connection to the main server and Queue definitions :

<!-- Local queue definitions  -->
<bean id="localConnectionFactory" class="org.springframework.jms.connection.CachingConnectionFactory">
    <property name="targetConnectionFactory">
        <bean class="org.apache.activemq.ActiveMQConnectionFactory">
            <property name="brokerURL" value="vm://localhost"/>
        </bean>
    </property>
    <property name="sessionCacheSize" value="10"/>
</bean>
<bean id="localEventQueue" class="org.apache.activemq.command.ActiveMQQueue"  >
    <constructor-arg value="event.client"/>
</bean>

<!-- Remote(Server) queue definitions  -->
<bean id="remoteConnectionFactory" class="org.springframework.jms.connection.CachingConnectionFactory">
    <property name="targetConnectionFactory">
        <bean class="org.apache.activemq.ActiveMQConnectionFactory">
            <property name="brokerURL" value="tcp://192.168.0.125:62626"/>
        </bean>
    </property>
    <property name="sessionCacheSize" value="10"/>
</bean>
<bean id="remoteQueue" class="org.apache.activemq.command.ActiveMQQueue">
    <constructor-arg value="remote.event"/>
</bean>

Local Process, on same remote site:

<!-- local process -->
<int:channel id="transformChannel" >
    <int:queue />
</int:channel>

<int-jms:message-driven-channel-adapter
        id="jmsEventsFromClient"
         connection-factory="localConnectionFactory"
         destination="localEventQueue"
         channel="transformChannel"
        concurrent-consumers="4"
        auto-startup="true"/>

<!-- Transforms the message from clients to a standard messages that server knows-->
<int:service-activator input-channel="transformChannel"
                       ref="messageTranslator"
                       output-channel="remoteChannel"  >
    <int:poller  fixed-delay="500">
    </int:poller>
</int:service-activator>


<int:transaction-synchronization-factory id="syncFactory">
    <int:after-commit expression="@store.removeFromIdCache(headers.id.toString())" />
    <int:after-rollback expression="@store.removeFromIdCache(headers.id.toString())"/>
</int:transaction-synchronization-factory>

<int:channel id="remoteChannel" >
     <int:queue message-store="store" />
</int:channel>

<!-- local file database with HSQL store of the remotechannel -->
<bean id="store" class="org.springframework.integration.jdbc.store.JdbcChannelMessageStore">
    <property name="dataSource" ref="dataSource"/>
    <property name="channelMessageStoreQueryProvider">
        <bean id="queryProvider" class="org.springframework.integration.jdbc.store.channel.HsqlChannelMessageStoreQueryProvider"/>
    </property>
    <property name="usingIdCache" value="true"/>
</bean>

Send to the remote Queue:

<!-- the message is send to the remote server -->
<int-jms:outbound-channel-adapter id="remoteJms"
                                  connection-factory="remoteConnectionFactory"
                                  destination="remoteQueue"
                                  channel="remoteChannel"
                                  session-transacted="true"
                                  auto-startup="true">

    <int:poller  fixed-delay="500">
        <int:transactional propagation="REQUIRED"
                           isolation="DEFAULT"
                           synchronization-factory="syncFactory"
                           transaction-manager="transactionManager"/>
    </int:poller>

</int-jms:outbound-channel-adapter>

When there is not a JTA transaction manager configured and the remoteJms is not session-transacted all works just fine, even when I simulate an offline situation the messages are correctly stored on the store, and when the connection with the server comes alive again (remoteJms) the messages are send them correctly. But when a JTA transaction manager is configured (atomikos) and the ActiveMQ main server goes down the messages are not been stored on the store. I thought as soon as the pooler in remoteJms receive the message it starts a new transaction, but this is not happening, it seams like the whole way from jmsEventsFromClient to the jmsOut looks like a single transaction and is failed because the remoteJms is down.

What I want is to have 2 transactions, the first should started when a message is receive on the eventQueue and finished when the message is leave it in the remoteChannel and the second should start when the message is take it from the remoteChannel and leave it on the remoteJms. Thanks for your comments and help.

EDIT
This is happening only when the remote server is down, and the message is removed from the store, but that is what I don't want.

Add the log error.

2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AbstractDataSourceBean   : AtomikosDataSoureBean 'dataSource': getConnection ( null )...
2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AbstractDataSourceBean   : AtomikosDataSoureBean 'dataSource': init...
2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.a.icatch.imp.CompositeTransactionImp   : addParticipant ( XAResourceTransaction: 7472616E73616374696F6E4D616E6167657230303038303030303430:7472616E73616374696F6E4D616E616765723830 ) for transaction transactionManager0008000040
2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.a.datasource.xa.XAResourceTransaction  : XAResource.start ( 7472616E73616374696F6E4D616E6167657230303038303030303430:7472616E73616374696F6E4D616E616765723830 , XAResource.TMNOFLAGS ) on resource dataSource represented by XAResource instance org.hsqldb.jdbc.pool.JDBCXAResource@55f823a3
2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.a.icatch.imp.CompositeTransactionImp   : registerSynchronization ( com.atomikos.jdbc.AtomikosConnectionProxy$JdbcRequeueSynchronization@c85d8b3 ) for transaction transactionManager0008000040
2015-06-29 16:39:16.859  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AtomikosConnectionProxy  : atomikos connection proxy for org.hsqldb.jdbc.pool.JDBCXAConnectionWrapper@731d1112: calling prepareStatement(SELECT COUNT(MESSAGE_ID) from INT_CHANNEL_MESSAGE where GROUP_KEY=? and REGION=?)...
hi message: una cadena 
2015-06-29 16:39:17.820  INFO 4982 --- [ask-scheduler-9] c.atomikos.jdbc.AbstractDataSourceBean   : AtomikosDataSoureBean 'dataSource': getConnection ( null )...
2015-06-29 16:39:17.820  INFO 4982 --- [ask-scheduler-9] c.atomikos.jdbc.AbstractDataSourceBean   : AtomikosDataSoureBean 'dataSource': init...
2015-06-29 16:39:25.093  WARN 4982 --- [0.1:57663@61616] o.a.a.b.TransportConnection.Transport    : Transport Connection to: tcp://192.168.0.125:57663 failed: java.io.EOFException
2015-06-29 16:39:27.145  WARN 4982 --- [     Atomikos:1] c.a.icatch.imp.ActiveStateHandler        : Timeout/setRollbackOnly of ACTIVE coordinator !
2015-06-29 16:39:47.821  WARN 4982 --- [ask-scheduler-9] com.atomikos.jdbc.AtomikosSQLException   : Connection pool exhausted - try increasing 'maxPoolSize' and/or 'borrowConnectionTimeout' on the DataSourceBean.
2015-06-29 16:39:47.822  INFO 4982 --- [ask-scheduler-4] c.a.icatch.imp.CompositeTransactionImp   : registerSynchronization ( com.atomikos.jdbc.AtomikosConnectionProxy$JdbcRequeueSynchronization@c85d8b3 ) for transaction transactionManager0008000040
2015-06-29 16:39:47.822  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AtomikosConnectionProxy  : atomikos connection proxy for org.hsqldb.jdbc.pool.JDBCXAConnectionWrapper@731d1112: calling prepareStatement(SELECT COUNT(MESSAGE_ID) from INT_CHANNEL_MESSAGE where GROUP_KEY=? and REGION=?)...
2015-06-29 16:39:47.823  INFO 4982 --- [ask-scheduler-4] c.a.icatch.imp.CompositeTransactionImp   : registerSynchronization ( com.atomikos.jdbc.AtomikosConnectionProxy$JdbcRequeueSynchronization@c85d8b3 ) for transaction transactionManager0008000040
2015-06-29 16:39:47.823  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AtomikosConnectionProxy  : atomikos connection proxy for org.hsqldb.jdbc.pool.JDBCXAConnectionWrapper@731d1112: calling prepareStatement(SELECT INT_CHANNEL_MESSAGE.MESSAGE_ID, INT_CHANNEL_MESSAGE.MESSAGE_BYTES from INT_CHANNEL_MESSAGE where INT_CHANNEL_MESSAGE.GROUP_KEY = ? and INT_CHANNEL_MESSAGE.REGION = ? order by CREATED_DATE, MESSAGE_SEQUENCE LIMIT 1)...
2015-06-29 16:39:47.823  INFO 4982 --- [ask-scheduler-4] c.atomikos.jdbc.AtomikosConnectionProxy  : atomikos connection proxy for org.hsqldb.jdbc.pool.JDBCXAConnectionWrapper@731d1112: close()...
2015-06-29 16:39:47.823  INFO 4982 --- [ask-scheduler-4] c.a.datasource.xa.XAResourceTransaction  : XAResource.end ( 7472616E73616374696F6E4D616E6167657230303038303030303430:7472616E73616374696F6E4D616E616765723830 , XAResource.TMSUCCESS ) on resource dataSource represented by XAResource instance org.hsqldb.jdbc.pool.JDBCXAResource@55f823a3
2015-06-29 16:39:47.823  INFO 4982 --- [ask-scheduler-4] c.a.icatch.imp.CompositeTransactionImp   : commit() done (by application) of transaction transactionManager0008000040
2015-06-29 16:39:47.824  INFO 4982 --- [ask-scheduler-4] c.a.datasource.xa.XAResourceTransaction  : XAResource.prepare ( 7472616E73616374696F6E4D616E6167657230303038303030303430:7472616E73616374696F6E4D616E616765723830 ) returning OK on resource dataSource represented by XAResource instance org.hsqldb.jdbc.pool.JDBCXAResource@55f823a3
2015-06-29 16:39:47.824  INFO 4982 --- [ask-scheduler-4] c.a.datasource.xa.XAResourceTransaction  : XAResource.rollback ( 7472616E73616374696F6E4D616E6167657230303038303030303430:7472616E73616374696F6E4D616E616765723830 ) on resource dataSource represented by XAResource instance org.hsqldb.jdbc.pool.JDBCXAResource@55f823a3
2015-06-29 16:39:47.825 ERROR 4982 --- [ask-scheduler-4] o.s.integration.handler.LoggingHandler   : org.springframework.transaction.UnexpectedRollbackException: JTA transaction unexpectedly rolled back (maybe due to a timeout); nested exception is javax.transaction.RollbackException: Prepare: NO vote
    at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1024)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:521)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:291)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy85.call(Unknown Source)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:298)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:52)
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:49)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:292)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: javax.transaction.RollbackException: Prepare: NO vote
    at com.atomikos.icatch.jta.TransactionImp.rethrowAsJtaRollbackException(TransactionImp.java:66)
    at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:206)
    at com.atomikos.icatch.jta.TransactionManagerImp.commit(TransactionManagerImp.java:436)
    at com.atomikos.icatch.jta.UserTransactionManager.commit(UserTransactionManager.java:177)
    at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1021)
    ... 22 more
Caused by: com.atomikos.icatch.RollbackException: Prepare: NO vote
    at com.atomikos.icatch.imp.ActiveStateHandler.prepare(ActiveStateHandler.java:231)
    at com.atomikos.icatch.imp.CoordinatorImp.prepare(CoordinatorImp.java:681)
    at com.atomikos.icatch.imp.CoordinatorImp.terminate(CoordinatorImp.java:970)
    at com.atomikos.icatch.imp.CompositeTerminatorImp.commit(CompositeTerminatorImp.java:82)
    at com.atomikos.icatch.imp.CompositeTransactionImp.commit(CompositeTransactionImp.java:336)
    at com.atomikos.icatch.jta.TransactionImp.commit(TransactionImp.java:190)
    ... 25 more

2015-06-29 16:39:47.825 ERROR 4982 --- [ask-scheduler-9] o.s.integration.handler.LoggingHandler   : org.springframework.messaging.MessageDeliveryException: failed to send Message to channel 'remoteChannel'; nested exception is org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.atomikos.jdbc.AtomikosSQLException: Connection pool exhausted - try increasing 'maxPoolSize' and/or 'borrowConnectionTimeout' on the DataSourceBean.
    at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:292)
    at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:239)
    at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:115)
    at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:45)
    at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:95)
    at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutput(AbstractMessageProducingHandler.java:248)
    at org.springframework.integration.handler.AbstractMessageProducingHandler.produceOutput(AbstractMessageProducingHandler.java:171)
    at org.springframework.integration.handler.AbstractMessageProducingHandler.sendOutputs(AbstractMessageProducingHandler.java:119)
    at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:105)
    at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:78)
    at org.springframework.integration.endpoint.PollingConsumer.handleMessage(PollingConsumer.java:74)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint.doPoll(AbstractPollingEndpoint.java:219)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint.access$000(AbstractPollingEndpoint.java:55)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:149)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call(AbstractPollingEndpoint.java:146)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller$1.run(AbstractPollingEndpoint.java:298)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor$1.run(ErrorHandlingTaskExecutor.java:52)
    at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
    at org.springframework.integration.util.ErrorHandlingTaskExecutor.execute(ErrorHandlingTaskExecutor.java:49)
    at org.springframework.integration.endpoint.AbstractPollingEndpoint$Poller.run(AbstractPollingEndpoint.java:292)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:81)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Could not get JDBC Connection; nested exception is com.atomikos.jdbc.AtomikosSQLException: Connection pool exhausted - try increasing 'maxPoolSize' and/or 'borrowConnectionTimeout' on the DataSourceBean.
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:80)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:630)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:909)
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:970)
    at org.springframework.integration.jdbc.store.JdbcChannelMessageStore.addMessageToGroup(JdbcChannelMessageStore.java:422)
    at org.springframework.integration.store.MessageGroupQueue.doOffer(MessageGroupQueue.java:329)
    at org.springframework.integration.store.MessageGroupQueue.put(MessageGroupQueue.java:274)
    at org.springframework.integration.store.MessageGroupQueue.put(MessageGroupQueue.java:48)
    at org.springframework.integration.channel.QueueChannel.doSend(QueueChannel.java:92)
    at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:277)
    ... 28 more
Caused by: com.atomikos.jdbc.AtomikosSQLException: Connection pool exhausted - try increasing 'maxPoolSize' and/or 'borrowConnectionTimeout' on the DataSourceBean.
    at com.atomikos.jdbc.AtomikosSQLException.throwAtomikosSQLException(AtomikosSQLException.java:46)
    at com.atomikos.jdbc.AbstractDataSourceBean.throwAtomikosSQLException(AbstractDataSourceBean.java:90)
    at com.atomikos.jdbc.AbstractDataSourceBean.throwAtomikosSQLException(AbstractDataSourceBean.java:85)
    at com.atomikos.jdbc.AbstractDataSourceBean.getConnection(AbstractDataSourceBean.java:347)
    at com.atomikos.jdbc.AbstractDataSourceBean.getConnection(AbstractDataSourceBean.java:394)
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
    ... 37 more

Turn on trace logging to view the transaction semantics; the inbound and outbound processes should be running in entirely separate transactions. Off the top of my head, I don't see how atomikos could combine both legs into a single transaction. — Gary Russell, Jun 29 '15 at 18:49
Thank you! there are a lot of log messages, I'm trying to configure the log to isolate the important messages. — dgofactory, Jun 29 '15 at 19:43
Puff I haven't solved the problem. If I increase the size of the pool for the `datasource` the same exceptions is happening, it just takes long to appear (after it has consumed all the connections `spring.datasource.max-active=100`). I think the pooler is executing a consumer every `fixed-delay` and the exception is launched after there are no more connections. Maybe I need to use a different type of consumer or I'am misunderstanding some concept. — dgofactory, Jun 30 '15 at 23:52

score 0 · Accepted Answer · answered Jul 01 '15 at 19:11

0

I think I figured it out - try setting receive-timeout="0" on the poller that's pulling from the store-backed QueueChannel.

answered Jul 01 '15 at 19:11

Gary Russell

166,535
14
146
179

Thanks so much @Gary Russell for your help, now it's working as I want. – dgofactory Jul 02 '15 at 15:25

Transaction boundaries on Spring Integration with ActiveMQ and an a channel backed with an Message Store

1 Answers1