[ https://issues.apache.org/jira/browse/AMQ-7229?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
JJ updated AMQ-7229: -------------------- Component/s: activemq-camel > JmsConnector handling loss of connection [ActiveMQConnection > {id=ID:xs-38677-1560088234347-2:100,clientId=ID:xs.test.int-38677-1560088234347-1:100,started=true}] > | org.apache.activemq.network.jms.JmsConnector | ActiveMQ Session Task-8514 > --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- > > Key: AMQ-7229 > URL: https://issues.apache.org/jira/browse/AMQ-7229 > Project: ActiveMQ > Issue Type: Bug > Components: activemq-camel, Broker, Connector, JMS client > Affects Versions: 5.15.8, 5.15.9 > Environment: CentOS 6 & 7 > Default JARS > Reporter: JJ > Priority: Blocker > Labels: beginner, newbie > > Periodically I am getting the following logged to my production and dev AMQ > instances; > {code:java} > JmsConnector handling loss of connection [ActiveMQConnection > {id=ID:server-38677-1560088234347-2:100,clientId=ID:xs.test.int-38677-1560088234347-1:100,started=true}]| > org.apache.activemq.network.jms.JmsConnector| ActiveMQ Session Task-8514 > {code} > This come at random times from two separate servers on separate networks > (connecting to a common upstream provider) These errors ALWAYS come in groups > of 11, with the time spanning 11 sec - both servers see the same error at the > same time (Indicating something at the far end maybe?) > When I check the connection count in a JMX console it has increased by 11, > with none of the old connections seeming to close or get cleaned up. > System config: > JMS-JMS Bridge with embedded broker bridging topics from a remote server to > local server. Local clients connect with nio+stomp and all have persistent > subscriptions to topics. > The remote connection is openwire. > When this error occurs it leads to a corrupted message which then causes the > DB store to grow until an OOM error occurs and AMQ stops processing. The only > way to resolve the issue is to stop all the connected clients and clear there > subscriptions and then reconnect. > I have done wireshark on a dev broker but can't see anything *obvious* though > wireshark doesn't like to dissect openwire so I can't see what's actually > going on. > This error sometimes occurs days apart, or like today multiple times a day. > The only reference I see in the [source code is line > 496|https://github.com/apache/activemq/blob/master/activemq-broker/src/main/java/org/apache/activemq/network/jms/JmsConnector.java] > > The error logged in debug is: > {code:java} > 2019-04-02 19:29:20,360 | TRACE | ID:xs-39837-1553964750839-4:140:2 sending > message: ActiveMQTextMessage {commandId = 3319310, responseRequired = false, > mes > sageId = ID:xs-39837-1553964750839-4:140:2:1:1, originalDestination = null, > originalTransactionId = null, producerId = > ID:xs-39837-1553964750839-4:140:2:1, > destination = topic://TD_ALL, transactionId = null, expiration = 0, > timestamp = 1554229760360, arrival = 0, brokerInTime = 1554229755115, > brokerOutTime = 15 > 54229755118, correlationId = null, replyTo = null, persistent = true, type = > null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = > null, > compressed = true, userID = null, content = > org.apache.activemq.util.ByteSequence@2a02b7e9, marshalledProperties = > org.apache.activemq.util.ByteSequence@7d > db0ca1, dataStructure = null, redeliveryCounter = 0, size = 0, properties = > null, readOnlyProperties = true, readOnlyBody = true, droppable = false, > jmsXGroupFirstForConsumer = false, text = > \\\{"SF_MSG":{"time":"1554229754000","area_id":...r":"2W58"}}} | > org.apache.activemq.ActiveMQSession | ActiveMQ Session Task-4447 > 2019-04-02 19:29:20,360 | TRACE | Running task iteration 0 - > vm://xs.test.int#279 | org.apache.activemq.thread.PooledTaskRunner | ActiveMQ > VMTransport: vm://xs.test.int#279-1 > 2019-04-02 19:29:20,400 | DEBUG | Error occured while processing sync > command: ActiveMQTextMessage {commandId = 7, responseRequired = true, > messageId = ID:xs-39837-1553964750839-4:140:2:1:1, originalDestination = > null, originalTransactionId = null, producerId = > ID:xs-39837-1553964750839-4:140:2:1, destination = topic://TD_ALL, > transactionId = null, expiration = 0, timestamp = 1554229760360, arrival = 0, > brokerInTime = 1554229760361, brokerOutTime = 1554229755118, correlationId = > null, replyTo = null, persistent = true, type = null, priority = 4, groupID = > null, groupSequence = 0, targetConsumerId = null, compressed = true, userID = > null, content = org.apache.activemq.util.ByteSequence@2a02b7e9, > marshalledProperties = org.apache.activemq.util.ByteSequence@7ddb0ca1, > dataStructure = null, redeliveryCounter = 0, size = 1595, properties = null, > readOnlyProperties = true, readOnlyBody = true, droppable = false, > jmsXGroupFirstForConsumer = false, text = > \\{"SF_MSG":{"time":"1554229754000","area_id":...r":"2W58"}}}, exception: > java.io.EOFException | org.apache.activemq.broker.TransportConnection.Service > | ActiveMQ VMTransport: vm://xs.test.int#279-1 > java.io.EOFException > at > java.io.DataInputStream.readUnsignedShort(DataInputStream.java:340)[:1.8.0_201] > at > java.io.DataInputStream.readUTF(DataInputStream.java:589)[:1.8.0_201] > at > java.io.DataInputStream.readUTF(DataInputStream.java:564)[:1.8.0_201] > at > org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap(MarshallingSupport.java:97)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap(MarshallingSupport.java:78)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap(MarshallingSupport.java:70)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.command.Message.unmarsallProperties(Message.java:252)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.command.Message.getProperty(Message.java:202)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.policy.RetainedMessageSubscriptionRecoveryPolicy.add(RetainedMessageSubscriptionRecoveryPolicy.java:53)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.Topic.dispatch(Topic.java:756)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:556)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.Topic.send(Topic.java:484)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.DestinationFilter.send(DestinationFilter.java:138)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:508)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:459)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:293)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.security.AuthorizationBroker.send(AuthorizationBroker.java:226)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:578)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:336)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:275)[activemq-broker-5.15.9.jar:5.15.9] > at > org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)[activemq-client-5.15.9.jar:5.15.9] > at > org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)[activemq-client-5.15.9.jar:5.15.9] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_201] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_201] > at java.lang.Thread.run(Thread.java:748)[:1.8.0_201]{code} > > If I front the connection to the upstream server by using camel - I get the > error below which matches up with the error above.. I am currently running > camel in full debug to hopefully catch another event. I'm unsure if using the > camel configuration will stop the eventual OOM conditrion as seen above but I > will try and configure a test client later to watch. > {code:java} > 2019-06-15 19:28:23,855 | WARN | Execution of JMS message listener failed. > Caused by: [org.apache.camel.RuntimeCamelException - javax.jms.JMSException: > java.io.EOFException] | > org.apache.camel.component.jms.EndpointMessageListener | Camel (Piper_Bravo) > thread #1 - JmsConsumer[TD_ALL_SIG_AREA] > org.apache.camel.RuntimeCamelException: javax.jms.JMSException: > java.io.EOFException > at > org.apache.camel.component.jms.JmsBinding.extractHeadersFromJms(JmsBinding.java:209)[camel-jms-2.23.0.jar:2.23.0] > at > org.apache.camel.component.jms.JmsMessage.populateInitialHeaders(JmsMessage.java:235)[camel-jms-2.23.0.jar:2.23.0] > at > org.apache.camel.impl.DefaultMessage.createHeaders(DefaultMessage.java:258)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.component.jms.JmsMessage.ensureInitialHeaders(JmsMessage.java:220)[camel-jms-2.23.0.jar:2.23.0] > at > org.apache.camel.component.jms.JmsMessage.getHeader(JmsMessage.java:170)[camel-jms-2.23.0.jar:2.23.0] > at > org.apache.camel.impl.DefaultMessage.getHeader(DefaultMessage.java:94)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.impl.DefaultUnitOfWork.<init>(DefaultUnitOfWork.java:115)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.impl.DefaultUnitOfWork.<init>(DefaultUnitOfWork.java:75)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.impl.DefaultUnitOfWorkFactory.createUnitOfWork(DefaultUnitOfWorkFactory.java:34)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.createUnitOfWork(CamelInternalProcessor.java:695)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.before(CamelInternalProcessor.java:663)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.processor.CamelInternalProcessor$UnitOfWorkProcessorAdvice.before(CamelInternalProcessor.java:634)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.processor.CamelInternalProcessor.process(CamelInternalProcessor.java:149)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:97)[camel-core-2.23.0.jar:2.23.0] > at > org.apache.camel.component.jms.EndpointMessageListener.onMessage(EndpointMessageListener.java:113)[camel-jms-2.23.0.jar:2.23.0] > at > org.springframework.jms.listener.AbstractMessageListenerContainer.doInvokeListener(AbstractMessageListenerContainer.java:719)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.AbstractMessageListenerContainer.invokeListener(AbstractMessageListenerContainer.java:679)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.AbstractMessageListenerContainer.doExecuteListener(AbstractMessageListenerContainer.java:649)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:317)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:255)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1168)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1160)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1057)[spring-jms-4.3.18.RELEASE.jar:4.3.18.RELEASE] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_212] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_212] > at java.lang.Thread.run(Thread.java:748)[:1.8.0_212]{code} -- This message was sent by Atlassian JIRA (v7.6.3#76005)