Дамп ActiveMQ Artemis Thread - PullRequest
       99

Дамп ActiveMQ Artemis Thread

1 голос
/ 13 июля 2020

У меня проблема с ActiveMQ Artemis версии 2.10.0, работающей на docker. Это как раз проблема с потоками (логи ниже). В какой-то момент в журналах я вижу эту запись:

Component org.apache.activemq.artemis.core.io.buffer.TimedBuffer is expired on path 0

После этого есть запись, о которой объявленный процесс брокера будет убит:

AMQ224079: The process for the virtual machine will be killed, as component org.apache.activemq.artemis.core.io.buffer.TimedBuffer@51b01960 is not responsive

Позже есть серия записей с идентификатором процесса потока, поскольку id = 2, на идентификатор потока 200 (т.е. на значение, которое установлено переменной thread-pool-max-size =200 scheduled-thread-pool-max-size= 20, как описано в документах ).

На Веб-сайт Artemis Я обнаружил, что брокер можно отключить, если он находится в нестабильном состоянии.

Почему это произошло?

Журналы:

 WARN  [org.apache.activemq.artemis.utils.critical.CriticalMeasure] Component org.apache.activemq.artemis.core.io.buffer.TimedBuffer is expired on path 0
 ERROR [org.apache.activemq.artemis.core.server] AMQ224079: The process for the virtual machine will be killed, as component org.apache.activemq.artemis.core.io.buffer.TimedBuffer@51b01960 is not responsive
 WARN  [org.apache.activemq.artemis.core.server] AMQ222199: Thread dump: *******************************************************************************
Complete Thread dump
"Reference Handler" Id=2 RUNNABLE
        at java.base@11.0.5/java.lang.ref.Reference.waitForReferencePendingList(Native Method)
        at java.base@11.0.5/java.lang.ref.Reference.processPendingReferences(Reference.java:241)
        at java.base@11.0.5/java.lang.ref.Reference$ReferenceHandler.run(Reference.java:213)


"Finalizer" Id=3 WAITING on java.lang.ref.ReferenceQueue$Lock@1d3b0b50
        at java.base@11.0.5/java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.ReferenceQueue$Lock@1d3b0b50
        at java.base@11.0.5/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
        at java.base@11.0.5/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176)
        at java.base@11.0.5/java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:170)


"Signal Dispatcher" Id=4 RUNNABLE


"Common-Cleaner" Id=18 TIMED_WAITING on java.lang.ref.ReferenceQueue$Lock@a9de548
        at java.base@11.0.5/java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.ReferenceQueue$Lock@a9de548
        at java.base@11.0.5/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
        at java.base@11.0.5/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
        at java.base@11.0.5/java.lang.Thread.run(Thread.java:834)
        at java.base@11.0.5/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:134)


"oneagentsubpathsender 1.189.238.20200508-120527" Id=20 RUNNABLE (in native)


"oneagentperiodiceventsmanaged" Id=21 RUNNABLE (in native)


"oneagentautosensor" Id=22 RUNNABLE


"oneagentperiodicurls" Id=23 RUNNABLE (in native)


"oneagentperiodicrequests" Id=24 RUNNABLE (in native)


"ActiveMQ Artemis Server Shutdown Timer" Id=27 TIMED_WAITING on java.util.TaskQueue@3cc6ec06
        at java.base@11.0.5/java.lang.Object.wait(Native Method)
        -  waiting on java.util.TaskQueue@3cc6ec06
        at java.base@11.0.5/java.util.TimerThread.mainLoop(Timer.java:553)
        at java.base@11.0.5/java.util.TimerThread.run(Timer.java:506)

"Thread-0 (-scheduled-threads)" Id=29 RUNNABLE
        at java.management@11.0.5/sun.management.ThreadImpl.dumpThreads0(Native Method)
        at java.management@11.0.5/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:502)
        at java.management@11.0.5/sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:490)
        at org.apache.activemq.artemis.utils.ThreadDumpUtil.threadDump(ThreadDumpUtil.java:47)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.threadDump(ActiveMQServerImpl.java:1022)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.lambda$initializeCriticalAnalyzer$0(ActiveMQServerImpl.java:678)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$$Lambda$127/0x00000001002df840.run(Unknown Source)
        at org.apache.activemq.artemis.utils.critical.CriticalAnalyzerImpl.fireAction(CriticalAnalyzerImpl.java:155)
        at org.apache.activemq.artemis.utils.critical.CriticalAnalyzerImpl.check(CriticalAnalyzerImpl.java:140)
        at org.apache.activemq.artemis.utils.critical.CriticalAnalyzerImpl$1.run(CriticalAnalyzerImpl.java:53)
        at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$2.run(ActiveMQScheduledComponent.java:284)
        at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$3.run(ActiveMQScheduledComponent.java:294)
        at java.base@11.0.5/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base@11.0.5/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
        at java.base@11.0.5/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)

        Number of locked synchronizers = 1
        - java.util.concurrent.ThreadPoolExecutor$Worker@1b58ff9e


"Thread-0 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@466cf502)" Id=35 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@350d7400
        at java.base@11.0.5/jdk.internal.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@350d7400
        at java.base@11.0.5/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
        at java.base@11.0.5/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
        at org.apache.activemq.artemis.utils.ActiveMQThreadPoolExecutor$ThreadPoolQueue.poll(ActiveMQThreadPoolExecutor.java:112)
        at org.apache.activemq.artemis.utils.ActiveMQThreadPoolExecutor$ThreadPoolQueue.poll(ActiveMQThreadPoolExecutor.java:45)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1053)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)



"Thread-0 (activemq-netty-threads)" Id=112 WAITING on java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync@50ab59d6
        at java.base@11.0.5/jdk.internal.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync@50ab59d6
        at java.base@11.0.5/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:885)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:917)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1240)
        at java.base@11.0.5/java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:959)
        at org.apache.activemq.artemis.core.paging.impl.PagingStoreImpl.page(PagingStoreImpl.java:835)
        at org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.addToPage(AbstractJournalStorageManager.java:2074)
        at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1308)
        at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1003)
        at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:894)
        at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:2073)
        -  locked org.apache.activemq.artemis.core.server.impl.ServerSessionImpl@7805129
        at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1712)
        -  locked org.apache.activemq.artemis.core.server.impl.ServerSessionImpl@7805129
        at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1651)
        -  locked org.apache.activemq.artemis.core.server.impl.ServerSessionImpl@7805129
        at org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1643)
        at org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.lambda$sendShouldBlockProducer$0(AMQSession.java:453)
        at org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession$$Lambda$274/0x0000000100597840.run(Unknown Source)
        at org.apache.activemq.artemis.core.paging.impl.PagingStoreImpl.checkMemory(PagingStoreImpl.java:728)
        at org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.sendShouldBlockProducer(AMQSession.java:504)
        at org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.send(AMQSession.java:415)
        at org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1570)
        at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)
        at org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.bufferReceived(OpenWireConnection.java:293)
        at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:654)
        at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323)
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:337)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1408)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:359)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:345)
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:930)
        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:796)
        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:427)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:328)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905)
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)


"Thread-29 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@466cf502)" Id=200 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@350d7400
        at java.base@11.0.5/jdk.internal.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@350d7400
        at java.base@11.0.5/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
        at java.base@11.0.5/java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:458)
        at org.apache.activemq.artemis.utils.ActiveMQThreadPoolExecutor$ThreadPoolQueue.poll(ActiveMQThreadPoolExecutor.java:112)
        at org.apache.activemq.artemis.utils.ActiveMQThreadPoolExecutor$ThreadPoolQueue.poll(ActiveMQThreadPoolExecutor.java:45)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1053)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)


"Scheduler-143999341" Id=202 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@2a25f629
        at java.base@11.0.5/jdk.internal.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@2a25f629
        at java.base@11.0.5/java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
        at java.base@11.0.5/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
        at java.base@11.0.5/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1170)
        at java.base@11.0.5/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
        at java.base@11.0.5/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base@11.0.5/java.lang.Thread.run(Thread.java:834)


"Thread-1 (activemq-netty-threads)" Id=2344 RUNNABLE (in native)
        at io.netty.channel.epoll.Native.epollWait0(Native Method)
        at io.netty.channel.epoll.Native.epollWait(Native.java:114)
        at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:251)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:276)
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905)
        at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)

1 Ответ

1 голос
/ 13 июля 2020

Эта проблема, насколько я могу судить, на самом деле не имеет ничего общего с потоками. Проблема заключается в том, как указано в сообщении об ошибке, что «TimedBuffer истек на пути 0» или, другими словами, «TimedBuffer@51b01960 не отвечает». «TimedBuffer» - это компонент, который отвечает за сброс данных на диск, и это занимает слишком много времени для передачи sh данных, поэтому «критический анализатор» брокера завершает работу брокера и генерирует дамп потока для целей отладки.

«Критический анализатор» - это служба посредника, которая отслеживает важные задачи, и если выполнение этих задач занимает слишком много времени, критический анализатор примет меры. По умолчанию broker.xml содержит следующую конфигурацию для критического анализатора:

<critical-analyzer>true</critical-analyzer>
<critical-analyzer-timeout>120000</critical-analyzer-timeout>
<critical-analyzer-check-period>60000</critical-analyzer-check-period>
<critical-analyzer-policy>HALT</critical-analyzer-policy>

Следовательно, каждые 60 секунд критический анализатор будет проверять различные компоненты, и если какой-либо из них остановился на 120 секунд (т.е. 2 минуты), тогда это остановит брокера. Подробнее о критическом анализаторе вы можете прочитать в документации .

...