[mule-user] New problems with JMS SingleResource Transaction and AMQ

5 views
Skip to first unread message

John Toohey

unread,
Mar 4, 2007, 5:14:06 PM3/4/07
to us...@mule.codehaus.org
When I use a Grinder script to process 10 messages in the Q, I get the following exception :-

17:03:44,582 INFO  [JmsConnector] Connector org.mule.providers.jms.JmsConnector has been stopped
17:03:44,582 INFO  [JmsConnector] Disconnected: org.mule.providers.jms.JmsConnector@2bf5bf
17:03:44,583 INFO  [JmsConnector] Connector org.mule.providers.jms.JmsConnector has been stopped
Exception in thread "ActiveMQ Transport: tcp://localhost/127.0.0.1:61616" java.lang.ClassCastException: org.apache.activemq.transport.InactivityMonitor$2
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.compareTo(ScheduledThreadPoolExecutor.java:189)
        at edu.emory.mathcs.backport.java.util.PriorityQueue.remove(PriorityQueue.java:507)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.remove(DelayQueue.java:379)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.remove(ScheduledThreadPoolExecutor.java:707)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.remove(ThreadPoolExecutor.java:1582)
        at org.apache.activemq.thread.Scheduler.cancel(Scheduler.java:55)
        at org.apache.activemq.transport.InactivityMonitor.stopMonitorThreads(InactivityMonitor.java:176)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:101)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:150)
        at java.lang.Thread.run(Thread.java:613)

And in the Active MQ logs I see :-

DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-61534-1173045523348-1:9:4' has not been started.
javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-61534-1173045523348-1:9:4' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:230)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:114)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:127)
        at org.apache.activemq.broker.AbstractConnection.processMessage(AbstractConnection.java:433)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:591)
        at org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:237)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:61)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:92)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:67)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:124)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:123)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:88)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
        at java.lang.Thread.run(Thread.java:613)
DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, at: 0:216296
DEBUG JournalMessageStore            - Transacted message remove commit for: ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, at: 0:216296
DEBUG JournalMessageStore            - Journalled transacted message add for: ID:JT-L2.local-61534-1173045523348-1:9:1:10:1, at: 0:216781
DEBUG JournalMessageStore            - Transacted message add commit for: ID:JT-L2.local-61534-1173045523348-1:9:1:10:1, at: 0:216781
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
INFO  PrefetchSubscription           - Could not correlate acknowledgment with dispatched message: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1:9:9, messageCount = 10}
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Invalid acknowledgment: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1:9:9, messageCount = 10}
javax.jms.JMSException: Invalid acknowledgment: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1:9:9, messageCount = 10}
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:185)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:234)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:366)
        at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:177)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:66)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:66)
        at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:79)
        at org.apache.activemq.broker.AbstractConnection.processMessageAck(AbstractConnection.java:441)

My Mule Config looks like this :-

    <mule-descriptor name="TPBroker" implementation="com.parspro.core.services.TPBroker">

      <inbound-router>
<endpoint address="TransactionBroker" transformers="JMSMessageToObject">
  <transaction action="BEGIN_OR_JOIN" factory="org.mule.providers.jms.JmsTransactionFactory"/>
<!--   <transaction action="ALWAYS_BEGIN" factory="org.mule.transaction.XaTransactionFactory"/>-->
</endpoint>
      </inbound-router>

      <outbound-router>

<router className="org.mule.routing.outbound.FilteringOutboundRouter">
  <endpoint address="TransactionProcessor"/>
  <filter expectedType="com.parspro.core.domain.dto.SaleImpl" className="org.mule.routing.filters.PayloadTypeFilter"/>
</router>

<router className="org.mule.routing.outbound.FilteringOutboundRouter">
  <endpoint address="TPRejectedValidBets"/>
  <filter expectedType="com.parspro.core.dto.RejectedValidBet" className="org.mule.routing.filters.PayloadTypeFilter"/>
</router>

      </outbound-router>

    </mule-descriptor>

  <!-- Transacted JMS Connector used for TPs -->
  <connector name="jmsTPConnector" className="org.mule.providers.jms.JmsConnector">
    <properties>
      <property name="specification" value="1.1"/>
      <property name="acknowledgeMode" value="1"/>
      <container-property name="connectionFactory" reference="activeMqConnectionFactory" container="core-spring" />
      <property name="maxRedelivery" value="-1"/>
      <property name="persistentDelivery" value="true"/>

      <map name="serviceOverrides">
<property name="message.receiver" value="org.mule.providers.jms.TransactedSingleResourceJmsMessageReceiver"/>
<property name="transacted.message.receiver" value="org.mule.providers.jms.TransactedSingleResourceJmsMessageReceiver"/>
      </map>

    </properties>

  </connector>


In my UMO, I handle the rollback, commit and number of retries to control the routing of the messages, depending on whether they are processed successfully. In a normal JMS server this kind of thing is easy to do, but I'm having a lot of problems getting it to work correctly with Mule.

Anyone think it could be an AMQ issue?

Mule 1.3.3
AMQ 4.0.2


- JT

Andrew Perepelytsya

unread,
Mar 4, 2007, 10:16:43 PM3/4/07
to us...@mule.codehaus.org
John,

Looks weird indeed. 2 suggestions:
  1. Do try with AMQ 4.1, not 4.0.1
  2. Are you running multiple nodes with AMQ? Try with a single one in case you do.
Andrew

On 3/4/07, John Toohey <j...@parspro.com> wrote:
When I use a Grinder script to process 10 messages in the Q, I get the following exception :-

17:03:44,582 INFO  [JmsConnector] Connector org.mule.providers.jms.JmsConnector has been stopped
17:03:44,582 INFO  [JmsConnector] Disconnected: org.mule.providers.jms.JmsConnector@2bf5bf
17:03:44,583 INFO  [JmsConnector] Connector org.mule.providers.jms.JmsConnector has been stopped
Exception in thread "ActiveMQ Transport: tcp://localhost/127.0.0.1:61616" java.lang.ClassCastException: org.apache.activemq.transport.InactivityMonitor$2
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.compareTo(ScheduledThreadPoolExecutor.java :189)
        at edu.emory.mathcs.backport.java.util.PriorityQueue.remove(PriorityQueue.java:507)
        at edu.emory.mathcs.backport.java.util.concurrent.DelayQueue.remove(DelayQueue.java:379)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.remove(ScheduledThreadPoolExecutor.java:707)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.remove (ThreadPoolExecutor.java:1582)
        at org.apache.activemq.thread.Scheduler.cancel(Scheduler.java:55)
        at org.apache.activemq.transport.InactivityMonitor.stopMonitorThreads(InactivityMonitor.java :176)
        at org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
        at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:101)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:150)
        at java.lang.Thread.run(Thread.java:613)

And in the Active MQ logs I see :-

DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-61534-1173045523348-1:9:4' has not been started.
javax.jms.JMSException: Transaction 'TX:ID: JT-L2.local-61534-1173045523348-1:9:4' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:230)
        at org.apache.activemq.broker.TransactionBroker.send (TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:114)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java :98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:127)
        at org.apache.activemq.broker.AbstractConnection.processMessage(AbstractConnection.java:433)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:591)
        at org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:237)
        at org.apache.activemq.broker.TransportConnection$1.onCommand (TransportConnection.java:61)
        at org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:92)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java :67)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:124)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:123)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:88)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
        at java.lang.Thread.run(Thread.java:613)
DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, at: 0:216296
DEBUG JournalMessageStore            - Transacted message remove commit for: ID: JT-L2.local-61534-1173045523348-1:8:12:1:1, at: 0:216296
DEBUG JournalMessageStore            - Journalled transacted message add for: ID:JT-L2.local-61534-1173045523348-1:9:1:10:1, at: 0:216781
DEBUG JournalMessageStore            - Transacted message add commit for: ID: JT-L2.local-61534-1173045523348-1:9:1:10:1, at: 0:216781
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
INFO  PrefetchSubscription           - Could not correlate acknowledgment with dispatched message: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID: JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1 :9:9, messageCount = 10}
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Invalid acknowledgment: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID: JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1 :9:9, messageCount = 10}
javax.jms.JMSException: Invalid acknowledgment: MessageAck {commandId = 54, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId = null, lastMessageId = ID: JT-L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-61534-1173045523348-1:9:9, messageCount = 10}
        at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge (PrefetchSubscription.java:185)
        at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:234)
        at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java :366)
        at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:177)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:66)
        at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:66)
        at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:79)
        at org.apache.activemq.broker.AbstractConnection.processMessageAck (AbstractConnection.java:441)

John Toohey

unread,
Mar 4, 2007, 10:28:55 PM3/4/07
to us...@mule.codehaus.org
Thanks, am going to try with AMQ 4.1 tonight, but was concerned if the JMS transports in 1.3.3 supported 4.1. I am only using one MQ broker at the moment, and thought I had this fixed, until I ran the Grinder scripts against it. I'll post something as soon as I have something more.


- JT

yolcuabbas

unread,
Mar 5, 2007, 6:41:06 AM3/5/07
to us...@mule.codehaus.org

copy the file "backport-util-concurrent-2.1.jar" to %MULE_HOME%/lib/user!

>> L2.local-61534-1173045523348-1 :9:9, messageCount = 10}
>> javax.jms.JMSException: Invalid acknowledgment: MessageAck
>> {commandId = 54, responseRequired = false, ackType = 2, consumerId
>> = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId =
>> null, lastMessageId = ID: JT-

>> L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://
>> parspro-core.TransactionBroker, transactionId = TX:ID:JT-

--
View this message in context: http://www.nabble.com/New-problems-with-JMS-SingleResource-Transaction-and-AMQ-tf3344261.html#a9309981
Sent from the Mule - User mailing list archive at Nabble.com.


---------------------------------------------------------------------
To unsubscribe from this list please visit:

http://xircles.codehaus.org/manage_email

Andrew Perepelytsya

unread,
Mar 5, 2007, 9:47:41 AM3/5/07
to us...@mule.codehaus.org
The 3.0 version is the preferred one. Moreover it's bundled with Mule 1.4 now.

Andrew

>> ( InactivityMonitor.java :176)
>> parspro-core.TransactionBroker , transactionId = TX:ID:JT-

>> L2.local-61534-1173045523348-1 :9:9, messageCount = 10}
>> javax.jms.JMSException: Invalid acknowledgment: MessageAck
>> {commandId = 54, responseRequired = false, ackType = 2, consumerId
>> = ID:JT-L2.local-61534-1173045523348-1:9:1:1, firstMessageId =
>> null, lastMessageId = ID: JT-
>> L2.local-61534-1173045523348-1:8:12:1:1, destination = queue://
>> parspro-core.TransactionBroker , transactionId = TX:ID:JT-

John Toohey

unread,
Mar 5, 2007, 1:32:08 PM3/5/07
to us...@mule.codehaus.org
Updated AMQ to 4.1, ( added apache-activemq-4.1.0-incubator.jar to the mule/lib/user, this is the bundled AMQ 4.1 jar) and ran test again, sending 10 messages to the Q. Nothing in the Mule logs on the first test, but AMQ has these exceptions :-

DEBUG JournalMessageStore            - Transacted message add commit for: ID:JT-L2.local-57912-1173118836305-1:2:1:3:1, at: 0:32840
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Journalled message remove for: ID:JT-L2.local-60921-1173118872832-1:0:1:1:5, at: 0:35303
DEBUG JournalMessageStore            - Journalled message add for: ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:35640
DEBUG JournalMessageStore            - Journalled message add for: ID:JT-L2.local-57912-1173118836305-1:0:9:1:1, at: 0:37562
DEBUG BetBrokerReplies               - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Journalled transacted message add for: ID:JT-L2.local-57912-1173118836305-1:2:1:5:1, at: 0:38416
DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:40783
DEBUG JournalMessageStore            - Transacted message add commit for: ID:JT-L2.local-57912-1173118836305-1:2:1:5:1, at: 0:38416
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Transacted message remove commit for: ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:40783
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:230)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:136)
        at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:480)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:604)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:284)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:177)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:65)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:133)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
        at java.lang.Thread.run(Thread.java:613)
INFO  PrefetchSubscription           - Could not correlate acknowledgment with dispatched message: MessageAck {commandId = 41, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1:2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:6, messageCount = 4}
DEBUG PrefetchSubscription           - Acknowledgment out of sync (Normally occurs when failover connection reconnects): MessageAck {commandId = 41, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1:2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:6, messageCount = 4}
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:230)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:136)
        at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:480)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:604)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:284)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:177)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:65)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:133)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
        at java.lang.Thread.run(Thread.java:613)
DEBUG JournalMessageStore            - Journalled transacted message add for: ID:JT-L2.local-57912-1173118836305-1:2:1:7:1, at: 0:41268
DEBUG JournalMessageStore            - Transacted message add commit for: ID:JT-L2.local-57912-1173118836305-1:2:1:7:1, at: 0:41268
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
INFO  PrefetchSubscription           - Could not correlate acknowledgment with dispatched message: MessageAck {commandId = 50, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1:2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:8, messageCount = 4}
DEBUG PrefetchSubscription           - Acknowledgment out of sync (Normally occurs when failover connection reconnects): MessageAck {commandId = 50, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1:2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:8, messageCount = 4}
DEBUG AbstractRegion                 - Removing consumer: ID:JT-L2.local-57912-1173118836305-1:2:1:1
DEBUG AbstractRegion                 - Removing consumer: ID:JT-L2.local-57912-1173118836305-1:2:-1:1
DEBUG TransportConnection            - Stopping connection: /127.0.0.1:60923
DEBUG TransportConnection            - Stopped connection: /127.0.0.1:60923

and this is then followed later by :-

DEBUG JournalMessageStore            - Transacted message add commit for: ID:JT-L2.local-57912-1173118836305-1:3:1:5:1, at: 0:79499
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Transacted message remove commit for: ID:JT-L2.local-57912-1173118836305-1:3:7:1:1, at: 0:81866
DEBUG Transport                      - Transport failed: java.io.EOFException
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:358)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267)
        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:156)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:136)
        at java.lang.Thread.run(Thread.java:613)
DEBUG TransportConnection            - Stopping connection: /127.0.0.1:60922




- JT

John Toohey

unread,
Mar 6, 2007, 10:23:04 AM3/6/07
to us...@mule.codehaus.org
I removed the TransactedSingleResourceJmsMessageReceiver and replaced it with TransactedJmsMessageReceiver, sent 1,000 message via a Grinder script, and everything worked as it should :-) Not sure what was going on here, but I may have been overloading the message listener on the SingleResource receiver.


- JT

Andrew Perepelytsya

unread,
Mar 6, 2007, 10:32:08 AM3/6/07
to us...@mule.codehaus.org
John,

If it's not too much effort for you, could you please post some performance results (in any form), with the nature of your processing, and possible a typical message size?

Andrew

On 3/6/07, John Toohey <j...@parspro.com> wrote:
I removed the TransactedSingleResourceJmsMessageReceiver and replaced it with TransactedJmsMessageReceiver, sent 1,000 message via a Grinder script, and everything worked as it should :-) Not sure what was going on here, but I may have been overloading the message listener on the SingleResource receiver.


- JT

On Mar 5, 2007, at 1:32 PM, John Toohey wrote:

Updated AMQ to 4.1, ( added apache-activemq-4.1.0-incubator.jar to the mule/lib/user, this is the bundled AMQ 4.1 jar) and ran test again, sending 10 messages to the Q. Nothing in the Mule logs on the first test, but AMQ has these exceptions :-

DEBUG JournalMessageStore            - Transacted message add commit for: ID: JT-L2.local-57912-1173118836305-1:2:1:3:1, at: 0:32840
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Journalled message remove for: ID: JT-L2.local-60921-1173118872832-1:0:1:1:5, at: 0:35303
DEBUG JournalMessageStore            - Journalled message add for: ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:35640
DEBUG JournalMessageStore            - Journalled message add for: ID: JT-L2.local-57912-1173118836305-1:0:9:1:1, at: 0:37562
DEBUG BetBrokerReplies               - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Journalled transacted message add for: ID: JT-L2.local-57912-1173118836305-1:2:1:5:1, at: 0:38416
DEBUG JournalMessageStore            - Journalled transacted message remove for: ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:40783
DEBUG JournalMessageStore            - Transacted message add commit for: ID: JT-L2.local-57912-1173118836305-1:2:1:5:1, at: 0:38416
DEBUG TPRejectedValidBets            - No subscriptions registered, will not dispatch message at this time.
DEBUG JournalMessageStore            - Transacted message remove commit for: ID: JT-L2.local-57912-1173118836305-1:2:2:1:1, at: 0:40783
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java :230)
        at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
        at org.apache.activemq.broker.CompositeDestinationBroker.send (CompositeDestinationBroker.java:98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:136)
        at org.apache.activemq.broker.TransportConnection.processMessage (TransportConnection.java:480)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:604)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java :284)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:177)
        at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:65)
        at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:133)
        at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
        at java.lang.Thread.run (Thread.java:613)
INFO  PrefetchSubscription           - Could not correlate acknowledgment with dispatched message: MessageAck {commandId = 41, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1 :2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:6, messageCount = 4}
DEBUG PrefetchSubscription           - Acknowledgment out of sync (Normally occurs when failover connection reconnects): MessageAck {commandId = 41, responseRequired = false, ackType = 2, consumerId = ID:JT-L2.local-57912-1173118836305-1 :2:1:1, firstMessageId = null, lastMessageId = ID:JT-L2.local-57912-1173118836305-1:2:2:1:1, destination = queue://parspro-core.TransactionBroker, transactionId = TX:ID:JT-L2.local-57912-1173118836305-1:2:6, messageCount = 4}
DEBUG Service                        - Async error occurred: javax.jms.JMSException: Transaction 'TX:ID:JT-L2.local-57912-1173118836305-1:2:5' has not been started.
javax.jms.JMSException: Transaction 'TX:ID: JT-L2.local-57912-1173118836305-1:2:5' has not been started.
        at org.apache.activemq.broker.TransactionBroker.getTransaction(TransactionBroker.java:230)
        at org.apache.activemq.broker.TransactionBroker.send (TransactionBroker.java:189)
        at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
        at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java :98)
        at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:136)
        at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:480)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:604)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:284)
        at org.apache.activemq.broker.TransportConnection$1.onCommand (TransportConnection.java:177)
        at java.lang.Thread.run (Thread.java:613)
Reply all
Reply to author
Forward
0 new messages