Stefan Warten created AMQ-5695:
----------------------------------
Summary: KahaDB not cleaning up log files
Key: AMQ-5695
URL: https://issues.apache.org/jira/browse/AMQ-5695
Project: ActiveMQ
Issue Type: Bug
Affects Versions: 5.11.1
Reporter: Stefan Warten
Since we have upgraded ActiveMQ from 5.10.0 to 5.11.1, KahaDB is not cleaning
up log files properly. It seems to keep all of them. It helped once to restart
the service and minutes later, ActiveMQ cleaned up 95% of log files but mostly
it is not cleaning up at all.
When partition was full, I stopped ActiveMQ, copied the KahaDB to another host
and started it with empty queues again. Then I forwarded all messages from that
other host back. Even when all messages were forwarded and all queues were
empty, the old KahaDB log files were not cleaned up.
I stopped ActiveMQ, removed db.data and db.redo to rebuild index which took
around 3h (350GB of log files) but still, the log files are not cleaned up.
[...]
2015-03-30 18:21:55,532 | INFO | @13786:158508, 321300000 entries recovered ..
| org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
2015-03-30 18:22:02,090 | INFO | Recovery replayed 321378917 operations from
the journal in 9226.159 seconds. |
org.apache.activemq.store.kahadb.MessageDatabase | WrapperSimpleAppMain
2015-03-30 18:22:02,402 | INFO | installing runtimeConfiguration plugin |
org.apache.activemq.plugin.RuntimeConfigurationPlugin | WrapperSimpleAppMain
2015-03-30 18:22:04,576 | INFO | Apache ActiveMQ 5.11.1
(prd-mig-02-sat.example.com,
ID:prd-mig-02-sat.example.com-26260-1427730492201-1:1) is starting |
org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
2015-03-30 18:22:04,946 | INFO | pending local transactions: [] |
org.apache.activemq.store.kahadb.MultiKahaDBTransactionStore |
WrapperSimpleAppMain
2015-03-30 18:22:08,488 | INFO | Configuration class path resource
[activemq.xml] | org.apache.activemq.plugin.RuntimeConfigurationBroker |
WrapperSimpleAppMain
2015-03-30 18:22:12,198 | INFO | Listening for connections at:
nio://prd-mig-02-sat.example.com:61616?transport.reuseAddress=true |
org.apache.activemq.transport.TransportServerThreadSupport |
WrapperSimpleAppMain
2015-03-30 18:22:12,199 | INFO | Connector openwire started |
org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,232 | INFO | Listening for connections at:
stomp+nio://prd-mig-02-sat.example.com:61613?transport.closeAsync=false&transport.reuseAddress=true
| org.apache.activemq.transport.TransportServerThreadSupport |
WrapperSimpleAppMain
2015-03-30 18:22:12,234 | INFO | Connector stomp started |
org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,237 | INFO | Establishing network connection from
vm://prd-mig-02-sat.example.com?async=false&network=true to
tcp://172.42.15.40:61616 |
org.apache.activemq.network.DiscoveryNetworkConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,286 | INFO | Connector vm://prd-mig-02-sat.example.com
started | org.apache.activemq.broker.TransportConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,318 | INFO | Establishing network connection from
vm://prd-mig-02-sat.example.com?async=false&network=true to
tcp://172.42.15.39:61616 |
org.apache.activemq.network.DiscoveryNetworkConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,321 | INFO | Network Connector
DiscoveryNetworkConnector:FORWARDER:BrokerService[prd-mig-02-sat.example.com]
started | org.apache.activemq.network.NetworkConnector | WrapperSimpleAppMain
2015-03-30 18:22:12,325 | INFO | Apache ActiveMQ 5.11.1
(prd-mig-02-sat.example.com,
ID:prd-mig-02-sat.example.com-26260-1427730492201-1:1) started |
org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
2015-03-30 18:22:12,326 | INFO | For help or more information please see:
http://activemq.apache.org | org.apache.activemq.broker.BrokerService |
WrapperSimpleAppMain
2015-03-30 18:22:12,381 | INFO | Network connection between
vm://prd-mig-02-sat.example.com#0 and tcp:///172.42.15.40:61616@58567
(prdvip-amq-01-sat.example.com) has been established. |
org.apache.activemq.network.DemandForwardingBridgeSupport |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp:///172.42.15.40:61616@58567, localBroker=
vm://prd-mig-02-sat.example.com#0
2015-03-30 18:22:12,381 | INFO | Network connection between
vm://prd-mig-02-sat.example.com#2 and tcp:///172.42.15.39:61616@4523
(prdvip-amq-02-sat.example.com) has been established. |
org.apache.activemq.network.DemandForwardingBridgeSupport |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp:///172.42.15.39:61616@4523, localBroker=
vm://prd-mig-02-sat.example.com#2
2015-03-31 04:21:13,971 | INFO | Slow KahaDB access: Journal append took: 0
ms, Index update took 1936 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:07:34,560 | INFO | Slow KahaDB access: cleanup took 30113 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:07:39,076 | INFO | Slow KahaDB access: cleanup took 4015 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:08:48,101 | INFO | Slow KahaDB access: Journal append took: 0
ms, Index update took 2667 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:09:39,629 | INFO | Slow KahaDB access: cleanup took 3470 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:10:20,789 | INFO | Slow KahaDB access: Journal append took: 0
ms, Index update took 2666 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:11:02,925 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2714 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:11:23,673 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2632 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:11:53,784 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2736 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:12:19,786 | INFO | Slow KahaDB access: Journal append took: 0
ms, Index update took 2663 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:13:08,826 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2770 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:13:32,862 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2819 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:14:08,931 | INFO | Slow KahaDB access: Journal append took: 0
ms, Index update took 2885 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
2015-03-31 06:14:42,495 | INFO | Slow KahaDB access: cleanup took 3480 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:16:13,040 | INFO | Slow KahaDB access: cleanup took 3341 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:16:43,920 | INFO | Slow KahaDB access: cleanup took 3760 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:17:14,221 | INFO | Slow KahaDB access: cleanup took 3717 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:17:44,498 | INFO | Slow KahaDB access: cleanup took 3722 |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | ActiveMQ Journal
Checkpoint Worker
2015-03-31 06:18:20,988 | INFO | Slow KahaDB access: Journal append took: 1
ms, Index update took 2971 ms |
org.apache.activemq.store.kahadb.AbstractKahaDBStore | JobScheduler:JMS
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
