Jean-Yves Nicolas created AMQ-7359:
--------------------------------------
Summary: ConcurrentModificationException on client side followed
by high memory consumption on server side
Key: AMQ-7359
URL: https://issues.apache.org/jira/browse/AMQ-7359
Project: ActiveMQ
Issue Type: Bug
Affects Versions: 5.15.3
Environment: OS: Red Hat Enterprise Linux Server release 7.6 (Maipo)
ActiveMQ standalone version 5.15.3
Producer: J2EE application running on JBoss EAP 7.1
Reporter: Jean-Yves Nicolas
Attachments: image-2019-12-06-15-44-40-467.png
Hello,
On our production environment, we use a standalone instance of activemq 5.15.3.
We observed after a while that the heap consumption increases. We took a memory
dump to help us to find the cause of the problem.
We saw that one of the queue uses lot of memory. The memory is used by the
attribute pendingCachedIds (LinkedList) that contains for the example bellow
1014378 items. We compare this list with other queue. The pendingCachedIds
attribute is empty for other queue.
See here a screenshot from MAT:
!image-2019-12-06-15-44-40-467.png!
We then inspected the first element of the list. The futureOrSequenceLong
attribute of this first item allow us to inspect (at least partially) the xml
message that was produced and we identify the date of production, as well as
the message identifier. Note that the class name of the futureOrSequenceLong
attribute is
org.apache.activemq.store.kahadb.KahaDBStore$StoreQueueTask$InnerFutureTask for
the first Item, but it is java.lang.Long for subsequent items.
Having identify the business message and the get the time when this message was
produced, we inspect both logs of activemq itself and the producer client
application (J2EE application running in a JBoss EAP).
We did not see any unusual log in activemq server. We can see the
sending/preprocess/postproccess/ack events.
On producer side, we can see the folllowing stacktrace:
{code:java}
Caused by: java.lang.RuntimeException: javax.jms.JMSException :
java.util.concurrent.ExecutionException:
java.util.ConcurrentModificationException
at
org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:54)
at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1399)
at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1428)
at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1323)
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1974)
at
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:288)
at
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:223)
at
org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241)
...
Caused by: java.lang.Exception: java.lang.Throwable :
java.util.concurrent.ExecutionException:
java.util.ConcurrentModificationException
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at org.apache.activemq.broker.region.Queue.doMessageSend(Queue.java:881)
at org.apache.activemq.broker.region.Queue.send(Queue.java:743)
at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:505)
at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:459)
at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:293)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)
at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)
at
org.apache.activemq.broker.util.LoggingBrokerPlugin.send(LoggingBrokerPlugin.java:275)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)
at
org.apache.activemq.broker.util.TimeStampingBrokerPlugin.send(TimeStampingBrokerPlugin.java:131)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)
at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:572)
at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:330)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:194)
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.SslTransport.doConsume(SslTransport.java:108)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.Exception: java.util.ConcurrentModificationException
at java.util.HashMap$HashIterator.nextNode(HashMap.java:1442)
at java.util.HashMap$KeyIterator.next(HashMap.java:1466)
at
org.apache.activemq.util.MarshallingSupport.marshalPrimitiveMap(MarshallingSupport.java:61)
at org.apache.activemq.command.Message.beforeMarshall(Message.java:261)
at
org.apache.activemq.command.ActiveMQTextMessage.beforeMarshall(ActiveMQTextMessage.java:120)
at
org.apache.activemq.openwire.v11.MessageMarshaller.looseMarshal(MessageMarshaller.java:281)
at
org.apache.activemq.openwire.v11.ActiveMQMessageMarshaller.looseMarshal(ActiveMQMessageMarshaller.java:111)
at
org.apache.activemq.openwire.v11.ActiveMQTextMessageMarshaller.looseMarshal(ActiveMQTextMessageMarshaller.java:111)
at org.apache.activemq.openwire.OpenWireFormat.marshal(OpenWireFormat.java:162)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.addMessage(KahaDBStore.java:453)
at
org.apache.activemq.store.kahadb.KahaDBStore$StoreQueueTask.run(KahaDBStore.java:1428)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624){code}
It's interesting to know that on consumer side, the message was well processed
(not business inconsistency).
Our activemq instance uses persistence with a quite basic configuration:
{code:java}
<persistenceAdapter>
<kahaDB directory="/nfs/amq-data"/>
</persistenceAdapter>{code}
Producers and consumers use this transport connector:
{noformat}
<transportConnector name="openwire"
uri="ssl://0.0.0.0:61616?needClientAuth=true"/>{noformat}
We have several interrogations:
* Why the ConcurrentModificationException is raised?
** What are those modifications that can be triggered simultaneously?
* Why, after this exception, the size of pendingCachedIds grows?
* Is there any way, as workaround, to clean the pendingCachedIds without
stopping ActiveMQ
** Our current workaround is to restart the ActiveMQ
About the items in this pendingCachedIds, we can tell that:
* The first element is not the first element ever enqueued in the queue. We
are sure that before the raise of the ConcurrentModificationException, the size
of the list is limited. We did a memory dump of the ActiveMQ a couple of days
after a restart to validate this assumption.
* After a quick math, the size of the pendingCachedIds list seems to be the
equal to the number of messages produced since the raise of the exception.
Thanks a lot for your help
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
