| <div class="wiki-content maincontent"><p>Clean-up of un-referenced KahaDB journal log files <strong><code>data-<id>.log</code></strong> will occur every 30 seconds by default. If a data file is in-use it will not be cleaned up.</p><p>A data file may be in-use because:</p><ol><li>It contains a pending message for a destination or durable topic subscription</li><li>It contains an ACK for a message which is in an in-use data file - the ACK cannot be removed as a recovery would then mark the message for redelivery</li><li>The journal references a pending transaction</li><li>It is a journal file, and there may be a pending write to it</li></ol><p><span style="line-height: 1.4285715;">The <strong><code>TRACE</code></strong> level logging of the <strong><code>org.apache.activemq.store.kahadb.MessageDatabase</code></strong> class provides insight into the cleanup process and will allow you to determine why a given data file is considered in-use and as a result, not a candidate for cleanup.</span></p><p>To debug, add the following (or similar) to your <strong><code>log4j.properties</code></strong> file (if needed):</p><div class="code panel pdl" style="border-width: 1px;"><div class="codeContent panelContent pdl"> |
| <pre class="brush: java; gutter: false; theme: Default" style="font-size:12px;">log4j.appender.kahadb=org.apache.log4j.RollingFileAppender |
| log4j.appender.kahadb.file=${activemq.base}/data/kahadb.log |
| log4j.appender.kahadb.maxFileSize=1024KB |
| log4j.appender.kahadb.maxBackupIndex=5 |
| log4j.appender.kahadb.append=true |
| log4j.appender.kahadb.layout=org.apache.log4j.PatternLayout |
| log4j.appender.kahadb.layout.ConversionPattern=%d [%-15.15t] %-5p %-30.30c{1} - %m%n |
| log4j.logger.org.apache.activemq.store.kahadb.MessageDatabase=TRACE, kahadb</pre> |
| </div></div><p>Either restart ActiveMQ and let the cleanup process run (give it a minute or two for example) or alternatively apply this logging configuration to a running broker via JMX. The <strong><code>Broker</code></strong> MBean exposes an operation called <strong><code>reloadLog4jProperties</code></strong> in JMX that can be used to tell the broker to reload its <strong><code>log4j.properties</code></strong>. Often its enough to apply this logging configuration for 2-5 minutes and then analyze the broker's log file.</p><p>Examine the log file and look for cleanup of the data files. The process starts with the complete set of known data files and queries the index on a per destination basis to prune this list. Anything that remains is a candidate for cleanup. The trace logging gives the destination and the log file numbers that remain candidates for removal as it iterates through the index.</p><p>At some point you'll hit a destination and the number of data file ids will suddenly drop because that destination references them. It could be a DLQ or an offline durable subscriber. In any event, the logging will help you pinpoint the destinations that are hogging disk space.</p><p>Here is a quick sample:</p><div class="code panel pdl" style="border-width: 1px;"><div class="codeContent panelContent pdl"> |
| <pre class="brush: java; gutter: false; theme: Default" style="font-size:12px;"> TRACE | Last update: 164:41712, full gc candidates set: [86, 87, 163, 164] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after first tx:164:41712, [86, 87, 163] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:A, [86, 87, 163] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:1:B, [86, 87, 163] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:D, [86, 87, 163] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:E, [86, 87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:H, [86, 87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:I, [86, 87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates after dest:0:J, [87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| TRACE | gc candidates: [87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker |
| DEBUG | Cleanup removing the data files: [87] | org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal Checkpoint Worker</pre> |
| </div></div><p>We get one candidate, <strong><code>data-87.log</code></strong> from the existing set of journal data files <strong><code>[86, 87, 163, 164]</code></strong>. There is a current transaction using <strong><code>164</code></strong>, destination (Queue named <strong><code>E</code></strong>) <code>'<strong>0:E</strong>'</code> has some messages in <strong><code>163</code></strong>, destination <code>'<strong>0:I</strong>'</code> has messages in <strong><code>86</code></strong> and <strong><code>87</code></strong> is un-referenced. In this case, there must be some long standing un-acknowledged messages or a very slow consumer on destination <code>'<strong>0:I</strong>'</code>.</p><div class="confluence-information-macro confluence-information-macro-information"><span class="aui-icon aui-icon-small aui-iconfont-info confluence-information-macro-icon"></span><div class="confluence-information-macro-body"><p>The <code>'<strong>0:</strong>'</code> prefix is shorthand for a queue, <code>'<strong>1:</strong>'</code> for a topic. Example: <strong><code>dest:1:B</code></strong> refers to a topic named <strong><code>B</code></strong>.</p></div></div><p> </p><p> </p><hr><h3 id="WhydoKahaDBlogfilesremainaftercleanup-Non-persistentmessages">Non-persistent messages</h3><p>Similar for non-persistent messages that are not stored in your configured KahaDB persistence adapter but get swapped to temp storage once they exceed the broker's configured <strong><code>memoryUsage</code></strong> limit. A similar logging configuration can show details of the cleanup of temp storage.</p><p> </p><div class="code panel pdl" style="border-width: 1px;"><div class="codeContent panelContent pdl"> |
| <pre class="brush: java; gutter: false; theme: Default" style="font-size:12px;">log4j.appender.kahadb=org.apache.log4j.RollingFileAppender |
| log4j.appender.kahadb.file=${activemq.base}/data/kahadb.log |
| log4j.appender.kahadb.maxFileSize=1024KB |
| log4j.appender.kahadb.maxBackupIndex=5 |
| log4j.appender.kahadb.append=true |
| log4j.appender.kahadb.layout=org.apache.log4j.PatternLayout |
| log4j.appender.kahadb.layout.ConversionPattern=%d [%-15.15t] %-5p %-30.30c{1} - %m%n |
| log4j.logger.org.apache.activemq.store.kahadb=TRACE, kahadb |
| log4j.logger.org.apache.activemq.store.kahadb.MessageDatabase=INFO, kahadb |
|  </pre> |
| </div></div><p> </p><p>Note the last line of above logging configuration disables the verbose logging of the KahaDB cleanup task. If that line gets removed, the cleanup details of both KahaDB and temp storage will be logged to the same file but you need to be careful not to mix the logging output.</p></div> |
| |
