FUSE Message Broker
  1. FUSE Message Broker
  2. MB-1133

DurableSubProcessWithRestartTest , acknowledged messages appear to intermittently be redelivered to the subscriber

    Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Major Major
    • Resolution: Done
    • Affects Version/s: 5.5.1-fuse-03-06
    • Component/s: broker
    • Labels:
      None
    • Environment:
      tested with apache-activemq-5.5.1.fuse-20120330.033257-8
    • Similar Issues:
      Show 10 results 

      Description

      See log file snippet below.

      2012-04-05 09:36:09,070 [Server         ] - INFO  rableSubProcessWithRestartTest - Sending Trans[id=37, count=673, clientType=D]
      2012-04-05 09:36:09,294 [Server         ] - INFO  rableSubProcessWithRestartTest - About to Commit Trans[id=37, count=673, clientType=D], ID=22327
      2012-04-05 09:36:09,402 [Client3        ] - INFO  rableSubProcessWithRestartTest - Received Trans[id=37, count=673] in Client[id=3, type=D].
      2012-04-05 09:36:09,402 [Client3        ] - INFO  rableSubProcessWithRestartTest - Going offline during transaction commit.
      2012-04-05 09:36:09,428 [Client3        ] - INFO  rableSubProcessWithRestartTest - Client[id=3, type=D] OFFLINE.
      2012-04-05 09:36:09,462 [Server         ] - INFO  rableSubProcessWithRestartTest - Committed Trans[id=37, count=673, clientType=D], ID=22327
      2012-04-05 09:36:09,462 [Client8        ] - INFO  rableSubProcessWithRestartTest - Received Trans[id=37, count=0] in Client[id=8, type=B].
      
      .....
      .....
      
      2012-04-05 09:36:15,195 [Server         ] - INFO  rableSubProcessWithRestartTest - Sending Trans[id=47, count=571, clientType=null]
      2012-04-05 09:36:15,387 [Server         ] - INFO  rableSubProcessWithRestartTest - About to Commit Trans[id=47, count=571, clientType=null], ID=28247
      2012-04-05 09:36:15,498 [Server         ] - INFO  rableSubProcessWithRestartTest - Committed Trans[id=47, count=571, clientType=null], ID=28247
      2012-04-05 09:36:15,644 [Client3        ] - INFO  rableSubProcessWithRestartTest - Client[id=3, type=D] ONLINE.
      2012-04-05 09:36:15,645 [ActiveMQ Task-3] - INFO  FailoverTransport              - Successfully connected to tcp://localhost:61656?wireFormat.maxInactivityDuration=0
      2012-04-05 09:36:15,662 [Client3        ] - INFO  rableSubProcessWithRestartTest - ! Message has been processed before. Client[id=3, type=D] message = ActiveMQMessage {commandId = 225, responseRequired = true, messageId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1:221, originalDestination = null, originalTransactionId = null, producerId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1, destination = topic://TopicT, transactionId = TX:ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1, expiration = 0, timestamp = 1333611369144, arrival = 0, brokerInTime = 1333611369144, brokerOutTime = 1333611375647, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@274ce1fd, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {ID=21874, CARGO=aaaaaa...a, TYPE=h, TRANS=37}, readOnlyProperties = true, readOnlyBody = true, droppable = false}
      2012-04-05 09:36:15,663 [Client3        ] - ERROR rableSubProcessWithRestartTest - Missing messages!
      Missing TRANS=40, size=1
      Received message: ActiveMQMessage {commandId = 225, responseRequired = true, messageId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1:221, originalDestination = null, originalTransactionId = null, producerId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1, destination = topic://TopicT, transactionId = TX:ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1, expiration = 0, timestamp = 1333611369144, arrival = 0, brokerInTime = 1333611369144, brokerOutTime = 1333611375647, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@274ce1fd, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {ID=21874, CARGO=aaaaaaaaaaaa...., TYPE=h, TRANS=37}, readOnlyProperties = true, readOnlyBody = true, droppable = false}
      Expected message: ActiveMQMessage {commandId = 514, responseRequired = true, messageId = ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1:1:510, originalDestination = null, originalTransactionId = null, producerId = ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1:1, destination = topic://TopicT, transactionId = TX:ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1, expiration = 0, timestamp = 1333611370812, arrival = 0, brokerInTime = 1333611370812, brokerOutTime = 1333611372628, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@2888bd33, dataStructure = null, redeliveryCounter = 0, size = 1071, properties = {COMMIT=true, RELEVANT=true, ID=24037, TRANS=40}, readOnlyProperties = true, readOnlyBody = true, droppable = false}
      java.lang.RuntimeException: Missing messages!
      Missing TRANS=40, size=1
      Received message: ActiveMQMessage {commandId = 225, responseRequired = true, messageId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1:221, originalDestination = null, originalTransactionId = null, producerId = ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1:1, destination = topic://TopicT, transactionId = TX:ID:unknown3c07543fab70.home-55675-1333611344002-5:37:1, expiration = 0, timestamp = 1333611369144, arrival = 0, brokerInTime = 1333611369144, brokerOutTime = 1333611375647, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@274ce1fd, dataStructure = null, redeliveryCounter = 0, size = 0, properties = {ID=21874, CARGO=aaaaaaaaaaaaaaaaaa..., TYPE=h, TRANS=37}, readOnlyProperties = true, readOnlyBody = true, droppable = false}
      Expected message: ActiveMQMessage {commandId = 514, responseRequired = true, messageId = ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1:1:510, originalDestination = null, originalTransactionId = null, producerId = ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1:1, destination = topic://TopicT, transactionId = TX:ID:unknown3c07543fab70.home-55675-1333611344002-5:40:1, expiration = 0, timestamp = 1333611370812, arrival = 0, brokerInTime = 1333611370812, brokerOutTime = 1333611372628, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = null, marshalledProperties = org.apache.activemq.util.ByteSequence@2888bd33, dataStructure = null, redeliveryCounter = 0, size = 1071, properties = {COMMIT=true, RELEVANT=true, ID=24037, TRANS=40}, readOnlyProperties = true, readOnlyBody = true, droppable = false}
      	at org.apache.activemq.usecases.DurableSubProcessWithRestartTest.exit(DurableSubProcessWithRestartTest.java:823)
      	at org.apache.activemq.usecases.DurableSubProcessWithRestartTest.exit(DurableSubProcessWithRestartTest.java:819)
      	at org.apache.activemq.usecases.DurableSubProcessWithRestartTest$Client.onClientMessage(DurableSubProcessWithRestartTest.java:648)
      	at org.apache.activemq.usecases.DurableSubProcessWithRestartTest$Client.process(DurableSubProcessWithRestartTest.java:547)
      	at org.apache.activemq.usecases.DurableSubProcessWithRestartTest$Client.run(DurableSubProcessWithRestartTest.java:495)
      
      

      Client3 appears to recieve the message batch/message in server transaction that is being commited as client3 goes OFFLINE. When client 3 comes back on line later, a message from that message batch is redelivered to the client3

        Issue Links

          Activity

          Hide
          Pat Fox
          added a comment -

          Perhaps this is linked to MB-1117, not definite yet.

          Show
          Pat Fox
          added a comment - Perhaps this is linked to MB-1117 , not definite yet.
          Hide
          Gary Tully
          added a comment -

          fix for https://issues.apache.org/jira/browse/AMQ-3805 is on the 5.5.1-fuse branch.

          Show
          Gary Tully
          added a comment - fix for https://issues.apache.org/jira/browse/AMQ-3805 is on the 5.5.1-fuse branch.
          Show
          Gary Tully
          added a comment - snapshot with the fix: http://repo.fusesource.com/nexus/content/repositories/snapshots/org/apache/activemq/apache-activemq/5.5.1.fuse-SNAPSHOT/apache-activemq-5.5.1.fuse-20120504.171059-15-bin.tar.gz

            People

            • Assignee:
              Gary Tully
              Reporter:
              Pat Fox
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: