[jira] [Commented] (ARTEMIS-3504) AMQ224080: The server process will now be stopped, as component JournalStorageManage is not responsive

["Justin Bertram (Jira)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/ARTEMIS-3504?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17462971#comment-17462971 ] 

Justin Bertram commented on ARTEMIS-3504:
-----------------------------------------

[~hurschler], I recommend you upgrade to 2.20.0 when it is available for download. It just [passed the release vote|https://lists.apache.org/thread/sx1n84379nf9lbbl189cx6y947gso7hj] so it should be available in a few days. It has a fix for ARTEMIS-3587 which may be causing the critical analyzer to malfunction.

However, the critical analyzer is not involved in the problem from your most recent comment. The broker is shutting down due to a _critical_ error as noted in this message:

{noformat}
AMQ222010: Critical IO Error, shutting down the server. file=NULL, message=unable to open : java.io.IOException: Cannot initialize file{noformat}

The root cause for this error is that the broker cannot initialize a new journal file in which to store incoming messages. This may be related to the earlier log message indicating you were running out of disk space:

{noformat}
AMQ222210: Free storage space is at 1.6GB of 21.5GB total. Usage rate is 92.6% which is beyond the configured <max-disk-usage>. System will start blocking producers.{noformat}

I recommend you monitor your messaging applications to ensure message consumption and production are staying essentially balanced so messages don't accumulate on the broker. It would probably also be good to make sure the broker has enough disk space to perform the functions you require.

> AMQ224080: The server process will now be stopped, as component JournalStorageManage is not responsive
> ------------------------------------------------------------------------------------------------------
>
>                 Key: ARTEMIS-3504
>                 URL: https://issues.apache.org/jira/browse/ARTEMIS-3504
>             Project: ActiveMQ Artemis
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 2.18.0
>            Reporter: André Hurschler
>            Priority: Major
>         Attachments: artemis_master-18-10-2021.log
>
>
> We get this error again at different times in a productive system
> {noformat}
> AMQ224080: The server process will now be stopped, as component org.apache.activemq.artemis.core.persistence.impl.journal.JournalStorageManager@65631036 is not responsive {noformat}
> We use the ActiveMQ Artemis Native Layer 1.0.2, Red Hat Linux, on a VMWare VM.
>  
> "Thread-1 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@6253c26)" Id=30 TIMED_WAITING on java.util.concurrent.CountDownLatch$Sync@5118bf3"Thread-1 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@6253c26)" Id=30 TIMED_WAITING on java.util.concurrent.CountDownLatch$Sync@5118bf3 at sun.misc.Unsafe.park(Native Method) -  waiting on java.util.concurrent.CountDownLatch$Sync@5118bf3 at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328) at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277) at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl$StaticConnector.connect(ServerLocatorImpl.java:1735) at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:540) -  locked org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl@616cbadb at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:528) at org.apache.activemq.artemis.core.server.cluster.ClusterController$ConnectRunnable.run(ClusterController.java:491) at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:65) at org.apache.activemq.artemis.utils.actors.ProcessorBase$$Lambda$39/389993238.run(Unknown Source) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
>  Number of locked synchronizers = 1 - java.util.concurrent.ThreadPoolExecutor$Worker@3a3e78f
> "Thread-0 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@6253c26)" Id=29 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6436d24a at sun.misc.Unsafe.park(Native Method) -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6436d24a at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) 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.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "RMI RenewClean-[fenacosrv43113.main.corp.fenaco.com:4998,javax.rmi.ssl.SslRMIClientSocketFactory@76a2ddf3]" Id=28 TIMED_WAITING on java.lang.ref.ReferenceQueue$Lock@338d9251 at java.lang.Object.wait(Native Method) -  waiting on java.lang.ref.ReferenceQueue$Lock@338d9251 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:563) at java.lang.Thread.run(Thread.java:748)
> "RMI Scheduler(0)" Id=27 TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@66bdc591 at sun.misc.Unsafe.park(Native Method) -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@66bdc591 at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
> "GC Daemon" Id=25 TIMED_WAITING on sun.misc.GC$LatencyLock@620311ff at java.lang.Object.wait(Native Method) -  waiting on sun.misc.GC$LatencyLock@620311ff at sun.misc.GC$Daemon.run(GC.java:117)
> "RMI Reaper" Id=24 WAITING on java.lang.ref.ReferenceQueue$Lock@6bc4405f at java.lang.Object.wait(Native Method) -  waiting on java.lang.ref.ReferenceQueue$Lock@6bc4405f at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) at sun.rmi.transport.ObjectTable$Reaper.run(ObjectTable.java:351) at java.lang.Thread.run(Thread.java:748)
> "RMI TCP Accept-4998" Id=23 RUNNABLE (in native) at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409) at java.net.ServerSocket.implAccept(ServerSocket.java:560) at sun.security.ssl.SSLServerSocketImpl.accept(SSLServerSocketImpl.java:199) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:405) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:377) at java.lang.Thread.run(Thread.java:748)
> "RMI TCP Accept-4999" Id=22 RUNNABLE (in native) at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409) at java.net.ServerSocket.implAccept(ServerSocket.java:560) at java.net.ServerSocket.accept(ServerSocket.java:528) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:405) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:377) at java.lang.Thread.run(Thread.java:748)
> "Thread-5 (ActiveMQ-client-netty-threads)" Id=21 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:281) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-4 (ActiveMQ-client-netty-threads)" Id=20 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:286) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-3 (ActiveMQ-client-netty-threads)" Id=19 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:281) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-2 (ActiveMQ-client-netty-threads)" Id=18 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:281) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-1 (ActiveMQ-client-netty-threads)" Id=17 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:286) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-0 (ActiveMQ-client-netty-threads)" Id=16 RUNNABLE (in native) at io.netty.channel.epoll.Native.epollWait0(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:176) at io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:281) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:351) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> "Thread-0 (-scheduled-threads)" Id=15 RUNNABLE at sun.management.ThreadImpl.dumpThreads0(Native Method) at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:496) at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:484) at org.apache.activemq.artemis.utils.ThreadDumpUtil.threadDump(ThreadDumpUtil.java:47) at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.threadDump(ActiveMQServerImpl.java:1127) at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.lambda$initializeCriticalAnalyzer$1(ActiveMQServerImpl.java:734) at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$$Lambda$37/1944702768.run(Unknown Source) at org.apache.activemq.artemis.utils.critical.CriticalAnalyzerImpl.fireActions(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.runForExecutor(ActiveMQScheduledComponent.java:313) at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.bookedRunForScheduler(ActiveMQScheduledComponent.java:328) at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.runForScheduler(ActiveMQScheduledComponent.java:339) at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent.lambda$start$0(ActiveMQScheduledComponent.java:166) at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$$Lambda$36/2102368942.run(Unknown Source) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
>  Number of locked synchronizers = 1 - java.util.concurrent.ThreadPoolExecutor$Worker@72e5a8e
> "ActiveMQ Artemis Server Shutdown Timer" Id=10 TIMED_WAITING on java.util.TaskQueue@3484586c at java.lang.Object.wait(Native Method) -  waiting on java.util.TaskQueue@3484586c at java.util.TimerThread.mainLoop(Timer.java:552) at java.util.TimerThread.run(Timer.java:505)
> "Signal Dispatcher" Id=5 RUNNABLE
> "Finalizer" Id=3 WAITING on java.lang.ref.ReferenceQueue$Lock@3c9d9220 at java.lang.Object.wait(Native Method) -  waiting on java.lang.ref.ReferenceQueue$Lock@3c9d9220 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
> "Reference Handler" Id=2 WAITING on java.lang.ref.Reference$Lock@466bf0a5 at java.lang.Object.wait(Native Method) -  waiting on java.lang.ref.Reference$Lock@466bf0a5 at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference.tryHandlePending(Reference.java:191) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
> ===============================================================================End Thread dump *******************************************************************************
>  2021-10-18 15:56:24,499 WARN  [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Server locator is closed (maybe it was garbage collected): java.lang.IllegalStateException: Server locator is closed (maybe it was garbage collected) at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.assertOpen(ServerLocatorImpl.java:1850) [artemis-core-client-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.createSessionFactory(ServerLocatorImpl.java:648) [artemis-core-client-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:549) [artemis-core-client-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.core.client.impl.ServerLocatorImpl.connect(ServerLocatorImpl.java:528) [artemis-core-client-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.core.server.cluster.ClusterController$ConnectRunnable.run(ClusterController.java:491) [artemis-server-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.18.0.jar:2.18.0] at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:65) [artemis-commons-2.18.0.jar:2.18.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_302] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_302] at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.18.0.jar:2.18.0]
>  2021-10-18 15:56:24,506 WARN  [org.apache.activemq.artemis.core.server] AMQ222061: Client connection failed, clearing up resources for session 4aa5359e-2fc0-11ec-8b13-005056a3484b2021-10-18 15:56:24,506 WARN  [org.apache.activemq.artemis.core.server] AMQ222107: Cleared up resources for session 4aa5359e-2fc0-11ec-8b13-005056a3484b2021-10-18 15:56:24,787 INFO  [io.hawt.web.auth.AuthenticationFilter] Destroying hawtio authentication filter2021-10-18 15:56:24,792 INFO  [io.hawt.HawtioContextListener] Destroying hawtio services2021-10-18 15:56:24,829 INFO  [org.apache.activemq.hawtio.plugin.PluginContextListener] Destroyed artemis-plugin plugin2021-10-18 15:56:24,842 INFO  [org.apache.activemq.hawtio.branding.PluginContextListener] Destroyed activemq-branding plugin



--
This message was sent by Atlassian Jira
(v8.20.1#820001)