You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Jiri Daněk (Jira)" <ji...@apache.org> on 2020/08/10 10:15:00 UTC
[jira] [Reopened] (ARTEMIS-2866) AMQ214015: Failed to execute
connection life cycle listener
[ https://issues.apache.org/jira/browse/ARTEMIS-2866?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jiri Daněk reopened ARTEMIS-2866:
---------------------------------
Reopening, because the logged NPE deserves investigation in any case.
h3. Investigation
This is a line of my code.
{code:java}
broker.configuration.addQueueConfiguration(new CoreQueueConfiguration().setAddress(someQueue));
{code}
In this, I do not call {{.setName()}} by mistake. That causes a NPE in
{code:java|title=org/apache/activemq/artemis/core/server/impl/ActiveMQServerImpl.java}
private void deployQueuesFromListQueueConfiguration(List<QueueConfiguration> queues) throws Exception {
[...]
ActiveMQServerLogger.LOGGER.deployQueue(config.getName().toString(), config.getAddress().toString(), config.getRoutingType().toString());
[...]
{code}
which is properly logged (line 16469 in Travis link above), I just did not realize it is relevant because it is far away from the final exception thrown
{noformat}
ERROR - AMQ224000: Failure in initialisation
java.lang.NullPointerException
at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.deployQueuesFromListQueueConfiguration(ActiveMQServerImpl.java:3245)
at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.deployQueuesFromConfiguration(ActiveMQServerImpl.java:3251)
at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.initialisePart2(ActiveMQServerImpl.java:3011)
at org.apache.activemq.artemis.core.server.impl.LiveOnlyActivation.run(LiveOnlyActivation.java:76)
at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.internalStart(ActiveMQServerImpl.java:603)
at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.start(ActiveMQServerImpl.java:530)
at org.apache.activemq.artemis.core.server.embedded.EmbeddedActiveMQ.start(EmbeddedActiveMQ.java:116)
at util.Broker.startBroker(Broker.java:70)
at QPIDJMS484Test.testSendDispositionsAfterRecoverForUnacknowledgedMessages(QPIDJMS484Test.java:68)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
{noformat}
and with that, the broker is not completely initialized, so while it appears to be working later in the test, it actually never run {{remotingService.start();}} in {{org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl#initialisePart2}}, which means the relevant Executor has never been initialized, and it being {{null}} is causing the exception in issue summary. I believe that this is the case because the exceptions in logs go away if I add {{setName(someQueue).setRoutingType(RoutingType.ANYCAST)}} when declaring the queue/topic.
h3. Conclusion
My lingering question is. How am I supposed to start EmbeddedActiveMQ, so that I reliably detect it failed to start? What I do currently is apparently not good enough:
{code:java}
try {
embeddedBroker.start();
} catch (Exception e) {
throw new RuntimeException("Failed to start the embedded broker", e);
}
{code}
h3. Other instances of AMQ214015 I could find
It looks like it can appear during shutdown or configuration reload of the broker.
* https://github.com/corda/corda/issues/6093 Failed to execute connection life cycle listener
* https://issues.redhat.com/browse/JBEAP-10193 java.util.concurrent.RejectedExecutionException during shutting down server with MDB
* https://next.travis-ci.org/github/apache/activemq-artemis/jobs/713675247#L5880
> AMQ214015: Failed to execute connection life cycle listener
> -----------------------------------------------------------
>
> Key: ARTEMIS-2866
> URL: https://issues.apache.org/jira/browse/ARTEMIS-2866
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: AMQP
> Affects Versions: 2.14.0
> Reporter: Jiri Daněk
> Priority: Major
>
> I've upgraded Artemis from version 2.10.1 to 2.14.0 and now I started seeing an occasional test failure in my project https://github.com/rh-messaging/cli-java.
> https://travis-ci.org/github/rh-messaging/cli-java/jobs/714822739#L17121
> {noformat}
> ERROR - AMQ214015: Failed to execute connection life cycle listener
> java.lang.NullPointerException
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.onAddedTaskIfNotRunning(ProcessorBase.java:186)
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.task(ProcessorBase.java:174)
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.execute(OrderedExecutor.java:54)
> at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.exceptionCaught(ActiveMQChannelHandler.java:106)
> at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:302)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:264)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
> at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
> at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:818)
> at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
> at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
> at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
> at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
> at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> DEBUG - Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@3c42114d[Shutting down, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1] is shutdown: true and terminated: false took: 0.000 seconds.
> DEBUG - Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@3c42114d[Shutting down, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1] is shutdown: true and terminated: false took: 0.000 seconds.
> DEBUG - Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@3c42114d[Shutting down, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1] is shutdown: true and terminated: false took: 0.000 seconds.
> DEBUG - Freed 6 thread-local buffer(s) from thread: AmqpProvider :(3):[amqp://localhost:34728]
> DEBUG - Freed 6 thread-local buffer(s) from thread: AmqpProvider :(3):[amqp://localhost:34728]
> DEBUG - Freed 6 thread-local buffer(s) from thread: AmqpProvider :(3):[amqp://localhost:34728]
> DEBUG - Stopping server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> DEBUG - Stopping server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> DEBUG - Stopping server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> DEBUG - Stopping Cluster Controller 740858526 for server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> DEBUG - Stopping Cluster Controller 740858526 for server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> DEBUG - Stopping Cluster Controller 740858526 for server ActiveMQServerImpl::serverUUID=5fc3d18c-d65e-11ea-8039-02426c35a891
> WARN - AMQ222113: On ManagementService stop, there are 1 unexpected registered MBeans: [acceptor.amqp]
> WARN - AMQ222113: On ManagementService stop, there are 1 unexpected registered MBeans: [acceptor.amqp]
> WARN - AMQ222113: On ManagementService stop, there are 1 unexpected registered MBeans: [acceptor.amqp]
> DEBUG - Stopping the lock monitor
> DEBUG - Stopping the lock monitor
> DEBUG - Stopping the lock monitor
> DEBUG - The lock monitor was already stopped
> DEBUG - The lock monitor was already stopped
> DEBUG - The lock monitor was already stopped
> DEBUG - writing status: 80
> DEBUG - writing status: 80
> DEBUG - writing status: 80
> DEBUG - trying to lock position: 0
> DEBUG - trying to lock position: 0
> DEBUG - trying to lock position: 0
> DEBUG - locked position: 0
> DEBUG - locked position: 0
> DEBUG - locked position: 0
> INFO - AMQ221002: Apache ActiveMQ Artemis Message Broker version 2.14.0 [5fc3d18c-d65e-11ea-8039-02426c35a891] stopped, uptime 2.730 seconds
> INFO - AMQ221002: Apache ActiveMQ Artemis Message Broker version 2.14.0 [5fc3d18c-d65e-11ea-8039-02426c35a891] stopped, uptime 2.730 seconds
> INFO - AMQ221002: Apache ActiveMQ Artemis Message Broker version 2.14.0 [5fc3d18c-d65e-11ea-8039-02426c35a891] stopped, uptime 2.730 seconds
> [ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 2.739 s <<< FAILURE! - in QPIDJMS484Test
> [ERROR] testSendDispositionsAfterRecoverForUnacknowledgedMessages{Broker, Path} Time elapsed: 2.739 s <<< FAILURE!
> com.google.common.truth.AssertionErrorWithFacts: expected not to be: null
> at QPIDJMS484Test.testSendDispositionsAfterRecoverForUnacknowledgedMessages(QPIDJMS484Test.java:94)
> {noformat}
> I will investigate when this started to appear and I will add more details here.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)