Re: Async error occurred javax.jms.JMSException: Unmatched acknowledge

2018-03-13 Thread Tim Bain 
Are you using XA transactions, or just JMS ones? And did a master-slave
failover occur? If you're using XA and a failover occurred while that
message was being processing, it's possible you're seeing an occurrence of
https://issues.apache.org/jira/browse/AMQ-5854. It was observed as early as
5.9.1, but it's possible that it's also in earlier versions such as 5.8.0
that you're using. If this describes your setup, I'd definitely recommend
an upgrade to get that fix. You'd probably want to go all the way to 5.15.3
unless you've got a strong reason to use an earlier version.

And in general, if you see that message immediately after a failover (even
without XA transactions), this could be expected behavior, because it would
indicate the client trying to ack a message that the new master broker
didn't dispatch. Did a failover occur around the time this happened?

If not, there have been several reports of similar symptoms over the past
few years (
http://activemq.2283324.n4.nabble.com/Active-MQ-5-15-acknowledgment-issue-Async-error-occurred-javax-jms-JMSException-Unmatched-acknowledg-td4735271.html,
https://issues.apache.org/jira/browse/AMQ-6902,
https://issues.apache.org/jira/browse/AMQ-3901,
https://stackoverflow.com/questions/27928419/activemq-throwing-unmatched-acknowledge-exception),
but not enough information from those reporters to actually figure out the
root cause. Can you please look at each of those reports and tell us in
which ways your situation matches theirs and in which ways if any you're
doing something different than they are? Maybe by comparing and
contrasting, we can find something to investigate further.

Also, did I understand you to say that you would get this message
indicating a duplicate ack, but then the message would not be discarded and
would be redelivered later? That sounds like either we have two copies of
the message in the message store or like we're somehow confusing which
message the ack goes to, but I want to be sure I understand the exact
sequence of events correctly.

Tim

On Tue, Mar 13, 2018 at 8:04 AM, mm <marcus.meu...@novis-software.de> wrote:

> Hi, i have got the following WARNING Message...
>
> 2018-03-05 17:07:17,385 | WARN  | Async error occurred:
> javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId =
> 3101,
> responseRequired = false, ackType = 2, consumerId =
> ID:FEICFFR011-61629-1520204406620-0:4:0:0, firstMessageId =
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:301, lastMessageId =
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:302, destination =
> queue://DZBANK_TO_ICF, transactionId =
> TX:ID:FEICFFR011-61629-1520204406620-0:4:1027, messageCount = 2,
> poisonCause
> = null}; Could not find Message-ID
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:301 in dispatched-list (start of
> ack) | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ
> Transport: tcp:///127.0.0.1:49257@61616
> javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId =
> 3101,
> responseRequired = false, ackType = 2, consumerId =
> ID:FEICFFR011-61629-1520204406620-0:4:0:0, firstMessageId =
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:301, lastMessageId =
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:302, destination =
> queue://DZBANK_TO_ICF, transactionId =
> TX:ID:FEICFFR011-61629-1520204406620-0:4:1027, messageCount = 2,
> poisonCause
> = null}; Could not find Message-ID
> ID:FEICFFR011-63905-1520229600356-1:1:1:1:301 in dispatched-list (start of
> ack)
> at
> org.apache.activemq.broker.region.PrefetchSubscription.
> assertAckMatchesDispatched(PrefetchSubscription.java:482)
> at
> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(
> PrefetchSubscription.java:214)
> at
> org.apache.activemq.broker.region.AbstractRegion.
> acknowledge(AbstractRegion.java:426)
> at
> org.apache.activemq.broker.region.RegionBroker.
> acknowledge(RegionBroker.java:408)
> at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
> at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
> at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
> at
> org.apache.activemq.broker.TransactionBroker.acknowledge(
> TransactionBroker.java:287)
> at
> org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
> at
> org.apache.activemq.broker.MutableBrokerFilter.acknowledge(
> MutableBrokerFilter.java:87)
> at
> org.apache.activemq.broker.TransportConnection.processMessageAck(
> TransportConnection.java:508)
> at
> org.apache.activemq.command.MessageAck.visit(MessageAck.java:236)
>

Async error occurred javax.jms.JMSException: Unmatched acknowledge

2018-03-13 Thread mm 
Hi, i have got the following WARNING Message...

2018-03-05 17:07:17,385 | WARN  | Async error occurred:
javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 3101,
responseRequired = false, ackType = 2, consumerId =
ID:FEICFFR011-61629-1520204406620-0:4:0:0, firstMessageId =
ID:FEICFFR011-63905-1520229600356-1:1:1:1:301, lastMessageId =
ID:FEICFFR011-63905-1520229600356-1:1:1:1:302, destination =
queue://DZBANK_TO_ICF, transactionId =
TX:ID:FEICFFR011-61629-1520204406620-0:4:1027, messageCount = 2, poisonCause
= null}; Could not find Message-ID
ID:FEICFFR011-63905-1520229600356-1:1:1:1:301 in dispatched-list (start of
ack) | org.apache.activemq.broker.TransportConnection.Service | ActiveMQ
Transport: tcp:///127.0.0.1:49257@61616
javax.jms.JMSException: Unmatched acknowledge: MessageAck {commandId = 3101,
responseRequired = false, ackType = 2, consumerId =
ID:FEICFFR011-61629-1520204406620-0:4:0:0, firstMessageId =
ID:FEICFFR011-63905-1520229600356-1:1:1:1:301, lastMessageId =
ID:FEICFFR011-63905-1520229600356-1:1:1:1:302, destination =
queue://DZBANK_TO_ICF, transactionId =
TX:ID:FEICFFR011-61629-1520204406620-0:4:1027, messageCount = 2, poisonCause
= null}; Could not find Message-ID
ID:FEICFFR011-63905-1520229600356-1:1:1:1:301 in dispatched-list (start of
ack)
at
org.apache.activemq.broker.region.PrefetchSubscription.assertAckMatchesDispatched(PrefetchSubscription.java:482)
at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:214)
at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:426)
at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:408)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:287)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77)
at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87)
at
org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:508)
at
org.apache.activemq.command.MessageAck.visit(MessageAck.java:236)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
at java.lang.Thread.run(Unknown Source)

My Probelm is know that it seems that the incoming Message would not be
acknowlodged at this time, the message would hold back in ActiveMQ (we use
no dead letter Queue!) and would be send again some times later. So our
Application receive the message at 2 times.  

We use ActiveMQ 5.8.0 on Windows distribution (32 bit).
Our Transport Mode for ActiveMQ is SESSION_TRANSACTED so we commit every
Message when they was arraived. This works the most time perfect, but
sometimes we had this WARNING "Async error occurred" and we get some
Messages doubles. Is it possible to solve this when we update to newer
ActiveMQ maybe 5.12. or is it a problem with the transport Mode?

Hope somebody can hel me...




--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html

Re: Active MQ 5.15 acknowledgment issue: 'Async error occurred: javax.jms.JMSException: Unmatched acknowledge - Could not find Message-ID in dispatched-list start of ack'

2018-01-24 Thread Tim Bain 
Is this a single broker or a network of brokers? If it's standalone, then
yes, I believe that it indicates a client error. If it's a network of
brokers, we'd need more information about the network (# nodes, topology,
etc.) and about the networkConnectors as you've configured them, to see if
this is a client error as you suggested or if it's an artifact of the
network itself.

Tim

On Jan 17, 2018 2:05 AM, "pablo1a"  wrote:

> Hi all,
>
> We are experiencing a recurring message acknowledgment issue in the form
> of:
>
> / <> <> <>
> <1516176117355>   javax.jms.JMSException: Unmatched acknowledge*: MessageAck {commandId =
> 17, responseRequired = false, ackType = 2, consumerId =
> ID:c27791-62893-1516176115418-1:1:2:1, firstMessageId =
> ID:c27791-62370-1516175410475-1:1:1:1:1, lastMessageId =
> ID:c27791-62439-1516175599485-1:1:1:24:1, destination =
> queue://Consumer.core.VirtualTopic.FotowebEvents, transactionId =
> XID:[48801,globalId=035763fff035ffb7ffee4d52,branchId=
> 7765626c6f6769632e656a622e636f6e7461696e65722e4a4d53436f6e6e
> 656374696f6e506f6c6c65722e466f746f776562496d6167654576656e74
> cffc7ffc9ffa4],
> messageCount = 2, poisonCause = null}; *Could not find Message-ID
> ID:c27791-62370-1516175410475-1:1:1:1:1 in dispatched-list (start of
> ack)*>
> /
>
> What I see occuring in the broker's log is a two 'Acknowledging message for
> ...' lines occurring only one second apart, for this referenced message ID
> /c27791-62370-1516175410475-1:1:1:1:1/. So while the first acknowledging
> step/call has already dequeued/acked the message, the second, superfluous
> call doesn't find the message anymore thus causing the error.
>
> Questions:
> - Am i right to issume this is erronous behavior *on the client side*, in
> calling the ack twice?
> - What client configuration or setting(s) might be erroneous here?
> - Any other thought for troubleshooting? I have Googled quite a bit and
> applied 'jms.prefetchPolicy.queuePrefetch=1' on the broker URl, but to no
> avail yet.
>
> Context:
> - Consumer is an MDB deployed in weblogic JEE server, set up to use
> ActiveMQ
> 5.15 client libs.
> - XA transaction-based acknowledgement is used.
> - Broker is a ActiveMQ 5.15 broker instance deployed in another weblogic
> server (packaged within war).
>
> Thank you in advance,
>
> Patrick
>
> Broker's log example, red lines mark identical Ack calls happening within
> second from one another:
>  extract-unmatched-ack-0.png>
>
>  extract-unmatched-ack-1.png>
>
>
>
>
>
> --
> Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-
> f2341805.html
>

Active MQ 5.15 acknowledgment issue: 'Async error occurred: javax.jms.JMSException: Unmatched acknowledge - Could not find Message-ID in dispatched-list start of ack'

2018-01-17 Thread pablo1a 
Hi all,

We are experiencing a recurring message acknowledgment issue in the form of: 

/ <> <> <>
<1516176117355>  javax.jms.JMSException: Unmatched acknowledge*: MessageAck {commandId =
17, responseRequired = false, ackType = 2, consumerId =
ID:c27791-62893-1516176115418-1:1:2:1, firstMessageId =
ID:c27791-62370-1516175410475-1:1:1:1:1, lastMessageId =
ID:c27791-62439-1516175599485-1:1:1:24:1, destination =
queue://Consumer.core.VirtualTopic.FotowebEvents, transactionId =
XID:[48801,globalId=035763fff035ffb7ffee4d52,branchId=7765626c6f6769632e656a622e636f6e7461696e65722e4a4d53436f6e6e656374696f6e506f6c6c65722e466f746f776562496d6167654576656e74cffc7ffc9ffa4],
messageCount = 2, poisonCause = null}; *Could not find Message-ID
ID:c27791-62370-1516175410475-1:1:1:1:1 in dispatched-list (start of ack)*>
/

What I see occuring in the broker's log is a two 'Acknowledging message for
...' lines occurring only one second apart, for this referenced message ID
/c27791-62370-1516175410475-1:1:1:1:1/. So while the first acknowledging
step/call has already dequeued/acked the message, the second, superfluous
call doesn't find the message anymore thus causing the error.

Questions:
- Am i right to issume this is erronous behavior *on the client side*, in
calling the ack twice?
- What client configuration or setting(s) might be erroneous here?
- Any other thought for troubleshooting? I have Googled quite a bit and
applied 'jms.prefetchPolicy.queuePrefetch=1' on the broker URl, but to no
avail yet. 

Context:
- Consumer is an MDB deployed in weblogic JEE server, set up to use ActiveMQ
5.15 client libs.
- XA transaction-based acknowledgement is used.
- Broker is a ActiveMQ 5.15 broker instance deployed in another weblogic
server (packaged within war).

Thank you in advance,

Patrick

Broker's log example, red lines mark identical Ack calls happening within
second from one another:

 


 





--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html