Mule
  1. Mule
  2. MULE-4376

Unexpected redelivery behaviour in ActiveMQ JMS Connector

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 2.2.1
    • Fix Version/s: None
    • Component/s: Transport: JMS
    • Labels:
      None
    • Environment:

      Mule 2.1.1, JDK 1.5.0_16; WinXP

    • User impact:
      Medium
    • Configuration:
      Hide

      <service name="TransactionOnInboundOnly">
      <inbound>
      <jms:inbound-endpoint queue="FromTest02" transformer-refs="JMSToObject" synchronous="false">
      <jms:transaction action="ALWAYS_BEGIN" timeout="15000"/>
      </jms:inbound-endpoint>
      </inbound>
      <outbound>
      <pass-through-router>
      <file:outbound-endpoint path="./FromJMS" outputPattern="$

      {OUTPUTPATTERN}

      " synchronous="false"/>
      </pass-through-router>
      </outbound>
      </service>

      Show
      <service name="TransactionOnInboundOnly"> <inbound> <jms:inbound-endpoint queue="FromTest02" transformer-refs="JMSToObject" synchronous="false"> <jms:transaction action="ALWAYS_BEGIN" timeout="15000"/> </jms:inbound-endpoint> </inbound> <outbound> <pass-through-router> < file:outbound-endpoint path="./FromJMS" outputPattern="$ {OUTPUTPATTERN} " synchronous="false"/> </pass-through-router> </outbound> </service>
    • Log Output:
      Attached as log file
    • Similar Issues:
      MULE-7195Incorrect message redelivery policy when using JMS
      MULE-8226JMS Durable Subscriber - unexpected behaviour in Mule HA Cluster - no failover
      MULE-7164dispatcher-threading-profile is an invalid property on jms:activemq-connector.
      MULE-221Jms Redelivery needs improvement
      MULE-1625Add Jms Redelivery Server Notifications
      MULE-5124ActiveMQ connectors fail to reconnect after JMS server restart
      MULE-1476Add ActiveMQ-specific JMS connector
      MULE-7534JMS connector doesn't reconnect to ActiveMQ broker 5.6 when using blocking=true
      MULE-6721Restarting Mule app makes loss JMS messages due to redelivery failure
      MULE-4162JMS Redelivery Handler tries to deliver a message in an endless loop

      Description

      See config for this.

      I send a message on the inbound JMS queue which starts a transaction; once the message hits the outbound endpoint (which cannot participate in the transaction) the transaction is rolled back. This is the expected behaviour and with Mule 2.1, those were the results I used to get.

      With Mule 2.2.1 I get different results. Tracing the transaction and endpoint-message notifications, I notice the following:

      1) With both versions, the first notification is transaction_BEGAN
      2) With both versions, the 2nd notification is MESSAGE_DISPATCHED
      3) With both versions, the 3rd notification is MESSAGE_RECEIVED
      4) With both versions, the 4th notification is TRANSACTION_ROLLEDBACK
      With Mule 2.2.2, there are some more notifications:
      5) TRANSACTION_BEGAN
      6) MESSAGE_RECEIVED
      7) TRANSACTION_ROLLEDBACK

      I dug deeper and noticed that the message used in (6) above is identical to the first one except that the JMSRedelivery property is set to true. I set maxRedelivery="0" in my config thinking that the default had changed but this was not it.

      Digging into the source, I found this in ActiveMqJmsConnector (line 73):

      // redelivery = deliveryCount - 1, but AMQ is considering the first delivery attempt as a redelivery (wrong!). adjust for it
      setMaximumRedeliveriesMethod.invoke(redeliveryPolicy, getMaxRedelivery() + 1);

      Thinking that perhaps Mule is over-compensating, I set maxRedelivery="-1" and got the results I expected.

      Note: Apart from the over-compensation, I don't think I should be allowed to set this attribute to a value less than zero ...

      1. mule.log
        464 kB
        Antoine Borg
      2. mule-config.xml
        2 kB
        Antoine Borg
      3. TransactionsTestSuite.java
        8 kB
        Antoine Borg

        Activity

        Hide
        Andrew Perepelytsya added a comment -

        And which AMQ version is that? I know that this setting has been messed with a lot since 4.x. The compensation is required for 4.x (as explained in the source comment)

        Show
        Andrew Perepelytsya added a comment - And which AMQ version is that? I know that this setting has been messed with a lot since 4.x. The compensation is required for 4.x (as explained in the source comment)
        Hide
        Antoine Borg added a comment -

        Ouch - the one detail I forgot to include ... sorry about that.

        ActiveMQ 4.1.1

        Show
        Antoine Borg added a comment - Ouch - the one detail I forgot to include ... sorry about that. ActiveMQ 4.1.1
        Hide
        Daniel Feist added a comment -

        Andrew, Please raise this to critical if it is a regression and has no work around.

        Show
        Daniel Feist added a comment - Andrew, Please raise this to critical if it is a regression and has no work around.
        Hide
        Ken Yagen added a comment - - edited

        An issue was fixed with redelivery in 2.2 that does change the behavior of redelivery (correcting a problem that existed previously). Please see MULE-4162. Is it possible that the fix for this issue uncovered a subtle change in AMQ behavior between versions? The Mule test suite runs against AMQ 4.1.2. Can you try your test with that version to see if it's any different?

        Show
        Ken Yagen added a comment - - edited An issue was fixed with redelivery in 2.2 that does change the behavior of redelivery (correcting a problem that existed previously). Please see MULE-4162 . Is it possible that the fix for this issue uncovered a subtle change in AMQ behavior between versions? The Mule test suite runs against AMQ 4.1.2. Can you try your test with that version to see if it's any different?
        Hide
        Antoine Borg added a comment -

        I have just retested with AMQ 4.1.2 and have the same result - I need to set maxRedelivery to -1 before it will work

        Show
        Antoine Borg added a comment - I have just retested with AMQ 4.1.2 and have the same result - I need to set maxRedelivery to -1 before it will work
        Hide
        Andrew Perepelytsya added a comment -

        Also note that the number of consumers will affect the count, it's not absolutely reliable (depends on vendor implementation). What it really takes care of is 'once it's over the threshold, do something'. Have you tried with consumers count set to 1?

        Show
        Andrew Perepelytsya added a comment - Also note that the number of consumers will affect the count, it's not absolutely reliable (depends on vendor implementation). What it really takes care of is 'once it's over the threshold, do something'. Have you tried with consumers count set to 1?
        Hide
        Antoine Borg added a comment -

        Thanks for the tip Andrew.

        With ActiveMQ 4.1.2 and numberOfConsumers="1", I still get the problem and need to leave maxRedelivery="-1"

        I tried with ActiveMQ 4.1.1 and numberOfConsumers="1" but still need to set maxRedelivery="-1"

        Show
        Antoine Borg added a comment - Thanks for the tip Andrew. With ActiveMQ 4.1.2 and numberOfConsumers="1", I still get the problem and need to leave maxRedelivery="-1" I tried with ActiveMQ 4.1.1 and numberOfConsumers="1" but still need to set maxRedelivery="-1"
        Hide
        Antoine Borg added a comment -

        I've added the complete mule-config.xml if it's of any help. The relevant part is the service I've already added, but you never know what may be affecting things

        Show
        Antoine Borg added a comment - I've added the complete mule-config.xml if it's of any help. The relevant part is the service I've already added, but you never know what may be affecting things
        Hide
        Antoine Borg added a comment -

        Attached test case too to show how I'm testing this configuration

        Show
        Antoine Borg added a comment - Attached test case too to show how I'm testing this configuration
        Hide
        Fabien Arrault added a comment -

        This issue is reproductible with Mule 3.1.0 and ActiveMQ 5.2.0

        Don't know if it's new with Mule 3, but this error log is quite clear :

        ERROR 2011-03-18 17:22:28,379 [ActiveMQ Session Task] org.mule.exception.DefaultServiceExceptionStrategy:
        ********************************************************************************
        Message : "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage
        Code : MULE_ERROR--2
        --------------------------------------------------------------------------------
        Exception stack is:
        1. "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage (org.mule.transport.jms.redelivery.MessageRedeliveredException)
        org.mule.transport.jms.redelivery.JmsXRedeliveryHandler:85 (http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/transport/jms/redelivery/MessageRedeliveredException.html)
        --------------------------------------------------------------------------------
        Root Exception stack trace:
        org.mule.transport.jms.redelivery.MessageRedeliveredException: "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage
        at org.mule.transport.jms.redelivery.JmsXRedeliveryHandler.handleRedelivery(JmsXRedeliveryHandler.java:85)
        at org.mule.transport.jms.MultiConsumerJmsMessageReceiver$JmsWorker.preProcessMessage(MultiConsumerJmsMessageReceiver.java:385)
        at org.mule.transport.AbstractReceiverWorker$1.doInTransaction(AbstractReceiverWorker.java:96)
        + 3 more (set debug level logging or '-Dmule.verbose.exceptions=true' for everything)
        ********************************************************************************

        Show
        Fabien Arrault added a comment - This issue is reproductible with Mule 3.1.0 and ActiveMQ 5.2.0 Don't know if it's new with Mule 3, but this error log is quite clear : ERROR 2011-03-18 17:22:28,379 [ActiveMQ Session Task] org.mule.exception.DefaultServiceExceptionStrategy: ******************************************************************************** Message : "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage Code : MULE_ERROR--2 -------------------------------------------------------------------------------- Exception stack is: 1. "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage (org.mule.transport.jms.redelivery.MessageRedeliveredException) org.mule.transport.jms.redelivery.JmsXRedeliveryHandler:85 ( http://www.mulesoft.org/docs/site/current3/apidocs/org/mule/transport/jms/redelivery/MessageRedeliveredException.html ) -------------------------------------------------------------------------------- Root Exception stack trace: org.mule.transport.jms.redelivery.MessageRedeliveredException: "Message with id "ID:inge30-THINK-50205-1300465348000-0:0:4:1:1" has been redelivered 1 times on endpoint "jms://FromTest02", which exceeds the maxRedelivery setting of 0 on the connector "ActiveMQ". Message payload is of type: ActiveMQTextMessage at org.mule.transport.jms.redelivery.JmsXRedeliveryHandler.handleRedelivery(JmsXRedeliveryHandler.java:85) at org.mule.transport.jms.MultiConsumerJmsMessageReceiver$JmsWorker.preProcessMessage(MultiConsumerJmsMessageReceiver.java:385) at org.mule.transport.AbstractReceiverWorker$1.doInTransaction(AbstractReceiverWorker.java:96) + 3 more (set debug level logging or '-Dmule.verbose.exceptions=true' for everything) ********************************************************************************
        Hide
        Arved Sandstrom added a comment -

        This issue also reproducible with Mule CE 3.3 and WebSphere MQ. <jms:inbound-endpoint /> goes into the infinite "redelivery" loop described here unless "maxRedelivery" on the connector is set to -1.

        Show
        Arved Sandstrom added a comment - This issue also reproducible with Mule CE 3.3 and WebSphere MQ. <jms:inbound-endpoint /> goes into the infinite "redelivery" loop described here unless "maxRedelivery" on the connector is set to -1.

          People

          • Assignee:
            Unassigned
            Reporter:
            Antoine Borg
          • Votes:
            2 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:

              Development