Jerrold Stoy created AMQ-9070:
---------------------------------
Summary: Async error occurred
Key: AMQ-9070
URL: https://issues.apache.org/jira/browse/AMQ-9070
Project: ActiveMQ
Issue Type: Bug
Components: Broker
Affects Versions: 5.16.3
Environment: Enviroment: Red Hat Linux 8.2
Version of ActiveMQ: 5.16.3
Java Version: openJDK version "11.0.7" 2020-04-14 LTS
Reporter: Jerrold Stoy
I have a broker on a host that I call the app-server. The broker client is on
a host called app-client.
The server and client communcate between two queues. The client sends request
to the REQUEST queue and the server responds back to the client on a RESPONSE
queue.
On the queue Producer the deliveryMode is set to NON_PERSISTENT, and the
timeToLive is set for about a minutes.
The client connects to the broker using the url:
"failover:(tcp://44.42.3.220:40220)?maxCacheSixe=xxx&trackMessages=true"
this is deal with machines coming up in any order. I also have disabled the
Jetty Admin console as per RedHat Bug [1061847|tel:1061847]
[https://bugzilla.redhat.com/show_bug.cgi?id=1061847]
We have a system test that during the test it shuts down the network interface
and later restarts the network interface. The test is trying to mimic a brief
network outage. Occassionally when the test is run I see the following in
broker log file:
2022-08-31 20:08:27,299 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-33483-1661976507140-0:1) is starting |
org.apache.activemq.broker.BrokerService | main
2022-08-31 20:08:27,659 | INFO | Listening for connections at:
tcp://44.42.3.1:40220?maximumConnections=1000&wireFormat.maxFrameSize=104857600
| org.apache.activemq.transport.TransportServerThreadSupport | main
2022-08-31 20:08:27,674 | INFO | Connector tcp40220 started |
org.apache.activemq.broker.TransportConnector | main
2022-08-31 20:08:27,675 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-33483-1661976507140-0:1) started |
org.apache.activemq.broker.BrokerService | main
2022-08-31 20:08:27,676 | INFO | For help or more information please see:
[http://activemq.apache.org|http://activemq.apache.org/] |
org.apache.activemq.broker.BrokerService | main
2022-08-31 20:12:51,237 | WARN | Async error occurred |
org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport:
tcp:///44.42.3.220:44224@40220
javax.jms.JMSException: Could not correlate acknowledgment with dispatched
message: MessageAck \{commandId = 23, responseRequired = false, ackType = 1,
consumerId = ID:app-client-38581-1661976570805-1:1:1:1, firstMessageId =
ID:app-server-41559-1661976536817-1:1:1:1:17, lastMessageId =
ID:app-server-41559-1661976536817-1:1:1:1:17, destination = queue://RESPONSE,
transactionId = null, messageCount = 1, poisonCause = java.lang.Throwable:
Suppressing duplicate delivery on connection, consumer
ID:app-client-38581-1661976570805-1:1:1:1}
at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:381)
at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:534)
at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:493)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89)
at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:278)
at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:89)
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:50)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:301)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
at java.base/java.lang.Thread.run(Thread.java:834)
2022-08-31 20:14:52,946 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-33483-1661976507140-0:1) is shutting down |
org.apache.activemq.broker.BrokerService | ActiveMQ ShutdownHook
2022-08-31 20:14:53,080 | INFO | Connector tcp40220 stopped |
org.apache.activemq.broker.TransportConnector | ActiveMQ ShutdownHook
2022-08-31 20:14:53,113 | INFO |
PListStore:[/opt/app/brokers/broker_220/data/localhost/tmp_storage] stopped |
org.apache.activemq.store.kahadb.plist.PListStoreImpl | ActiveMQ ShutdownHook
2022-08-31 20:14:53,114 | INFO | Stopping async queue tasks |
org.apache.activemq.store.kahadb.KahaDBStore | ActiveMQ ShutdownHook
2022-08-31 20:14:53,114 | INFO | Stopping async topic tasks |
org.apache.activemq.store.kahadb.KahaDBStore | ActiveMQ ShutdownHook
2022-08-31 20:14:53,116 | INFO | Stopped KahaDB |
org.apache.activemq.store.kahadb.KahaDBStore | ActiveMQ ShutdownHook
2022-08-31 20:14:53,132 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-33483-1661976507140-0:1) uptime 6 minutes |
org.apache.activemq.broker.BrokerService | ActiveMQ ShutdownHook
2022-08-31 20:14:53,133 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-33483-1661976507140-0:1) is shutdown |
org.apache.activemq.broker.BrokerService | ActiveMQ ShutdownHook
2022-08-31 20:14:53,135 | INFO | Closing
[org.apache.activemq.xbean.XBeanBrokerFactory$1@74a10858|mailto:org.apache.activemq.xbean.XBeanBrokerFactory$1@74a10858]:
startup date [Wed Aug 31 20:08:21 UTC 2022]; root of context hierarchy |
org.apache.activemq.xbean.XBeanBrokerFactory$1 | ActiveMQ ShutdownHook
2022-08-31 20:16:17,471 | INFO | Refreshing
[org.apache.activemq.xbean.XBeanBrokerFactory$1@74a10858|mailto:org.apache.activemq.xbean.XBeanBrokerFactory$1@74a10858]:
startup date [Wed Aug 31 20:16:17 UTC 2022]; root of context hierarchy |
org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
2022-08-31 20:16:21,367 | INFO | Using Persistence Adapter:
KahaDBPersistenceAdapter[/opt/app/brokers/broker_220/data/kahadb] |
org.apache.activemq.broker.BrokerService | main
2022-08-31 20:16:21,725 | INFO | KahaDB is version 7 |
org.apache.activemq.store.kahadb.MessageDatabase | main
2022-08-31 20:16:21,792 | INFO |
PListStore:[/opt/app/brokers/broker_220/data/localhost/tmp_storage] started |
org.apache.activemq.store.kahadb.plist.PListStoreImpl | main
2022-08-31 20:16:22,119 | INFO | Apache ActiveMQ 5.16.3 (localhost,
ID:app-server-38759-1661976981932-0:1) is starting |
org.apache.activemq.broker.BrokerService | main
2022-08-31 20:16:22,315 | INFO | Listening for connections at:
tcp://44.42.3.1:40220?maximumConnections=1000&wireFormat.maxFrameSize=104857600
| org.apache.activemq.transport.TransportServerThreadSupport | main
2022-08-31 20:16:22,338 | INFO | Connector tcp40220 started |
org.apache.activemq.broker.TransportConnector | main
On the client side I am seeing the following message logged:
2022-08-31T20:12:51.262000+00:00 WARNING JMSHelper onException The broker
connection is broken, and has thrown the following exception:
javax.jms.JMSException: Could not correlate acknowledgment with dispatched
message: MessageAck \{commandId = 23, responseRequired = false, ackType = 1,
consumerId = ID:app-client-38581-1661976570805-1:1:1:1, firstMessageId =
ID:app-server-41559-1661976536817-1:1:1:1:17, lastMessageId =
ID:app-server-41559-1661976536817-1:1:1:1:17, destination = queue://RESPONSE,
transactionId = null, messageCount = 1, poisonCause = java.lang.Throwable:
Suppressing duplicate delivery on connection, consumer
ID:app-client-38581-1661976570805-1:1:1:1}
Would anything in my configuration be causing the error that occurs at
2022-08-31 20:12:51,237 | WARN | Async error occurred |
org.apache.activemq.broker.TransportConnection.Service | ActiveMQ Transport:
tcp:///44.42.3.220:44224@40220. Is there anything that I can do to prevent the
error from occurring?
I have found similar posts on the web - but have not seen any explanation or
solutions.
Any help would be greatly appreciated.
# Stoy
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
