A possible workaround is to add create=false to the connection factory
URI:
<amq:connectionFactory id="amqConnectionFactory"
brokerURL="vm://localhost?create=false">
>From https://activemq.apache.org/vm-transport-reference
"create ... If the broker should be created on demand if it does not
already exist."
By setting this to false, the broker is not re-created on shutdown.
Are there any known side-effects on setting "create" to false for the
VM transport? (other than the broker not being auto created?)
Kind regards,
Martijn Brinkers
On Mon, 2020-12-14 at 16:07 +0100, Martijn Brinkers (list) wrote:
> I forgot to add that the issue only happens with a VM Transport,
> i.e.,
> if I configure a tcp transport, shutdown works correctly.
>
> Kind regards,
>
> Martijn Brinkers
>
> On Mon, 2020-12-14 at 15:51 +0100, Martijn Brinkers (list) wrote:
> > Hi Tim
> >
> > It took some time to debug. When I set a breakpoint (Eclipse), the
> > issue does not happen so it looks like some timing issue (race
> > condition).
> >
> > I added a stack dump to the start method of a modified
> > BrokerService
> > class.
> >
> > The stack dump from BrokerService#start when the application is
> > shutting down:
> >
> > [exec] java.lang.Thread.getStackTrace(Thread.java:1559)
> > [exec]
> > org.apache.activemq.broker.BrokerService.start(BrokerService.java:6
> > 12
> > )
> > [exec]
> > org.apache.activemq.transport.vm.VMTransportFactory.doCompositeConn
> > ec
> > t(
> > VMTransportFactory.java:127)
> > [exec]
> > org.apache.activemq.transport.vm.VMTransportFactory.doConnect(VMTra
> > ns
> > po
> > rtFactory.java:56)
> > [exec]
> > org.apache.activemq.transport.TransportFactory.connect(TransportFac
> > to
> > ry
> > .java:65)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createTransport(Activ
> > eM
> > QC
> > onnectionFactory.java:331)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnect
> > io
> > n(
> > ActiveMQConnectionFactory.java:346)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnect
> > io
> > n(
> > ActiveMQConnectionFactory.java:304)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createConnection(Acti
> > ve
> > MQ
> > ConnectionFactory.java:244)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.doCreate
> > Co
> > nn
> > ection(SingleConnectionFactory.java:342)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.initConn
> > ec
> > ti
> > on(SingleConnectionFactory.java:288)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.createCo
> > nn
> > ec
> > tion(SingleConnectionFactory.java:225)
> > [exec]
> > org.springframework.jms.support.JmsAccessor.createConnection(JmsAcc
> > es
> > so
> > r.java:184)
> > [exec]
> > org.springframework.jms.listener.AbstractJmsListeningContainer.crea
> > te
> > Sh
> > aredConnection(AbstractJmsListeningContainer.java:405)
> > [exec]
> > org.springframework.jms.listener.AbstractJmsListeningContainer.refr
> > es
> > hS
> > haredConnection(AbstractJmsListeningContainer.java:390)
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer.re
> > fr
> > es
> > hConnectionUntilSuccessful(DefaultMessageListenerContainer.java:885
> > )
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer.re
> > co
> > ve
> > rAfterListenerSetupFailure(DefaultMessageListenerContainer.java:861
> > )
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer$As
> > yn
> > cM
> > essageListenerInvoker.run(DefaultMessageListenerContainer.java:1012
> > )
> >
> > It looks like
> > DefaultMessageListenerContainer#recoverAfterListenerSetupFailure
> > creates a new instance of
> >
> >
> > Additional DEBUG output:
> >
> > [exec] 14 Dec 2020 15:41:32 | DEBUG ID:martijn-laptop-46343-
> > 1607956885604-4:1:1 Transaction Commit
> > :null (org.apache.activemq.ActiveMQSession)
> > [org.springframework.jms.listener.DefaultMessageListenerContainer#0
> > -
> > 1]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Publishing: vm://localhost
> > for
> > broker transport URI:
> > vm://localhost (org.apache.activemq.broker.TransportConnector)
> > [ActiveMQ BrokerService[localhost] Task-2]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Publishing: vm://localhost
> > for
> > broker transport URI:
> > vm://localhost (org.apache.activemq.broker.TransportConnector)
> > [ActiveMQ BrokerService[localhost] Task-2]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Connection Stopped:
> > vm://localhost#0 (org.apache.activemq.broker.TransportConnection
> > )
> > [ActiveMQ BrokerService[localhost] Task-2]
> > [exec] 14 Dec 2020 15:41:32 | INFO Connector vm://localhost
> > stopped (org.apache.activemq.broker.TransportConnector)
> > [ActiveMQ
> > ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 |
> > INFO PListStore:[/home/martijn/git/ciphermail-core/var/jms-
> > data/localhost/tmp_storage]
> > stopped (org.apache.activemq.store.kahadb.plist.PListStoreImpl)
> > [ActiveMQ ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | INFO Stopping async queue
> > tasks (org.apache.activemq.store.kahadb.KahaDBStore) [ActiveMQ
> > ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | INFO Stopping async topic
> > tasks (org.apache.activemq.store.kahadb.KahaDBStore) [ActiveMQ
> > ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Forcing shutdown of
> > ExecutorService:
> >
>
>
org.apache.activemq.store.kahadb.KahaDBStore$StoreTaskExecutor@7ae5430d
> > [Running, pool size = 0, active threads = 0, queued tasks = 0,
> > completed tasks = 0] (org.apache.activemq.util.ThreadPoolUtils)
> > [ActiveMQ ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Shutdown of
> > ExecutorService:
> > java.util.concurrent.ThreadPoolExecutor@7cd2745d[Terminated, pool
> > size
> > = 0, active threads = 0, queued tasks = 0, completed tasks = 1] is
> > shutdown: true and terminated: false took: 0.000
> > seconds. (org.apache.activemq.util.ThreadPoolUtils) [ActiveMQ
> > Connection Executor: vm://localhost#0]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Forcing shutdown of
> > ExecutorService:
> >
>
>
org.apache.activemq.store.kahadb.KahaDBStore$StoreTaskExecutor@30030b95
> > [Running, pool size = 0, active threads = 0, queued tasks = 0,
> > completed tasks = 0] (org.apache.activemq.util.ThreadPoolUtils)
> > [ActiveMQ ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | INFO Stopped
> > KahaDB (org.apache.activemq.store.kahadb.KahaDBStore) [ActiveMQ
> > ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Shutdown of
> > ExecutorService:
> > java.util.concurrent.ThreadPoolExecutor@14ef957c[Shutting down,
> > pool
> > size = 1, active threads = 1, queued tasks = 1, completed tasks =
> > 0]
> > is
> > shutdown: true and terminated: false took: 0.000
> > seconds. (org.apache.activemq.util.ThreadPoolUtils) [ActiveMQ
> > Connection Executor: vm://localhost#0]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Forcing shutdown of
> > ExecutorService:
> > java.util.concurrent.ThreadPoolExecutor@7a50bc0d[Running, pool size
> > =
> > 2, active threads = 0, queued tasks = 0, completed tasks =
> > 6] (org.apache.activemq.util.ThreadPoolUtils) [ActiveMQ
> > Connection
> > Executor: vm://localhost#0]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Checkpoint
> > started. (org.apache.activemq.store.kahadb.MessageDatabase)
> > [ActiveMQ ShutdownHook]
> > [exec] 14 Dec 2020 15:41:32 | DEBUG Checkpoint
> > done. (org.apache.activemq.store.kahadb.MessageDatabase)
> > [ActiveMQ
> > ShutdownHook]
> > [exec] java.lang.Thread.getStackTrace(Thread.java:1559)
> > [exec]
> > org.apache.activemq.broker.BrokerService.start(BrokerService.java:6
> > 12
> > )
> > [exec]
> > org.apache.activemq.transport.vm.VMTransportFactory.doCompositeConn
> > ec
> > t(
> > VMTransportFactory.java:127)
> > [exec]
> > org.apache.activemq.transport.vm.VMTransportFactory.doConnect(VMTra
> > ns
> > po
> > rtFactory.java:56)
> > [exec]
> > org.apache.activemq.transport.TransportFactory.connect(TransportFac
> > to
> > ry
> > .java:65)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createTransport(Activ
> > eM
> > QC
> > onnectionFactory.java:331)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnect
> > io
> > n(
> > ActiveMQConnectionFactory.java:346)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createActiveMQConnect
> > io
> > n(
> > ActiveMQConnectionFactory.java:304)
> > [exec]
> > org.apache.activemq.ActiveMQConnectionFactory.createConnection(Acti
> > ve
> > MQ
> > ConnectionFactory.java:244)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.doCreate
> > Co
> > nn
> > ection(SingleConnectionFactory.java:342)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.initConn
> > ec
> > ti
> > on(SingleConnectionFactory.java:288)
> > [exec]
> > org.springframework.jms.connection.SingleConnectionFactory.createCo
> > nn
> > ec
> > tion(SingleConnectionFactory.java:225)
> > [exec]
> > org.springframework.jms.support.JmsAccessor.createConnection(JmsAcc
> > es
> > so
> > r.java:184)
> > [exec]
> > org.springframework.jms.listener.AbstractJmsListeningContainer.crea
> > te
> > Sh
> > aredConnection(AbstractJmsListeningContainer.java:405)
> > [exec]
> > org.springframework.jms.listener.AbstractJmsListeningContainer.refr
> > es
> > hS
> > haredConnection(AbstractJmsListeningContainer.java:390)
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer.re
> > fr
> > es
> > hConnectionUntilSuccessful(DefaultMessageListenerContainer.java:885
> > )
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer.re
> > co
> > ve
> > rAfterListenerSetupFailure(DefaultMessageListenerContainer.java:861
> > )
> > [exec]
> > org.springframework.jms.listener.DefaultMessageListenerContainer$As
> > yn
> > cM
> > essageListenerInvoker.run(DefaultMessageListenerContainer.java:1012
> > )
> > [exec] java.lang.Thread.run(Thread.java:748)
> > [exec] 14 Dec 2020 15:41:32 | WARN Memory Usage for the
> > Broker
> > (1024mb) is more than the maximum available for the JVM: 455 mb -
> > resetting to 70% of maximum available: 318
> > mb (org.apache.activemq.broker.BrokerService)
> > [org.springframework.jms.listener.DefaultMess
> >
> > Kind regards,
> >
> > Martijn Brinkers
> >
> >
> >
> > On Sat, 2020-12-12 at 18:17 -0700, Tim Bain wrote:
> > > Can you set a debugger breakpoint in one of the methods of the
> > > broker's
> > > initialization process and then trigger the behavior? Then you'll
> > > have
> > > access to the call stack (including the values of all variables
> > > at
> > > each
> > > call in the stack) that resulted in the decision to start a new
> > > broker, and
> > > hopefully by walking up the stack you'll be able to see what
> > > caused
> > > initialization to occur when it otherwise wouldn't be expected
> > > to.
> > >
> > > Tim
> > >
> > > On Fri, Dec 11, 2020, 11:11 AM Martijn Brinkers <
> > > martijn.l...@gmail.com>
> > > wrote:
> > >
> > > > On 11-12-2020 18:37, Jean-Baptiste Onofre wrote:
> > > > > Do you use the vm connector in your broker service ?
> > > >
> > > > Yes that is correct. I only use it for internal JMS messaging.
> > > > The
> > > > transportConnector is therefore set vm://localhost
> > > >
> > > > Kind regards,
> > > >
> > > > Martijn Brinkers
> > > >
> > > >
> > > > > > Le 11 déc. 2020 à 16:17, Martijn Brinkers (list) <
> > > >
> > > > martijn.l...@gmail.com> a écrit :
> > > > > >
> > > > > > Unfortunately it looks like it's not easy (for me) to
> > > > > > replicate
> > > > > > in a
> > > > > > simple application.
> > > > > >
> > > > > > It looks like the issue is related to a shutdown hook
> > > > > > somehow
> > > > > > resurrecting the broker after the broker was stopped.
> > > > > >
> > > > > > Unfortunately the logging lines are a bit long so I hope
> > > > > > it's
> > > > > > somewhat
> > > > > > readable.
> > > > > >
> > > > > > The shutdown logging shows that ActiveMQ is shutting down
> > > > > > but
> > > > > > then just
> > > > > > after the shutdown hook, a new instance of the
> > > > > > BrokerService
> > > > > > is
> > > > > > created
> > > > > > with the default values. For example it reports a warning
> > > > > > about
> > > > > > max
> > > > > > memory 1024mb. In the spring config however the max memory
> > > > > > is
> > > > > > set to
> > > > > > 20MB.
> > > > > >
> > > > > > INFO Apache ActiveMQ 5.16.0 (localhost, ID:martijn-laptop-
> > > > > > 45763-
> > > > > > 1607698489325-0:1) is shutting
> > > > > > down (org.apache.activemq.broker.BrokerService)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > INFO Connector vm://localhost
> > > > > > stopped (org.apache.activemq.broker.TransportConnector)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > INFO PListStore:[/home/martijn/git/ciphermail-
> > > > > > core/var/jms-
> > > > > > data/localhost/tmp_storage]
> > > > > > stopped (org.apache.activemq.store.kahadb.plist.PListSto
> > > > > > re
> > > > > > Im
> > > > > > pl)
> > > > > > [ActiveMQ ShutdownHook]
> > > > > >
> > > > > > INFO Stopping async queue
> > > > > > tasks (org.apache.activemq.store.kahadb.KahaDBStore)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > INFO Stopping async topic
> > > > > > tasks (org.apache.activemq.store.kahadb.KahaDBStore)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > INFO Stopped
> > > > > > KahaDB (org.apache.activemq.store.kahadb.KahaDBStore)
> > > > > > [ActiveMQ ShutdownHook]
> > > > > >
> > > > > > WARN Memory Usage for the Broker (1024mb) is more than the
> > > > > > maximum
> > > > > > available for the JVM: 455 mb - resetting to 70% of maximum
> > > > > > available:
> > > > > > 318 mb (org.apache.activemq.broker.BrokerService)
> > > > > > [org.springframework.jms.listener.DefaultMessageListenerCon
> > > > > > ta
> > > > > > in
> > > > > > er#0-1]
> > > > > >
> > > > > > INFO Using Persistence Adapter:
> > > > > > KahaDBPersistenceAdapter[/home/martijn/git/ciphermail-
> > > > > > core/activemq-
> > > > > > data/localhost/KahaDB] (org.apache.activemq.broker.Broke
> > > > > > rS
> > > > > > er
> > > > > > vice)
> > > > > > [org.springframework.jms.listener.DefaultMessageListenerCon
> > > > > > ta
> > > > > > in
> > > > > > er#0-1]
> > > > > >
> > > > > > INFO Apache ActiveMQ 5.16.0 (localhost, ID:martijn-laptop-
> > > > > > 45763-
> > > > > > 1607698489325-0:1) uptime 7.446
> > > > > > seconds (org.apache.activemq.broker.BrokerService)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > INFO Apache ActiveMQ 5.16.0 (localhost, ID:martijn-laptop-
> > > > > > 45763-
> > > > > > 1607698489325-0:1) is
> > > > > > shutdown (org.apache.activemq.broker.BrokerService)
> > > > > > [ActiveMQ
> > > > > > ShutdownHook]
> > > > > >
> > > > > > A simple test application does not show this issue.
> > > > > >
> > > > > > If I disable (i.e., comment out) the following
> > > > > > DefaultMessageListenerContainer, then the shutdown works
> > > > > > normally.
> > > > > >
> > > > > > <bean
> > > > > > class="org.springframework.jms.listener.DefaultMessageListe
> > > > > > ne
> > > > > > rC
> > > > > > ontainer
> > > > > > " >
> > > > > > <property name="connectionFactory"
> > > > > > ref="connectionFactory"/>
> > > > > > <property name="destination"
> > > > > > ref="certificateCreatedTopic"/>
> > > > > > <property name="sessionTransacted" value="true" />
> > > > > > <property name="pubSubDomain" value="true"/>
> > > > > > <property name="subscriptionDurable" value="true" />
> > > > > > <property name="clientId" value="ciphermail.gateway" />
> > > > > > <property name="durableSubscriptionName"
> > > > > > value="certificate-
> > > > > > created-listener" />
> > > > > > </bean>
> > > > > >
> > > > > > For some reason adding DefaultMessageListenerContainer
> > > > > > instance
> > > > > > somehow
> > > > > > results in restarting and instance of BrokerService which
> > > > > > is
> > > > > > then
> > > > > > shutdown.
> > > > > >
> > > > > > Any idea?
> > > > > >
> > > > > > Kind regards,
> > > > > >
> > > > > > Martijn Brinkers
> > > > > >
> > > > > > On Fri, 2020-12-11 at 06:09 -0700, Tim Bain wrote:
> > > > > > > This sounds like a bug. Please submit a bug in JIRA,
> > > > > > > ideally
> > > > > > > attaching a
> > > > > > > minimal reproducer.
> > > > > > >
> > > > > > > Thanks,
> > > > > > > Tim
> > > > > > >
> > > > > > > On Fri, Dec 11, 2020, 5:58 AM Martijn Brinkers (list) <
> > > > > > > martijn.l...@gmail.com> wrote:
> > > > > > >
> > > > > > > > I have embedded ActiveMQ inside a spring application.
> > > > > > > >
> > > > > > > > The broker is configured in XML and I explicitly set
> > > > > > > > the
> > > > > > > > dataDirectory:
> > > > > > > >
> > > > > > > > <amq:broker useJmx="false" persistent="true"
> > > > > > > > dataDirectory="var/jms">
> > > > > > > > <amq:transportConnectors>
> > > > > > > > <amq:transportConnector uri="vm://localhost" />
> > > > > > > > </amq:transportConnectors>
> > > > > > > > </amq:broker>
> > > > > > > >
> > > > > > > > When I startup my application, the var/jms directory is
> > > > > > > > created and
> > > > > > > > JMS
> > > > > > > > messages are stored when required. If however I
> > > > > > > > shutdown
> > > > > > > > my
> > > > > > > > application, an addtional directory "activemq-
> > > > > > > > data/localhost/KahaDB" is
> > > > > > > > created. This only happens if "useShutdownHook" is true
> > > > > > > > (which is
> > > > > > > > the
> > > > > > > > default).
> > > > > > > >
> > > > > > > > It looks like the shutdownhook tries to create the
> > > > > > > > "data
> > > > > > > > directory"
> > > > > > > > but ignores the configured value and therefore uses the
> > > > > > > > default
> > > > > > > > data
> > > > > > > > directory name.
> > > > > > > >
> > > > > > > > Is this a bug? Or did I make a configuration error?
> > > > > > > >
> > > > > > > > Kind regards,
> > > > > > > >
> > > > > > > > Martijn Brinkers
> > > > > > > >
> > > > > > > >
> > > >
> > > >
> >
> >
>
>
