activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "raghav rao (Commented) (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-2891) ActiveMQ takes longer to start with KahaDb and more than 10000 messages
Date Fri, 09 Dec 2011 18:40:40 GMT

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

raghav rao commented on AMQ-2891:
---------------------------------

@Gary 

Thanks for your reply. I have found another issue....

Let's consider the case where the JVM process crashed.
Now when the broker restarts KahaDB is not able to load the messages and reports out of memory
error.

The KahaDB database size on disk is 34GB and has about 3 million records.

I set the broker memory limit to 2GB but still it crashes. Is it trying to load the entire
34 GB in memory??

Stack Trace
-----------
exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at org.apache.activemq.protobuf.BaseMessage.mergeFramed(BaseMessage.java:228)
        at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:825)
        at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
        at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:471)
        at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
        at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recover(KahaDBStore.java:464)
        at org.apache.activemq.store.ProxyMessageStore.recover(ProxyMessageStore.java:52)
        at org.apache.activemq.broker.region.Queue.initialize(Queue.java:270)
        at org.apache.activemq.broker.region.DestinationFactoryImpl.createDestination(DestinationFactoryImpl.java:86)
        at org.apache.activemq.broker.region.AbstractRegion.createDestination(AbstractRegion.java:473)
        at org.apache.activemq.broker.jmx.ManagedQueueRegion.createDestination(ManagedQueueRegion.java:56)
        at org.apache.activemq.broker.region.AbstractRegion.addDestination(AbstractRegion.java:123)
        at org.apache.activemq.broker.region.RegionBroker.addDestination(RegionBroker.java:298)
        at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
        at org.apache.activemq.advisory.AdvisoryBroker.addDestination(AdvisoryBroker.java:145)
        at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
        at org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
        at org.apache.activemq.broker.MutableBrokerFilter.addDestination(MutableBrokerFilter.java:151)
        at org.apache.activemq.broker.region.AbstractRegion.start(AbstractRegion.java:95)
        at org.apache.activemq.broker.region.RegionBroker.start(RegionBroker.java:198)
        at org.apache.activemq.broker.jmx.ManagedRegionBroker.start(ManagedRegionBroker.java:106)
        at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:157)
        at org.apache.activemq.broker.BrokerFilter.start(BrokerFilter.java:157)
        at org.apache.activemq.broker.TransactionBroker.start(TransactionBroker.java:109)
        at org.apache.activemq.broker.BrokerService$3.start(BrokerService.java:1803)
        at org.apache.activemq.broker.BrokerService.start(BrokerService.java:497)


Log messages from ActiveMQ broker
---------------------------------
[2011-12-09 10:26:29.339]  DEBUG: Main:memory: usage change from: 24822% of available memory,
to: 24823% of available memory
[2011-12-09 10:26:30.322]  DEBUG: Main:memory:queue://queue-AVIR:memory: usage change from:
24823% of available memory, to: 24824% of available memory
[2011-12-09 10:26:30.323]  DEBUG: Main:memory: usage change from: 24823% of available memory,
to: 24824% of available memory
[2011-12-09 10:26:31.714]  DEBUG: Main:memory:queue://queue-AVIR:memory: usage change from:
24824% of available memory, to: 24825% of available memory
[2011-12-09 10:26:31.715]  DEBUG: Main:memory: usage change from: 24824% of available memory,
to: 24825% of available memory
[2011-12-09 10:26:32.696]  DEBUG: Main:memory:queue://queue-AVIR:memory: usage change from:
24825% of available memory, to: 24826% of available memory
[2011-12-09 10:26:32.696]  DEBUG: Main:memory: usage change from: 24825% of available memory,
to: 24826% of available memory
[2011-12-09 10:26:34.657]  DEBUG: Main:memory:queue://queue-AVIR:memory: usage change from:
24826% of available memory, to: 24827% of available memory
[2011-12-09 10:26:34.657]  DEBUG: Main:memory: usage change from: 24826% of available memory,
to: 24827% of available memory

thanks,
Raghav
                
> 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 SelectChannelConnector@0.0.0.0: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 SelectChannelConnector@0.0.0.0: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

        

Mime
View raw message