[
https://issues.apache.org/jira/browse/AMQ-7229?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17134835#comment-17134835
]
JJ commented on AMQ-7229:
-------------------------
Hi Sorry - only just seen your questions.
I'm using VM transport on a single host.
A reproducible case may be a bit hard - I connect to a 3rd party who provide
bulk rail data in the UK. This issue only comes up intermittently and them and
us are at a bit of a loss. There back end is a little complex with a NoB and
camel conversions from XML to JSON and all sorts - they also still run a older
version of AMQ on there front end (5.8.0) though not much else is known about
there setup and I won't be able to get much in the way of detail.
We did some debugging between us and couldn't progress the issue any further.
Hopefully you saw my mailing list post with the examples of the messages in
both AMQ and Camel - Camel seems to ride through the issue (Though I suspect 1
batch of messages is actually lost) whereas AMQ chokes and causes the problems
detailed with persistent subscribers. We where also able to get a 3rd party to
test with my config and they didn't log any issues when I did on two separate
hosts.
I personally suspect something is getting corrupted somewhere hence the blank
message header though I'm not sure I'll find out where. The problem hasn't been
apparent in the last few months - most likely due to the low volumes of traffic
on the data feed.
When this all first started nothing had changed on my end, though I'm unsure if
anything changed upstream (and there support is not exactly great) so it was a
bit odd. If it ends up being something corrupt being passed from upstream that
would otherwise be invalid I'm happy to (presumably) drop the message as Camel
does than way it won't end up corrupting the persistence db.
At some point I will spin up a Artemis deployment and see if that fairs any
better as things start to pick-up in the UK and the data volumes go back to
normal in the next couple of months.
> 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: Broker, Camel, Connector, JMS client
> Affects Versions: 5.15.8, 5.15.9, 5.15.10
> Environment: CentOS 6 & 7
> Default JARS
> Reporter: JJ
> Assignee: Jean-Baptiste Onofré
> Priority: Blocker
> Labels: beginner, newbie
> Fix For: 5.16.1, 5.15.14
>
>
> 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
(v8.3.4#803005)
