You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Justin Bertram (Jira)" <ji...@apache.org> on 2022/02/05 22:14:00 UTC
[jira] [Resolved] (ARTEMIS-2733) Stopping broker while there are pending address auto-deletes produces many ERROR messages on shut down
[ https://issues.apache.org/jira/browse/ARTEMIS-2733?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Justin Bertram resolved ARTEMIS-2733.
-------------------------------------
Fix Version/s: 2.13.0
Resolution: Fixed
Fixed via ARTEMIS-2760.
> Stopping broker while there are pending address auto-deletes produces many ERROR messages on shut down
> ------------------------------------------------------------------------------------------------------
>
> Key: ARTEMIS-2733
> URL: https://issues.apache.org/jira/browse/ARTEMIS-2733
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: Broker
> Affects Versions: 2.11.0
> Reporter: Jiri Daněk
> Priority: Minor
> Fix For: 2.13.0
>
>
> Start broker with default configuration, with user admin/admin, and the following changes applied, using {{artemis run}} in the terminal.
> {code:bash}
> diff --git a/artemis.profile b/artemis.profile
> index 140db52..62857b7 100644
> --- a/artemis.profile
> +++ b/artemis.profile
> @@ -34,6 +34,10 @@ ARTEMIS_INSTANCE_ETC_URI='file:/home/jdanek/Downloads/AMQ7/apache-artemis-2.11.0
> # Java Opts
> JAVA_ARGS=" -XX:+PrintClassHistogram -XX:+UseG1GC -Xms512M -Xmx2G -Dhawtio.realm=activemq -Dhawtio.offline=true -Dhawtio.role=amq -Dhawtio.rolePrincipalClasses=org.apache.activemq.artemis.spi.core.security.jaas.RolePrincipal -Djolokia.policyLocation=${ARTEMIS_INSTANCE_ETC_URI}jolokia-access.xml"
>
> +JAVA_ARGS+=" -Dcom.sun.management.jmxremote=true -Dcom.sun.management.jmxremote.port=1099 -Dcom.sun.management.jmxremote.rmi.port=1099 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false"
> +
> +
> +
> #
> # Logs Safepoints JVM pauses: Uncomment to enable them
> # In addition to the traditional GC logs you could enable some JVM flags to know any meaningful and "hidden" pause that could
> diff --git a/broker.xml b/broker.xml
> index 66d3f1d..0b9cdb4 100644
> --- a/broker.xml
> +++ b/broker.xml
> @@ -106,7 +106,7 @@ under the License.
>
> <!-- once the disk hits this limit the system will block, or close the connection in certain protocols
> that won't support flow control. -->
> - <max-disk-usage>90</max-disk-usage>
> + <max-disk-usage>100</max-disk-usage>
>
> <!-- should the broker detect dead locks and other issues -->
> <critical-analyzer>true</critical-analyzer>
> {code}
> Start the attached code which creates and deletes MULTICAST queues on the broker. When it reaches queue number 2000 or so, stop the broker with Ctrl+c. It should take about 5 minutes to reach queue number 2000.
> Observe many errors of the following kind printed
> {noformat}
> 2020-04-22 16:08:00,486 ERROR [org.apache.activemq.artemis.core.server] AMQ224065: Failed to remove auto-created queue feasdft775.p: ActiveMQShutdownException[errorType=SHUTDOWN_ERROR message=Journal must be in state=LOADED, was [STOPPED]]
> at org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkJournalIsLoaded(JournalImpl.java:1087) [artemis-journal-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendDeleteRecordTransactional(JournalImpl.java:1160) [artemis-journal-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.journal.impl.JournalBase.appendDeleteRecordTransactional(JournalBase.java:98) [artemis-journal-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendDeleteRecordTransactional(JournalImpl.java:93) [artemis-journal-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.deleteAddressBinding(AbstractJournalStorageManager.java:1396) [artemis-server-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.removeAddressInfo(ActiveMQServerImpl.java:3312) [artemis-server-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.removeAddressInfo(ActiveMQServerImpl.java:3292) [artemis-server-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl$AddressQueueReaper.run(PostOfficeImpl.java:1762) [artemis-server-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$2.run(ActiveMQScheduledComponent.java:306) [artemis-commons-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42) [artemis-commons-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31) [artemis-commons-2.11.0.jar:2.11.0]
> at org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66) [artemis-commons-2.11.0.jar:2.11.0]
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [java.base:]
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [java.base:]
> at org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118) [artemis-commons-2.11.0.jar:2.11.0]
> {noformat}
> after which, many errors of the following form are printed
> {noformat}
> 2020-04-22 16:08:13,071 ERROR [org.apache.activemq.artemis.core.server] AMQ224065: Failed to remove auto-created queue feasdfc888.p: java.lang.NullPointerException
> {noformat}
> When I encountered this for the first time, I left the JMX program running for a long time, and let it to go to queue number 30000 or so before stopping the broker, When I started the broker again, it started slowly, and eventually ran out of heap space without completing startup. I was unable to replicate this afterwards.
> {noformat}
> 2020-04-22 19:51:08,723 INFO [org.apache.activemq.artemis.integration.bootstrap] AMQ101000: Starting ActiveMQ Artemis Server
> 2020-04-22 19:51:08,821 INFO [org.apache.activemq.artemis.core.server] AMQ221000: live Message Broker is starting with configuration Broker Configuration (clustered=false,journalDirectory=data/journal,bindingsDirectory=data/bindings,largeMessagesDirectory=data/large-messages,pagingDirectory=data/paging)
> 2020-04-22 19:51:08,926 INFO [org.apache.activemq.artemis.core.server] AMQ221013: Using NIO Journal
> 2020-04-22 19:51:09,070 INFO [org.apache.activemq.artemis.core.server] AMQ221057: Global Max Size is being adjusted to 1/2 of the JVM max size (-Xmx). being defined as 1,073,741,824
> 2020-04-22 19:51:09,126 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-server]. Adding protocol support for: CORE
> 2020-04-22 19:51:09,127 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-amqp-protocol]. Adding protocol support for: AMQP
> 2020-04-22 19:51:09,132 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-hornetq-protocol]. Adding protocol support for: HORNETQ
> 2020-04-22 19:51:09,139 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-mqtt-protocol]. Adding protocol support for: MQTT
> 2020-04-22 19:51:09,146 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-openwire-protocol]. Adding protocol support for: OPENWIRE
> 2020-04-22 19:51:09,147 INFO [org.apache.activemq.artemis.core.server] AMQ221043: Protocol module found: [artemis-stomp-protocol]. Adding protocol support for: STOMP
> 2020-04-22 19:51:09,316 INFO [org.apache.activemq.artemis.core.server] AMQ221034: Waiting indefinitely to obtain live lock
> 2020-04-22 19:51:09,317 INFO [org.apache.activemq.artemis.core.server] AMQ221035: Live Server Obtained live lock
> 2020-04-22 19:51:31,614 INFO [org.apache.activemq.artemis.core.server] AMQ221080: Deploying address DLQ supporting [ANYCAST]
> 2020-04-22 19:51:31,614 INFO [org.apache.activemq.artemis.core.server] AMQ221003: Deploying ANYCAST queue DLQ on address DLQ
> 2020-04-22 19:51:31,615 INFO [org.apache.activemq.artemis.core.server] AMQ221080: Deploying address ExpiryQueue supporting [ANYCAST]
> 2020-04-22 19:51:31,615 INFO [org.apache.activemq.artemis.core.server] AMQ221003: Deploying ANYCAST queue ExpiryQueue on address ExpiryQueue
> 2020-04-22 19:51:32,318 INFO [org.apache.activemq.artemis.core.server] AMQ221020: Started EPOLL Acceptor at 0.0.0.0:61616 for protocols [CORE,MQTT,AMQP,STOMP,HORNETQ,OPENWIRE]
> 2020-04-22 19:51:32,322 INFO [org.apache.activemq.artemis.core.server] AMQ221020: Started EPOLL Acceptor at 0.0.0.0:5445 for protocols [HORNETQ,STOMP]
> 2020-04-22 19:51:32,332 INFO [org.apache.activemq.artemis.core.server] AMQ221020: Started EPOLL Acceptor at 0.0.0.0:5672 for protocols [AMQP]
> 2020-04-22 19:51:32,336 INFO [org.apache.activemq.artemis.core.server] AMQ221020: Started EPOLL Acceptor at 0.0.0.0:1883 for protocols [MQTT]
> 2020-04-22 19:51:32,340 INFO [org.apache.activemq.artemis.core.server] AMQ221020: Started EPOLL Acceptor at 0.0.0.0:61613 for protocols [STOMP]
> 2020-04-22 19:51:32,345 INFO [org.apache.activemq.artemis.core.server] AMQ221007: Server is now live
> 2020-04-22 19:51:32,345 INFO [org.apache.activemq.artemis.core.server] AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.11.0 [0.0.0.0, nodeID=6fd8a068-84bb-11ea-bfc4-c6a0bfa68374]
> 2020-04-22 19:51:32,658 INFO [org.apache.activemq.hawtio.branding.PluginContextListener] Initialized activemq-branding plugin
> 2020-04-22 19:51:32,730 INFO [org.apache.activemq.hawtio.plugin.PluginContextListener] Initialized artemis-plugin plugin
> 2020-04-22 19:51:33,516 INFO [io.hawt.HawtioContextListener] Initialising hawtio services
> 2020-04-22 19:51:33,564 INFO [io.hawt.system.ConfigManager] Configuration will be discovered via system properties
> 2020-04-22 19:51:33,566 INFO [io.hawt.jmx.JmxTreeWatcher] Welcome to hawtio 1.5.5 : http://hawt.io/ : Don't cha wish your console was hawt like me? ;-)
> 2020-04-22 19:51:33,575 INFO [io.hawt.jmx.UploadManager] Using file upload directory: /home/jdanek/Downloads/AMQ7/apache-artemis-2.11.0/i0/tmp/uploads
> 2020-04-22 19:51:33,594 INFO [io.hawt.web.AuthenticationFilter] Starting hawtio authentication filter, JAAS realm: "activemq" authorized role(s): "amq" role principal classes: "org.apache.activemq.artemis.spi.core.security.jaas.RolePrincipal"
> 2020-04-22 19:51:33,642 INFO [io.hawt.web.JolokiaConfiguredAgentServlet] Jolokia overridden property: [key=policyLocation, value=file:/home/jdanek/Downloads/AMQ7/apache-artemis-2.11.0/i0/etc/jolokia-access.xml]
> 2020-04-22 19:51:33,893 INFO [io.hawt.web.RBACMBeanInvoker] Using MBean [hawtio:type=security,area=jmx,rank=0,name=HawtioDummyJMXSecurity] for role based access control
> 2020-04-22 19:51:34,786 INFO [io.hawt.system.ProxyWhitelist] Initial proxy whitelist: [localhost, 127.0.0.1, 10.40.208.18, 192.168.86.172]
> 2020-04-22 19:51:35,120 INFO [org.apache.activemq.artemis] AMQ241001: HTTP Server started at http://localhost:8161
> 2020-04-22 19:51:35,121 INFO [org.apache.activemq.artemis] AMQ241002: Artemis Jolokia REST API available at http://localhost:8161/console/jolokia
> 2020-04-22 19:51:35,121 INFO [org.apache.activemq.artemis] AMQ241004: Artemis Console available at http://localhost:8161/console
> 2020-04-22 19:51:42,554 INFO [io.hawt.web.LoginServlet] hawtio login is using 1800 sec. HttpSession timeout
> 2020-04-22 19:52:11,771 INFO [io.hawt.web.keycloak.KeycloakServlet] Keycloak integration is disabled
> 2020-04-22 19:53:08,114 WARN [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Java heap space: java.lang.OutOfMemoryError: Java heap space
> 2020-04-22 20:00:30,746 WARN [org.apache.activemq.artemis.utils.actors.OrderedExecutor] Java heap space: java.lang.OutOfMemoryError: Java heap space
> {noformat}
> The code to create the queues over JMX is
> {code:java}
> import com.redhat.amqx.management.artemis.ArtemisResolver;
> import org.apache.activemq.artemis.api.core.management.ActiveMQServerControl;
> import javax.management.MBeanServerConnection;
> import javax.management.remote.JMXConnector;
> import javax.management.remote.JMXConnectorFactory;
> import javax.management.remote.JMXServiceURL;
> import java.io.IOException;
> import java.util.HashMap;
> import java.util.Map;
> public class Main {
> public static void main(String[] args) {
> for (char c = 'a'; c < 'z'; c++) {
> String prefix = String.valueOf(c);
> new Thread(() -> {
> try {
> createAndDeleteQueues(prefix);
> } catch (Exception e) {
> e.printStackTrace();
> System.exit(1);
> }
> }).start();
> }
> }
> public static void createAndDeleteQueues(String prefix) throws Exception {
> for (long i = 1; i < 5000; i++) {
> String addressName = prefix + i;
> String routingType = "MULTICAST";
> System.out.println("createAndDeleteAddresses: " + addressName);
> createQueue(addressName, routingType);
> deleteQueue(addressName);
> }
> }
> public static void createQueue(String addressName, String routingType) throws Exception {
> MyArtemisResolver jmx = new MyArtemisResolver();
> ArtemisResolver artemisResolver = jmx.getArtemisResolver();
> final ActiveMQServerControl brokerView = artemisResolver.getBrokerView();
> brokerView.createQueue(addressName, addressName, routingType);
> jmx.close();
> }
> public static void deleteQueue(String addressName) throws Exception {
> MyArtemisResolver jmx = new MyArtemisResolver();
> ArtemisResolver artemisResolver = jmx.getArtemisResolver();
> final ActiveMQServerControl brokerView = artemisResolver.getBrokerView();
> brokerView.destroyQueue(addressName, true, false);
> jmx.close();
> }
> static class MyArtemisResolver {
> private final JMXConnector jmxc;
> private final String brokerName;
> MyArtemisResolver() throws IOException {
> String url = "service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi";
> brokerName = "0.0.0.0";
> Map<String, String[]> env = new HashMap<>();
> String[] creds = {"admin", "admin"};
> env.put(JMXConnector.CREDENTIALS, creds);
> jmxc = JMXConnectorFactory.connect(new JMXServiceURL(url), env);
> }
> public ArtemisResolver getArtemisResolver() throws IOException {
> MBeanServerConnection mBeanServerConnection = jmxc.getMBeanServerConnection();
> return new ArtemisResolver(mBeanServerConnection, brokerName);
> }
> public void close() throws IOException {
> if (jmxc != null) {
> jmxc.close();
> }
> }
> }
> }
> {code}
> There seem to be the following issues
> * Broker does not shut down cleanly
> * (Broker was then unable to start once. I did not manage to reproduce this afterwards.)
> * Error message talks about auto-created queues when in fact there is auto-created addresses
> Workaround for the issue seems to be to wait sufficient time after deleting the queues so that all address autodeletes complete.
--
This message was sent by Atlassian Jira
(v8.20.1#820001)