You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by xabhi <xa...@gmail.com> on 2017/03/13 06:41:59 UTC

Unmatched acknowledge: MessageAckExpected - message count (1) differs from count in dispatched-list (2)

Observed below exceptions in STOMP consumer after failover. The consumer
continued to receive messages but this exception kept coming on both client
and server side and when the master activemq instance took over after
another failover, all the messages were redelivered and below warning went
away.
I think it is a bug of some kind, can someone from ActiveMQ Dev team help
here. 

Exception:
[20170310 00:24:22:092 stomp_client.py:82 ERROR] Received an error:
org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK
received for message-id
[ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:4:-1:1:1]
            at
org.apache.activemq.transport.stomp.ProtocolConverter.onStompAck(ProtocolConverter.java:475)
            at
org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:250)
            at
org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:85)
            at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
            at
org.apache.activemq.transport.stomp.StompCodec.processCommand(StompCodec.java:129)
            at
org.apache.activemq.transport.stomp.StompCodec.parse(StompCodec.java:100)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.processBuffer(StompNIOTransport.java:136)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.serviceRead(StompNIOTransport.java:121)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.access$000(StompNIOTransport.java:44)
            at
org.apache.activemq.transport.stomp.StompNIOTransport$1.onSelect(StompNIOTransport.java:73)
            at
org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:98)
            at
org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:118)
            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)
 
[20170310 00:24:22:096 stomp_client.py:82 ERROR] Received an error:
javax.jms.JMSException: Unmatched acknowledge: MessageAck
{commandId = 5, responseRequired = false, ackType = 2, consumerId =
ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:9:-1:1, firstMessageId =
null, lastMessageId =
ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:4:-1:1:2, destination =
topic://run1.topic.0, transactionId = null, messageCount = 1, poisonCause =
null}
; Expected message count (1) differs from count in dispatched-list (2)
            at
org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:520)
            at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:212)
            at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:528)
            at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:484)
            at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:88)
            at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276)
            at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:88)
            at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:98)
            at
org.apache.activemq.broker.util.LoggingBrokerPlugin.acknowledge(LoggingBrokerPlugin.java:162)
            at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:98)
            at
deshaw.tools.jms.ActiveMQLoggingPlugin.acknowledge(ActiveMQLoggingPlugin.java:453)
            at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:98)
            at
org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:590)
            at
org.apache.activemq.command.MessageAck.visit(MessageAck.java:245)
            at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:336)
            at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
            at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:45)
            at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
            at
org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:97)
            at
org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:202)
            at
org.apache.activemq.transport.stomp.ProtocolConverter.onStompAck(ProtocolConverter.java:456)
            at
org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:250)
            at
org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:85)
            at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
            at
org.apache.activemq.transport.stomp.StompCodec.processCommand(StompCodec.java:129)
            at
org.apache.activemq.transport.stomp.StompCodec.parse(StompCodec.java:100)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.processBuffer(StompNIOTransport.java:136)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.serviceRead(StompNIOTransport.java:121)
            at
org.apache.activemq.transport.stomp.StompNIOTransport.access$000(StompNIOTransport.java:44)
            at
org.apache.activemq.transport.stomp.StompNIOTransport$1.onSelect(StompNIOTransport.java:73)
            at
org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:98)
            at
org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:118)
            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)



--
View this message in context: http://activemq.2283324.n4.nabble.com/Unmatched-acknowledge-MessageAckExpected-message-count-1-differs-from-count-in-dispatched-list-2-tp4723664.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Unmatched acknowledge: MessageAckExpected - message count (1) differs from count in dispatched-list (2)

Posted by xabhi <xa...@gmail.com>.
Hi Tim,
Thanks for the reply. I already submitted this as a bug in JIRA, see 
https://issues.apache.org/jira/browse/AMQ-6622
<https://issues.apache.org/jira/browse/AMQ-6622>  , but no one responded
there so I had to cross post on the forum.

I would like to know if there is any workaround for this bug in case it
happens in production? Is restart the only way to fix it?

Thanks,
Abhi



--
View this message in context: http://activemq.2283324.n4.nabble.com/Unmatched-acknowledge-MessageAckExpected-message-count-1-differs-from-count-in-dispatched-list-2-tp4723664p4723739.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Unmatched acknowledge: MessageAckExpected - message count (1) differs from count in dispatched-list (2)

Posted by Tim Bain <tb...@alumni.duke.edu>.
Please submit this as a bug in JIRA.

Tim

On Mar 12, 2017 11:48 PM, "xabhi" <xa...@gmail.com> wrote:

> Observed below exceptions in STOMP consumer after failover. The consumer
> continued to receive messages but this exception kept coming on both client
> and server side and when the master activemq instance took over after
> another failover, all the messages were redelivered and below warning went
> away.
> I think it is a bug of some kind, can someone from ActiveMQ Dev team help
> here.
>
> Exception:
> [20170310 00:24:22:092 stomp_client.py:82 ERROR] Received an error:
> org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK
> received for message-id
> [ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:4:-1:1:1]
>             at
> org.apache.activemq.transport.stomp.ProtocolConverter.
> onStompAck(ProtocolConverter.java:475)
>             at
> org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(
> ProtocolConverter.java:250)
>             at
> org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(
> StompTransportFilter.java:85)
>             at
> org.apache.activemq.transport.TransportSupport.doConsume(
> TransportSupport.java:83)
>             at
> org.apache.activemq.transport.stomp.StompCodec.processCommand(StompCodec.
> java:129)
>             at
> org.apache.activemq.transport.stomp.StompCodec.parse(StompCodec.java:100)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.processBuffer(
> StompNIOTransport.java:136)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.
> serviceRead(StompNIOTransport.java:121)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.
> access$000(StompNIOTransport.java:44)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport$1.
> onSelect(StompNIOTransport.java:73)
>             at
> org.apache.activemq.transport.nio.SelectorSelection.
> onSelect(SelectorSelection.java:98)
>             at
> org.apache.activemq.transport.nio.SelectorWorker$1.run(
> SelectorWorker.java:118)
>             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)
>
> [20170310 00:24:22:096 stomp_client.py:82 ERROR] Received an error:
> javax.jms.JMSException: Unmatched acknowledge: MessageAck
> {commandId = 5, responseRequired = false, ackType = 2, consumerId =
> ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:9:-1:1, firstMessageId
> =
> null, lastMessageId =
> ID:diogenes31.nyc.deshaw.com-41001-1489085659582-1:4:-1:1:2, destination =
> topic://run1.topic.0, transactionId = null, messageCount = 1, poisonCause =
> null}
> ; Expected message count (1) differs from count in dispatched-list (2)
>             at
> org.apache.activemq.broker.region.PrefetchSubscription.
> assertAckMatchesDispatched(PrefetchSubscription.java:520)
>             at
> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(
> PrefetchSubscription.java:212)
>             at
> org.apache.activemq.broker.region.AbstractRegion.
> acknowledge(AbstractRegion.java:528)
>             at
> org.apache.activemq.broker.region.RegionBroker.
> acknowledge(RegionBroker.java:484)
>             at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:88)
>             at
> org.apache.activemq.broker.TransactionBroker.acknowledge(
> TransactionBroker.java:276)
>             at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:88)
>             at
> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(
> MutableBrokerFilter.java:98)
>             at
> org.apache.activemq.broker.util.LoggingBrokerPlugin.acknowledge(
> LoggingBrokerPlugin.java:162)
>             at
> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(
> MutableBrokerFilter.java:98)
>             at
> deshaw.tools.jms.ActiveMQLoggingPlugin.acknowledge(
> ActiveMQLoggingPlugin.java:453)
>             at
> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(
> MutableBrokerFilter.java:98)
>             at
> org.apache.activemq.broker.TransportConnection.processMessageAck(
> TransportConnection.java:590)
>             at
> org.apache.activemq.command.MessageAck.visit(MessageAck.java:245)
>             at
> org.apache.activemq.broker.TransportConnection.service(
> TransportConnection.java:336)
>             at
> org.apache.activemq.broker.TransportConnection$1.
> onCommand(TransportConnection.java:200)
>             at
> org.apache.activemq.transport.MutexTransport.onCommand(
> MutexTransport.java:45)
>             at
> org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(
> AbstractInactivityMonitor.java:301)
>             at
> org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(
> StompTransportFilter.java:97)
>             at
> org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(
> ProtocolConverter.java:202)
>             at
> org.apache.activemq.transport.stomp.ProtocolConverter.
> onStompAck(ProtocolConverter.java:456)
>             at
> org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(
> ProtocolConverter.java:250)
>             at
> org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(
> StompTransportFilter.java:85)
>             at
> org.apache.activemq.transport.TransportSupport.doConsume(
> TransportSupport.java:83)
>             at
> org.apache.activemq.transport.stomp.StompCodec.processCommand(StompCodec.
> java:129)
>             at
> org.apache.activemq.transport.stomp.StompCodec.parse(StompCodec.java:100)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.processBuffer(
> StompNIOTransport.java:136)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.
> serviceRead(StompNIOTransport.java:121)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport.
> access$000(StompNIOTransport.java:44)
>             at
> org.apache.activemq.transport.stomp.StompNIOTransport$1.
> onSelect(StompNIOTransport.java:73)
>             at
> org.apache.activemq.transport.nio.SelectorSelection.
> onSelect(SelectorSelection.java:98)
>             at
> org.apache.activemq.transport.nio.SelectorWorker$1.run(
> SelectorWorker.java:118)
>             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)
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.
> nabble.com/Unmatched-acknowledge-MessageAckExpected-message-
> count-1-differs-from-count-in-dispatched-list-2-tp4723664.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>