[ https://issues.apache.org/jira/browse/AMQ-9070?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jean-Baptiste Onofré updated AMQ-9070: -------------------------------------- Fix Version/s: 5.19.0 5.18.3 (was: 5.18.2) > 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 > Assignee: Jean-Baptiste Onofré > Priority: Major > Fix For: 5.19.0, 5.17.5, 5.18.3 > > > 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)