You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Gilles Harloux (JIRA)" <ji...@apache.org> on 2012/10/23 17:47:14 UTC
[jira] [Created] (AMQ-4128) kahaDB journal file never gets
reclaimed after broker process crash
Gilles Harloux created AMQ-4128:
-----------------------------------
Summary: kahaDB journal file never gets reclaimed after broker process crash
Key: AMQ-4128
URL: https://issues.apache.org/jira/browse/AMQ-4128
Project: ActiveMQ
Issue Type: Bug
Components: Message Store
Affects Versions: 5.7.0
Environment: rhel 5.3, tomcat 6.0.35, jdk 1.6.0_35
Reporter: Gilles Harloux
(See this thread for the original report: http://activemq.2283324.n4.nabble.com/KahaDB-No-messages-but-log-files-not-reclaimed-and-StorePercentUsage-above-100-td4658074.html)
Setup: Embedded broker, mKahaDB store, transactions. Sometimes, when sigkill'ing the process and starting again, some kahaBD journal file won't ever get reclaimed, thus filing the disk and ultimately stopping the system.
The logs O see look a lot to me like logs from this report: https://issues.apache.org/jira/browse/AMQ-3866
I'll attach such a log file (db-444.log, matching logs below).
Logs for the restart part (the app runs inside tomcat):
{noformat}
Listening for transport dt_socket at address: 24001
Oct 23, 2012 5:27:45 PM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /opt/jdk1.6.0_33/jre/lib/amd64/server:/opt/jdk1.6.0_33/jre/lib/amd64:/opt/jdk1.6.0_33/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
Oct 23, 2012 5:27:45 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-24080
Oct 23, 2012 5:27:45 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 712 ms
Oct 23, 2012 5:27:45 PM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Oct 23, 2012 5:27:45 PM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.35
Oct 23, 2012 5:27:45 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor server.xml
2012-10-23 17:27:46,347 INFO main: [scratch.proto5.Bootstrap] bootstrap.+
2012-10-23 17:27:46,460 INFO main: [org.apache.activemq.xbean.XBeanBrokerFactory$1] Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@20ca5bff: startup date [Tue Oct 23 17:27:46 CEST 2012]; root of context hierarchy
2012-10-23 17:27:46,553 INFO main: [org.apache.xbean.spring.context.v2.XBeanXmlBeanDefinitionReader] Loading XML bean definitions from class path resource [activemq.xml]
2012-10-23 17:27:47,112 INFO main: [org.springframework.beans.factory.support.DefaultListableBeanFactory] Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3f70119f: defining beans [org.apache.activemq.xbean.XBeanBrokerService#0]; root of factory hierarchy
2012-10-23 17:27:47,448 INFO main: [org.apache.activemq.store.kahadb.plist.PListStore] PListStore:[/home/jel/proto5/tmp/activemq-data/localhost/tmp_storage] started
2012-10-23 17:27:47,510 INFO JMX connector: [org.apache.activemq.broker.jmx.ManagementContext] JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
2012-10-23 17:27:47,525 INFO main: [org.apache.activemq.broker.BrokerService] Using Persistence Adapter: MultiKahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB][KahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB/queue#3a#2f#2fb], KahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB/0]]
2012-10-23 17:27:47,619 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] KahaDB is version 4
2012-10-23 17:27:47,619 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] KahaDB is version 4
2012-10-23 17:27:47,644 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
2012-10-23 17:27:47,644 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
2012-10-23 17:27:47,943 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2 operations from the journal in 0.315 seconds.
2012-10-23 17:27:47,943 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2 operations from the journal in 0.315 seconds.
2012-10-23 17:27:47,991 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
2012-10-23 17:27:47,991 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
2012-10-23 17:27:52,650 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:27:52,650 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:27:52,655 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:27:52,655 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:27:57,675 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:27:57,675 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:27:57,680 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:27:57,680 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:02,700 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:02,700 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:02,704 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:02,704 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:07,724 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:07,724 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:07,728 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:07,728 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:12,748 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:12,748 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:12,752 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:12,752 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:17,772 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:17,772 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:17,776 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2393052, full gc candidates set: [173]
2012-10-23 17:28:17,776 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2393052, full gc candidates set: [173]
2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2393052, []
2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2393052, []
2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:17,777 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:17,777 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:22,797 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:22,797 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:22,801 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:22,801 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:27,821 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:27,821 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:27,825 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:27,825 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:27,951 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2462 operations from the journal in 39.96 seconds.
2012-10-23 17:28:27,951 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2462 operations from the journal in 39.96 seconds.
2012-10-23 17:28:27,953 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:27,953 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:27,964 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:27,964 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:28,034 INFO main: [org.apache.activemq.broker.BrokerService] Apache ActiveMQ 5.7.0 (broker, ID:perf1srv.dictao.com-59285-1351006072342-0:1) is starting
2012-10-23 17:28:28,466 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:28,466 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:101, full gc candidates set: [444, 445]
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:101, full gc candidates set: [444, 445]
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:28,469 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:28,469 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:28,864 INFO main: [org.apache.activemq.store.kahadb.MultiKahaDBTransactionStore] pending local transactions: [XID:[61616,globalId=49443a70657266317372762e64696374616f2e636f6d2d34303431352d313335313030343035313632392d333a31,branchId=31303039]]
2012-10-23 17:28:28,864 INFO main: [org.apache.activemq.store.kahadb.MultiKahaDBTransactionStore] pending local transactions: [XID:[61616,globalId=49443a70657266317372762e64696374616f2e636f6d2d34303431352d313335313030343035313632392d333a31,branchId=31303039]]
2012-10-23 17:28:29,024 INFO main: [org.apache.activemq.store.kahadb.plist.PListStore] PListStore:[/home/jel/proto5/tmp/activemq-data/localhost/tmp_storage] initialized
2012-10-23 17:28:29,361 INFO main: [org.apache.activemq.broker.BrokerService] Apache ActiveMQ 5.7.0 (broker, ID:perf1srv.dictao.com-59285-1351006072342-0:1) started
2012-10-23 17:28:29,361 INFO main: [org.apache.activemq.broker.BrokerService] For help or more information please see: http://activemq.apache.org
2012-10-23 17:28:29,416 INFO main: [org.apache.activemq.broker.TransportConnector] Connector vm://broker Started
Oct 23, 2012 5:28:29 PM com.sun.xml.ws.transport.http.servlet.WSServletContextListener contextInitialized
INFO: WSSERVLET12: JAX-WS context listener initializing
Oct 23, 2012 5:28:30 PM com.sun.xml.ws.transport.http.servlet.WSServletDelegate <init>
INFO: WSSERVLET14: JAX-WS servlet initializing
Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor manager.xml
Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.HostConfig deployDescriptor
INFO: Deploying configuration descriptor ROOT.xml
Oct 23, 2012 5:28:30 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-24080
Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 45319 ms
2012-10-23 17:28:32,845 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:32,845 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:32,851 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:32,851 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:33,490 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:33,490 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:33,493 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:33,493 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:37,871 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:37,871 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:37,876 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:37,876 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:38,513 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:38,513 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:38,516 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:38,516 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:42,896 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:42,896 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:42,901 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:42,901 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:43,536 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:43,536 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:43,540 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:43,540 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:47,921 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:47,921 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2405814, full gc candidates set: [173]
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2405814, full gc candidates set: [173]
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2405814, []
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2405814, []
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:47,926 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:47,926 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:48,560 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:48,560 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:48,563 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:48,563 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:52,946 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:52,946 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:52,950 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:52,950 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:53,583 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:53,583 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:53,586 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:53,586 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:57,970 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:57,970 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:57,974 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:57,974 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
2012-10-23 17:28:58,606 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:58,606 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:8225, full gc candidates set: [444, 445]
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:8225, full gc candidates set: [444, 445]
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:28:58,609 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
{noformat}
Later, I see lots of
{noformat}
2012-10-23 17:29:59,190 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 545:2227274, full gc candidates set: [444, 445, 446, 447, 448, 449, 450, 451, 452, 453, 454, 455, 456, 457, 458, 459, 460, 461, 462, 463, 464, 465, 466, 467, 468, 469, 470, 471, 472, 473, 474, 475, 476, 477, 478, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 507, 508, 509, 510, 511, 512, 513, 514, 515, 516, 517, 518, 519, 520, 521, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545]
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 545:2227274, full gc candidates set: [444, 445, 446, 447, 448, 449, 450, 451, 452, 453, 454, 455, 456, 457, 458, 459, 460, 461, 462, 463, 464, 465, 466, 467, 468, 469, 470, 471, 472, 473, 474, 475, 476, 477, 478, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 507, 508, 509, 510, 511, 512, 513, 514, 515, 516, 517, 518, 519, 520, 521, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545]
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] [Updated] (AMQ-4128) kahaDB journal file never gets
reclaimed after broker process crash
Posted by "Gilles Harloux (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/AMQ-4128?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Gilles Harloux updated AMQ-4128:
--------------------------------
Attachment: db-444.log
> kahaDB journal file never gets reclaimed after broker process crash
> -------------------------------------------------------------------
>
> Key: AMQ-4128
> URL: https://issues.apache.org/jira/browse/AMQ-4128
> Project: ActiveMQ
> Issue Type: Bug
> Components: Message Store
> Affects Versions: 5.7.0
> Environment: rhel 5.3, tomcat 6.0.35, jdk 1.6.0_35
> Reporter: Gilles Harloux
> Attachments: db-444.log
>
>
> (See this thread for the original report: http://activemq.2283324.n4.nabble.com/KahaDB-No-messages-but-log-files-not-reclaimed-and-StorePercentUsage-above-100-td4658074.html)
> Setup: Embedded broker, mKahaDB store, transactions. Sometimes, when sigkill'ing the process and starting again, some kahaBD journal file won't ever get reclaimed, thus filing the disk and ultimately stopping the system.
> The logs O see look a lot to me like logs from this report: https://issues.apache.org/jira/browse/AMQ-3866
> I'll attach such a log file (db-444.log, matching logs below).
> Logs for the restart part (the app runs inside tomcat):
> {noformat}
> Listening for transport dt_socket at address: 24001
> Oct 23, 2012 5:27:45 PM org.apache.catalina.core.AprLifecycleListener init
> INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /opt/jdk1.6.0_33/jre/lib/amd64/server:/opt/jdk1.6.0_33/jre/lib/amd64:/opt/jdk1.6.0_33/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> Oct 23, 2012 5:27:45 PM org.apache.coyote.http11.Http11Protocol init
> INFO: Initializing Coyote HTTP/1.1 on http-24080
> Oct 23, 2012 5:27:45 PM org.apache.catalina.startup.Catalina load
> INFO: Initialization processed in 712 ms
> Oct 23, 2012 5:27:45 PM org.apache.catalina.core.StandardService start
> INFO: Starting service Catalina
> Oct 23, 2012 5:27:45 PM org.apache.catalina.core.StandardEngine start
> INFO: Starting Servlet Engine: Apache Tomcat/6.0.35
> Oct 23, 2012 5:27:45 PM org.apache.catalina.startup.HostConfig deployDescriptor
> INFO: Deploying configuration descriptor server.xml
> 2012-10-23 17:27:46,347 INFO main: [scratch.proto5.Bootstrap] bootstrap.+
> 2012-10-23 17:27:46,460 INFO main: [org.apache.activemq.xbean.XBeanBrokerFactory$1] Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@20ca5bff: startup date [Tue Oct 23 17:27:46 CEST 2012]; root of context hierarchy
> 2012-10-23 17:27:46,553 INFO main: [org.apache.xbean.spring.context.v2.XBeanXmlBeanDefinitionReader] Loading XML bean definitions from class path resource [activemq.xml]
> 2012-10-23 17:27:47,112 INFO main: [org.springframework.beans.factory.support.DefaultListableBeanFactory] Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@3f70119f: defining beans [org.apache.activemq.xbean.XBeanBrokerService#0]; root of factory hierarchy
> 2012-10-23 17:27:47,448 INFO main: [org.apache.activemq.store.kahadb.plist.PListStore] PListStore:[/home/jel/proto5/tmp/activemq-data/localhost/tmp_storage] started
> 2012-10-23 17:27:47,510 INFO JMX connector: [org.apache.activemq.broker.jmx.ManagementContext] JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
> 2012-10-23 17:27:47,525 INFO main: [org.apache.activemq.broker.BrokerService] Using Persistence Adapter: MultiKahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB][KahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB/queue#3a#2f#2fb], KahaDBPersistenceAdapter[/home/jel/proto5/tmp/mKahaDB/0]]
> 2012-10-23 17:27:47,619 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] KahaDB is version 4
> 2012-10-23 17:27:47,619 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] KahaDB is version 4
> 2012-10-23 17:27:47,644 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
> 2012-10-23 17:27:47,644 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
> 2012-10-23 17:27:47,943 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2 operations from the journal in 0.315 seconds.
> 2012-10-23 17:27:47,943 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2 operations from the journal in 0.315 seconds.
> 2012-10-23 17:27:47,991 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
> 2012-10-23 17:27:47,991 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal ...
> 2012-10-23 17:27:52,650 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:27:52,650 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:27:52,655 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:27:52,655 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:27:57,675 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:27:57,675 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:27:57,680 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:27:57,680 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:02,700 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:02,700 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:02,704 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:02,704 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:07,724 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:07,724 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:07,728 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:07,728 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:12,748 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:12,748 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:12,752 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:12,752 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:17,772 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:17,772 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:17,776 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2393052, full gc candidates set: [173]
> 2012-10-23 17:28:17,776 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2393052, full gc candidates set: [173]
> 2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2393052, []
> 2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2393052, []
> 2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:17,777 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:17,777 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:17,777 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:22,797 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:22,797 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:22,801 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:22,801 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:27,821 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:27,821 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:27,825 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:27,825 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:27,951 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2462 operations from the journal in 39.96 seconds.
> 2012-10-23 17:28:27,951 INFO main: [org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 2462 operations from the journal in 39.96 seconds.
> 2012-10-23 17:28:27,953 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:27,953 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:27,964 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:27,964 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:28,034 INFO main: [org.apache.activemq.broker.BrokerService] Apache ActiveMQ 5.7.0 (broker, ID:perf1srv.dictao.com-59285-1351006072342-0:1) is starting
> 2012-10-23 17:28:28,466 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:28,466 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:101, full gc candidates set: [444, 445]
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:101, full gc candidates set: [444, 445]
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:28,469 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:28,469 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:28,469 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:28,864 INFO main: [org.apache.activemq.store.kahadb.MultiKahaDBTransactionStore] pending local transactions: [XID:[61616,globalId=49443a70657266317372762e64696374616f2e636f6d2d34303431352d313335313030343035313632392d333a31,branchId=31303039]]
> 2012-10-23 17:28:28,864 INFO main: [org.apache.activemq.store.kahadb.MultiKahaDBTransactionStore] pending local transactions: [XID:[61616,globalId=49443a70657266317372762e64696374616f2e636f6d2d34303431352d313335313030343035313632392d333a31,branchId=31303039]]
> 2012-10-23 17:28:29,024 INFO main: [org.apache.activemq.store.kahadb.plist.PListStore] PListStore:[/home/jel/proto5/tmp/activemq-data/localhost/tmp_storage] initialized
> 2012-10-23 17:28:29,361 INFO main: [org.apache.activemq.broker.BrokerService] Apache ActiveMQ 5.7.0 (broker, ID:perf1srv.dictao.com-59285-1351006072342-0:1) started
> 2012-10-23 17:28:29,361 INFO main: [org.apache.activemq.broker.BrokerService] For help or more information please see: http://activemq.apache.org
> 2012-10-23 17:28:29,416 INFO main: [org.apache.activemq.broker.TransportConnector] Connector vm://broker Started
> Oct 23, 2012 5:28:29 PM com.sun.xml.ws.transport.http.servlet.WSServletContextListener contextInitialized
> INFO: WSSERVLET12: JAX-WS context listener initializing
> Oct 23, 2012 5:28:30 PM com.sun.xml.ws.transport.http.servlet.WSServletDelegate <init>
> INFO: WSSERVLET14: JAX-WS servlet initializing
> Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.HostConfig deployDescriptor
> INFO: Deploying configuration descriptor manager.xml
> Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.HostConfig deployDescriptor
> INFO: Deploying configuration descriptor ROOT.xml
> Oct 23, 2012 5:28:30 PM org.apache.coyote.http11.Http11Protocol start
> INFO: Starting Coyote HTTP/1.1 on http-24080
> Oct 23, 2012 5:28:30 PM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 45319 ms
> 2012-10-23 17:28:32,845 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:32,845 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:32,851 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:32,851 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:33,490 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:33,490 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:33,493 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:33,493 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:37,871 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:37,871 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:37,876 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:37,876 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:38,513 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:38,513 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:38,516 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:38,516 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:42,896 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:42,896 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:42,901 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:42,901 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:43,536 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:43,536 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:43,540 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:43,540 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:47,921 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:47,921 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2405814, full gc candidates set: [173]
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 173:2405814, full gc candidates set: [173]
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2405814, []
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:173:2405814, []
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:47,926 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:47,926 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:47,926 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:48,560 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:48,560 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:48,563 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:48,563 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:52,946 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:52,946 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:52,950 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:52,950 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:53,583 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:53,583 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:53,586 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:53,586 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:57,970 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:57,970 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:57,974 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:57,974 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> 2012-10-23 17:28:58,606 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:58,606 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:8225, full gc candidates set: [444, 445]
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 445:8225, full gc candidates set: [444, 445]
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:58,609 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:28:58,609 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint done.
> {noformat}
> Later, I see lots of
> {noformat}
> 2012-10-23 17:29:59,190 DEBUG ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Checkpoint started.
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 545:2227274, full gc candidates set: [444, 445, 446, 447, 448, 449, 450, 451, 452, 453, 454, 455, 456, 457, 458, 459, 460, 461, 462, 463, 464, 465, 466, 467, 468, 469, 470, 471, 472, 473, 474, 475, 476, 477, 478, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 507, 508, 509, 510, 511, 512, 513, 514, 515, 516, 517, 518, 519, 520, 521, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545]
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] Last update: 545:2227274, full gc candidates set: [444, 445, 446, 447, 448, 449, 450, 451, 452, 453, 454, 455, 456, 457, 458, 459, 460, 461, 462, 463, 464, 465, 466, 467, 468, 469, 470, 471, 472, 473, 474, 475, 476, 477, 478, 479, 480, 481, 482, 483, 484, 485, 486, 487, 488, 489, 490, 491, 492, 493, 494, 495, 496, 497, 498, 499, 500, 501, 502, 503, 504, 505, 506, 507, 508, 509, 510, 511, 512, 513, 514, 515, 516, 517, 518, 519, 520, 521, 522, 523, 524, 525, 526, 527, 528, 529, 530, 531, 532, 533, 534, 535, 536, 537, 538, 539, 540, 541, 542, 543, 544, 545]
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates after first tx:444:627935, []
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> 2012-10-23 17:29:59,270 TRACE ActiveMQ Journal Checkpoint Worker: [org.apache.activemq.store.kahadb.MessageDatabase] gc candidates: []
> {noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira