[
https://issues.apache.org/jira/browse/AMQ-2891?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13166537#comment-13166537
]
raghav rao commented on AMQ-2891:
---------------------------------
@Gary
The issue where Broker is starting slowly even after shutting it down cleanly
is still there..
It takes 117 seconds to restart the broker with KahaDB size on disk = 14GB with
1 million records.
Subsequent starts after clean shutdown also take the same amount of time.
When i stop the broker i am calling broker.stop();
Thoughts??
Log statements
--------------
[2011-12-09 12:18:43.372] DEBUG: binding to broker: stitcher1-UDCServer
[2011-12-09 12:18:43.461] INFO:
PListStore:/home/rrao/myudc/stitcher1-UDCServer/tmp_storage started
[2011-12-09 12:18:43.572] DEBUG: Probably not using JRE 1.4:
mx4j.tools.naming.NamingService
[2011-12-09 12:18:43.574] DEBUG: Starting JMXConnectorServer...
[2011-12-09 12:18:43.694] INFO: Using Persistence Adapter:
KahaDBPersistenceAdapter[/home/rrao/myudc/stitcher1-UDCServer/KahaDB]
[2011-12-09 12:18:43.700] INFO: JMX consoles can connect to
service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
[2011-12-09 12:20:34.390] INFO: KahaDB is version 3
[2011-12-09 12:20:34.391] DEBUG: loading
[2011-12-09 12:20:34.400] DEBUG: loading
[2011-12-09 12:20:34.400] DEBUG: loading
[2011-12-09 12:20:34.400] DEBUG: loading
[2011-12-09 12:20:34.409] DEBUG: loading
[2011-12-09 12:20:34.409] DEBUG: loading
[2011-12-09 12:20:34.464] INFO: Recovering from the journal ...
[2011-12-09 12:20:34.464] INFO: Recovery replayed 1 operations from the
journal in 0.055 seconds.
[2011-12-09 12:20:36.905] INFO: ActiveMQ null JMS Message Broker
(stitcher1-UDCServer) is starting
[2011-12-09 12:20:36.905] INFO: For help or more information please see:
http://activemq.apache.org/
[2011-12-09 12:20:37.076] DEBUG: stitcher1-UDCServer adding destination:
queue://queue-AVIR
[2011-12-09 12:20:40.731] DEBUG: Checkpoint started.
[2011-12-09 12:20:40.752] DEBUG: Checkpoint done.
[2011-12-09 12:20:40.794] DEBUG: queue-AVIR toPageIn: 200, Inflight: 0,
pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
[2011-12-09 12:20:40.800] DEBUG: Publishing: vm://stitcher1-UDCServer for
broker transport URI:
vm://stitcher1-UDCServer?marshal=false&broker.persistent=true
[2011-12-09 12:20:40.800] DEBUG: stitcher1-UDCServer adding destination:
topic://ActiveMQ.Advisory.Queue
[2011-12-09 12:20:40.811] DEBUG: queue-AVIR toPageIn: 200, Inflight: 0,
pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
[2011-12-09 12:20:40.814] INFO: Connector
vm://stitcher1-UDCServer?marshal=false&broker.persistent=true Started
[2011-12-09 12:20:40.830] INFO: ActiveMQ JMS Message Broker
(stitcher1-UDCServer, ID:stitcher1-38687-1323462036935-0:1) started
[2011-12-09 12:20:40.940] DEBUG: Setting up new connection id:
ID:stitcher1-38687-1323462036935-2:1, address:
vm://stitcher1-UDCServer?marshal=false&broker.persistent=true#0
[2011-12-09 12:20:40.941] DEBUG: stitcher1-UDCServer adding destination:
topic://ActiveMQ.Advisory.Connection
[2011-12-09 12:20:40.949] DEBUG: stitcher1-UDCServer adding consumer:
ID:stitcher1-38687-1323462036935-2:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
[2011-12-09 12:20:41.080] DEBUG: Setting up new connection id:
ID:stitcher1-38687-1323462036935-2:2, address:
vm://stitcher1-UDCServer?marshal=false&broker.persistent=true#2
[2011-12-09 12:20:41.082] DEBUG: stitcher1-UDCServer adding consumer:
ID:stitcher1-38687-1323462036935-2:2:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
[2011-12-09 12:20:41.088] DEBUG: stitcher1-UDCServer adding consumer:
ID:stitcher1-38687-1323462036935-2:2:1:1 for destination: queue://queue-AVIR
[2011-12-09 12:20:41.095] DEBUG: queue://queue-AVIR add sub:
QueueSubscription: consumer=ID:stitcher1-38687-1323462036935-2:2:1:1,
destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 0, dispatched:
0, inflight: 0
[2011-12-09 12:20:41.095] DEBUG: stitcher1-UDCServer adding destination:
topic://ActiveMQ.Advisory.Consumer.Queue.queue-AVIR
[2011-12-09 12:20:41.096] DEBUG: queue-AVIR toPageIn: 200, Inflight: 0,
pagedInMessages.size 0, enqueueCount: 0, dequeueCount: 0
[2011-12-09 12:20:41.101] INFO: started dispatcher [AVIR-1]
(com.activevideo.udc.server.dispatcher.DispatcherManager.start:832)
[2011-12-09 12:20:41.157] DEBUG: Main:memory:queue://queue-AVIR:memory: usage
change from: 0% of available memory, to: 1% of available memory
[2011-12-09 12:20:41.158] DEBUG: Main:memory: usage change from: 0% of
available memory, to: 1% of available memory
[2011-12-09 12:20:41.169] DEBUG: Main:memory:queue://queue-AVIR:memory: usage
change from: 1% of available memory, to: 2% of available memory
[2011-12-09 12:20:41.169] DEBUG: Main:memory: usage change from: 1% of
available memory, to: 2% of available memory
[2011-12-09 12:20:41.184] DEBUG: Main:memory:queue://queue-AVIR:memory: usage
change from: 2% of available memory, to: 3% of available memory
[2011-12-09 12:20:41.184] DEBUG: Main:memory: usage change from: 2% of
available memory, to: 3% of available memory
[2011-12-09 12:20:41.199] DEBUG: Main:memory:queue://queue-AVIR:memory: usage
change from: 3% of available memory, to: 4% of available memory
[2011-12-09 12:20:41.199] DEBUG: Main:memory: usage change from: 3% of
available memory, to: 4% of available memory
[2011-12-09 12:20:41.213] DEBUG: Main:memory:queue://queue-AVIR:memory: usage
change from: 4% of available memory, to: 5% of available memory
[2011-12-09 12:20:41.213] DEBUG: Main:memory: usage change from: 4% of
available memory, to: 5% of available memory
> ActiveMQ takes longer to start with KahaDb and more than 10000 messages
> -----------------------------------------------------------------------
>
> Key: AMQ-2891
> URL: https://issues.apache.org/jira/browse/AMQ-2891
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.4.0
> Environment: Windows XP
> Reporter: Dinny Mathew
> Assignee: Gary Tully
>
> ActiveMQ takes around five minutes to start with KahaDb with more than 10000
> messages. All messages are persistent queue.
> With 500,000 persistent messsages, ittook around 20 minutes to start.
> See the five minutes time difference between lines:
> 2010-08-31 12:55:19,286 | INFO |
> PListStore:C:\ActiveMQ\apache-activemq-5.4.0\bin\win32\..\..\data\localhost\tmp_storage
> initialized | org.apache.activemq.store.kahadb.plist.PListStore |
> WrapperSimpleAppMain
> 2010-08-31 13:03:56,983 | INFO | Listening for connections at:
> nio://S90356004630988:61616 |
> org.apache.activemq.transport.TransportServerThreadSupport |
> WrapperSimpleAppMain
> From activemq.log with 100,000 messages
> 2010-08-31 12:55:10,436 | INFO | JMX consoles can connect to
> service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi |
> org.apache.activemq.broker.jmx.ManagementContext | JMX connector
> 2010-08-31 12:55:11,294 | INFO | KahaDB is version 2 |
> org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
> 2010-08-31 12:55:11,435 | INFO | Recovering from the journal ... |
> org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
> 2010-08-31 12:55:11,435 | INFO | Recovery replayed 1 operations from the
> journal in 0.063 seconds. | org.apache.activemq.store.kahadb.MessageDatabase
> | WrapperSimpleAppMain
> 2010-08-31 12:55:12,090 | INFO | ActiveMQ 5.4.0 JMS Message Broker
> (localhost) is starting | org.apache.activemq.broker.BrokerService |
> WrapperSimpleAppMain
> 2010-08-31 12:55:12,090 | INFO | For help or more information please see:
> http://activemq.apache.org/ | org.apache.activemq.broker.BrokerService |
> WrapperSimpleAppMain
> 2010-08-31 12:55:12,278 | INFO | Scheduler using directory:
> activemq-data\scheduler |
> org.apache.activemq.broker.scheduler.SchedulerBroker | WrapperSimpleAppMain
> 2010-08-31 12:55:19,286 | INFO |
> PListStore:C:\ActiveMQ\apache-activemq-5.4.0\bin\win32\..\..\data\localhost\tmp_storage
> initialized | org.apache.activemq.store.kahadb.plist.PListStore |
> WrapperSimpleAppMain
> 2010-08-31 13:03:56,983 | INFO | Listening for connections at:
> nio://S90356004630988:61616 |
> org.apache.activemq.transport.TransportServerThreadSupport |
> WrapperSimpleAppMain
> 2010-08-31 13:03:56,999 | INFO | Connector nio Started |
> org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
> 2010-08-31 13:03:57,045 | INFO | ActiveMQ JMS Message Broker (localhost,
> ID:S90356004630988-3777-1283273712137-0:0) started |
> org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
> 2010-08-31 13:03:57,639 | INFO | Logging to
> org.slf4j.impl.JCLLoggerAdapter(org.eclipse.jetty.util.log) via
> org.eclipse.jetty.util.log.Slf4jLog | org.eclipse.jetty.util.log |
> WrapperSimpleAppMain
> 2010-08-31 13:03:57,639 | INFO | jetty-7.0.1.v20091125 |
> org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 13:03:58,451 | INFO | ActiveMQ WebConsole initialized. |
> org.apache.activemq.web.WebConsoleStarter | WrapperSimpleAppMain
> 2010-08-31 13:03:58,857 | INFO | Initializing Spring FrameworkServlet
> 'dispatcher' | /admin | WrapperSimpleAppMain
> 2010-08-31 13:03:59,341 | INFO | ActiveMQ Console at
> http://0.0.0.0:8161/admin | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 13:04:00,091 | INFO | Initializing Spring root
> WebApplicationContext | /camel | WrapperSimpleAppMain
> 2010-08-31 13:04:02,668 | INFO | Connector vm://localhost Started |
> org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
> 2010-08-31 13:04:04,526 | INFO | Camel Console at http://0.0.0.0:8161/camel |
> org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 13:04:04,589 | INFO | ActiveMQ Web Demos at
> http://0.0.0.0:8161/demo | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 13:04:04,651 | INFO | RESTful file access application at
> http://0.0.0.0:8161/fileserver | org.eclipse.jetty.util.log |
> WrapperSimpleAppMain
> 2010-08-31 13:04:04,698 | INFO | Started [email protected]:8161
> | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2
> With 500,000 messages, AMQ took 20 minutes to start.
> 2010-08-31 15:24:31,178 | INFO | JMX consoles can connect to
> service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi |
> org.apache.activemq.broker.jmx.ManagementContext | JMX connector
> 2010-08-31 15:24:31,975 | INFO | KahaDB is version 2 |
> org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
> 2010-08-31 15:24:32,194 | INFO | Recovering from the journal ... |
> org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
> 2010-08-31 15:24:32,194 | INFO | Recovery replayed 1 operations from the
> journal in 0.047 seconds. | org.apache.activemq.store.kahadb.MessageDatabase
> | WrapperSimpleAppMain
> 2010-08-31 15:24:35,365 | INFO | ActiveMQ 5.4.0 JMS Message Broker
> (localhost) is starting | org.apache.activemq.broker.BrokerService |
> WrapperSimpleAppMain
> 2010-08-31 15:24:35,365 | INFO | For help or more information please see:
> http://activemq.apache.org/ | org.apache.activemq.broker.BrokerService |
> WrapperSimpleAppMain
> 2010-08-31 15:24:35,552 | INFO | Scheduler using directory:
> activemq-data\scheduler |
> org.apache.activemq.broker.scheduler.SchedulerBroker | WrapperSimpleAppMain
> 2010-08-31 15:24:48,034 | INFO |
> PListStore:C:\ActiveMQ\apache-activemq-5.4.0\bin\win32\..\..\data\localhost\tmp_storage
> initialized | org.apache.activemq.store.kahadb.plist.PListStore |
> WrapperSimpleAppMain
> 2010-08-31 15:45:09,767 | INFO | Listening for connections at:
> nio://S90356004630988:61616 |
> org.apache.activemq.transport.TransportServerThreadSupport |
> WrapperSimpleAppMain
> 2010-08-31 15:45:09,767 | INFO | Connector nio Started |
> org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
> 2010-08-31 15:45:09,876 | INFO | ActiveMQ JMS Message Broker (localhost,
> ID:S90356004630988-3029-1283282675427-0:0) started |
> org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
> 2010-08-31 15:45:10,923 | INFO | Logging to
> org.slf4j.impl.JCLLoggerAdapter(org.eclipse.jetty.util.log) via
> org.eclipse.jetty.util.log.Slf4jLog | org.eclipse.jetty.util.log |
> WrapperSimpleAppMain
> 2010-08-31 15:45:10,923 | INFO | jetty-7.0.1.v20091125 |
> org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 15:45:10,970 | INFO | Slow KahaDB access: cleanup took 1047 |
> org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
> Checkpoint Worker
> 2010-08-31 15:45:11,829 | INFO | ActiveMQ WebConsole initialized. |
> org.apache.activemq.web.WebConsoleStarter | WrapperSimpleAppMain
> 2010-08-31 15:45:12,235 | INFO | Initializing Spring FrameworkServlet
> 'dispatcher' | /admin | WrapperSimpleAppMain
> 2010-08-31 15:45:12,719 | INFO | ActiveMQ Console at
> http://0.0.0.0:8161/admin | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 15:45:13,422 | INFO | Initializing Spring root
> WebApplicationContext | /camel | WrapperSimpleAppMain
> 2010-08-31 15:45:16,390 | INFO | Connector vm://localhost Started |
> org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
> 2010-08-31 15:45:18,468 | INFO | Camel Console at http://0.0.0.0:8161/camel
> | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 15:45:18,561 | INFO | ActiveMQ Web Demos at
> http://0.0.0.0:8161/demo | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> 2010-08-31 15:45:18,624 | INFO | RESTful file access application at
> http://0.0.0.0:8161/fileserver | org.eclipse.jetty.util.log |
> WrapperSimpleAppMain
> 2010-08-31 15:45:18,686 | INFO | Started [email protected]:8161
> | org.eclipse.jetty.util.log | WrapperSimpleAppMain
> Here is the config:
> <broker xmlns="http://activemq.apache.org/schema/core";
> brokerName="localhost" dataDirectory="${activemq.base}/data"
> persistent="true" systemExitOnShutdown="true" useShutdownHook="false"
> advisorySupport="false" useJmx="true">
>
> <!--
> For better performances use VM cursor and small memory
> limit.
> For more information, see:
>
> http://activemq.apache.org/message-cursors.html
>
> Also, if your producer is "hanging", it's probably due to
> producer flow control.
> For more information, see:
> http://activemq.apache.org/producer-flow-control.html
> -->
>
> <destinationPolicy>
> <policyMap>
> <policyEntries>
> <policyEntry topic=">" producerFlowControl="false"
> optimizedDispatch="true" memoryLimit="128mb">
> <pendingSubscriberPolicy>
> <fileCursor />
> </pendingSubscriberPolicy>
> </policyEntry>
> <policyEntry queue=">" producerFlowControl="false"
> optimizedDispatch="true" memoryLimit="128mb">
> <!-- Use VM cursor for better latency
> For more information, see:
>
> http://activemq.apache.org/message-cursors.html
> -->
> <pendingQueuePolicy>
> <fileQueueCursor/>
> </pendingQueuePolicy>
>
> </policyEntry>
> </policyEntries>
> </policyMap>
> </destinationPolicy>
>
>
> <!--
> The managementContext is used to configure how ActiveMQ is
> exposed in
> JMX. By default, ActiveMQ uses the MBean server that is started
> by
> the JVM. For more information, see:
>
> http://activemq.apache.org/jmx.html
> -->
> <managementContext>
> <managementContext createConnector="true"/>
> </managementContext>
> <!--
> Configure message persistence for the broker. The default
> persistence
> mechanism is the KahaDB store (identified by the kahaDB tag).
> For more information, see:
>
> http://activemq.apache.org/persistence.html
> -->
> <persistenceAdapter>
> <kahaDB directory="${activemq.base}/data/kahadb"
> enableIndexWriteAsync="true" journalMaxFileLength="64mb"
> indexWriteBatchSize="10000" indexCacheSize="10000"/>
> </persistenceAdapter>
>
>
> <!--
> The systemUsage controls the maximum amount of space the broker
> will
> use before slowing down producers. For more information, see:
>
> http://activemq.apache.org/producer-flow-control.html
>
> <systemUsage>
> <systemUsage>
> <memoryUsage>
> <memoryUsage limit="600 mb"/>
> </memoryUsage>
> <storeUsage>
> <storeUsage limit="10 gb"/>
> </storeUsage>
> <tempUsage>
> <tempUsage limit="1 gb"/>
> </tempUsage>
> </systemUsage>
> </systemUsage>
> -->
>
> <!--
> The transport connectors expose ActiveMQ over a given protocol to
> clients and other brokers. For more information, see:
>
> http://activemq.apache.org/configuring-transports.html
> -->
> <transportConnectors>
> <transportConnector name="nio" uri="nio://0.0.0.0:61616"/>
> </transportConnectors>
> </broker>
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
