You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "JJ (JIRA)" <ji...@apache.org> on 2019/02/27 20:07:00 UTC

[jira] [Comment Edited] (AMQ-6902) Expected message count (1) differs from count in dispatched-list (100) & Unexpected ACK received

    [ https://issues.apache.org/jira/browse/AMQ-6902?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16779728#comment-16779728 ] 

JJ edited comment on AMQ-6902 at 2/27/19 8:06 PM:
--------------------------------------------------

I have been able to reproduce this error on a test server with a fresh deployment & updated versions of server, client and Java.

The issue does not cause a 'stuck queue' count in the test environment, but does appear to lead to a loss of messages and a client crash. Once the client is manually recovered messages are processed as normal.

I am able to reproduce this by running an AMQ instance in console mode, connecting 1 or more clients and an upstream message provider, then restarting the AMQ instance gracefully with a CTRL+C (it reports a successful stop)


was (Author: jj-amq):
I have been able to reproduce this error on a test server with a fresh deployment & updated versions of server, client and Java.

The issue does not cause a 'stuck queue' count in the test environment, but does appear to lead to a loss of messages and a client crash. Once the client is manually recovered messages are processed as normal.

> Expected message count (1) differs from count in dispatched-list (100) & Unexpected ACK received
> ------------------------------------------------------------------------------------------------
>
>                 Key: AMQ-6902
>                 URL: https://issues.apache.org/jira/browse/AMQ-6902
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: activemq-camel, Broker, networkbridge, stomp
>    Affects Versions: 5.15.2, 5.15.8
>         Environment: CentOS 6.9 x64
> {code:java}
> Linux xs 4.10.13-1.el6.elrepo.x86_64 #1 SMP Thu Apr 27 12:13:03 EDT 2017 x86_64 x86_64 x86_64 GNU/Linux{code}
> STOP Consumer via;
> {code:java}
> ruby 2.2.3p173 (2015-08-18 revision 51636) [x86_64-linux-gnu]{code}
> {code:java}
> stomp-gem 1.4.3{code}
>            Reporter: JJ
>            Priority: Major
>              Labels: newbie
>
> Following an unexpected server restart the following errors where observed and lead to an apparent loss of messages to the client. (looks related to: AMQ-6622)
> AMQ is running as a network broker bridging topics from a private data feed providing client connectivity. The local client topics are persistent.
> The chain of events is roughly;
>  1 - AMQ stops ungracefully due to server issue.
>  2 - Server restarts & AMQ auto restarts & re-connects to upstream provider.
>  3 - AMQ buffers messages for all known persistent topics for ~40min
>  4 - Clients re connect to AMQ and expect to drain down the topics. Several exhibited errors.
> Log extracts only;
> {code:java}
> 2018-02-18 12:13:19,442 | WARN  | Async error occurred: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 518, responseRequired = false, ackType = 2, consumerId = ID:xs-35265-1518953016334-7:1:-1:1, firstMessageId = null, lastMessageId = ID:xs-35265-1518953016334-4:1:2:1:503, destination = topic://TD_ANG, transactionId = null, messageCount = 1, poisonCause = null}; Expected message count (1) differs from count in dispatched-list (100) | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport: tcp:///172.16.0.2:44808@61618
> 2018-02-18 12:13:19,443 | WARN  | Exception occurred while processing a command: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 518, responseRequired = false, ackType = 2, consumerId = ID:xs-35265-1518953016334-7:1:-1:1, firstMessageId = null, lastMessageId = ID:xs-35265-1518953016334-4:1:2:1:503, destination = topic://TD_ANG, transactionId = null, messageCount = 1, poisonCause = null}; Expected message count (1) differs from count in dispatched-list (100) | org.apache.activemq.transport.stomp.ProtocolConverter | ActiveMQ BrokerService[xs.goth.int] Task-3
> 2018-02-18 12:20:11,343 | WARN  | Async error occurred: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 735, responseRequired = false, ackType = 2, consumerId = ID:xs-35265-1518953016334-7:5:-1:1, firstMessageId = null, lastMessageId = ID:xs-35265-1518953016334-4:1:5:1:323, destination = topic://TRUST_EB, transactionId = null, messageCount = 1, poisonCause = null}; Expected message count (1) differs from count in dispatched-list (100) | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport: tcp:///172.16.0.2:45030@61618
> 2018-02-18 12:20:11,344 | WARN  | Exception occurred while processing a command: javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 735, responseRequired = false, ackType = 2, consumerId = ID:xs-35265-1518953016334-7:5:-1:1, firstMessageId = null, lastMessageId = ID:xs-35265-1518953016334-4:1:5:1:323, destination = topic://TRUST_EB, transactionId = null, messageCount = 1, poisonCause = null}; Expected message count (1) differs from count in dispatched-list (100) | org.apache.activemq.transport.stomp.ProtocolConverter | ActiveMQ BrokerService[xs.goth.int] Task-7
> 2018-02-18 12:20:10,959 | WARN  | Exception occurred processing: ACK -> org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK received for message-id [ID:xs-35265-1518953016334-4:1:5:1:318] | org.apache.activemq.transport.stomp.ProtocolConverter | ActiveMQ Transport: tcp:///172.16.0.2:45030@61618
> 2018-02-18 12:20:11,053 | WARN  | Exception occurred processing: ACK -> org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK received for message-id [ID:xs-35265-1518953016334-4:1:5:1:319] | org.apache.activemq.transport.stomp.ProtocolConverter | ActiveMQ Transport: tcp:///172.16.0.2:45030@61618
> 2018-02-18 12:20:11,129 | WARN  | Exception occurred processing: ACK -> org.apache.activemq.transport.stomp.ProtocolException: Unexpected ACK received for message-id [ID:xs-35265-1518953016334-4:1:5:1:320] | org.apache.activemq.transport.stomp.ProtocolConverter | ActiveMQ Transport: tcp:///172.16.0.2:45030@61618
> {code}
> The AMQ Admin console showed the 'Pending Queue Size' as 100+ for the relevant topic and would never drain down to 0. During this time the consumer client was still receiving other messages from the topic.
> Nothing was shown in the DLQ.
> This is a production environment.
> The client consuming the 'TRUST_XX' topic logged the same error but recovered with lots of Unexpected ACK's and duplicated messages, the client consuming the 'TD_ANG' topic was the one which ended up with the 'stuck' messages.
> Deleting the persistent subscription from within the AMQ web admin and re-connecting the client resolved the issue.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)