diff --git a/solr/CHANGES.txt b/solr/CHANGES.txt index 64ae7ebb353..e426320317e 100644 --- a/solr/CHANGES.txt +++ b/solr/CHANGES.txt @@ -112,6 +112,11 @@ Apache ZooKeeper 3.4.6 Detailed Change List ---------------------- +New Features +---------------------- + +* SOLR-6403: TransactionLog replay status logging. (Mark Miller) + Bug Fixes ---------------------- diff --git a/solr/core/src/java/org/apache/solr/update/HdfsTransactionLog.java b/solr/core/src/java/org/apache/solr/update/HdfsTransactionLog.java index 73df56e6d3f..73ab0e7215c 100644 --- a/solr/core/src/java/org/apache/solr/update/HdfsTransactionLog.java +++ b/solr/core/src/java/org/apache/solr/update/HdfsTransactionLog.java @@ -421,6 +421,16 @@ public class HdfsTransactionLog extends TransactionLog { return "LogReader{" + "file=" + tlogFile + ", position=" + fis.position() + ", end=" + fos.size() + "}"; } } + + @Override + public long currentPos() { + return fis.position(); + } + + @Override + public long currentSize() { + return sz; + } } diff --git a/solr/core/src/java/org/apache/solr/update/TransactionLog.java b/solr/core/src/java/org/apache/solr/update/TransactionLog.java index 08ba6c46913..f5aef97651e 100644 --- a/solr/core/src/java/org/apache/solr/update/TransactionLog.java +++ b/solr/core/src/java/org/apache/solr/update/TransactionLog.java @@ -647,6 +647,18 @@ public class TransactionLog { } } + // returns best effort current position + // for info purposes + public long currentPos() { + return fis.position(); + } + + // returns best effort current size + // for info purposes + public long currentSize() throws IOException { + return channel.size(); + } + } public abstract class ReverseReader { diff --git a/solr/core/src/java/org/apache/solr/update/UpdateLog.java b/solr/core/src/java/org/apache/solr/update/UpdateLog.java index 6e91d1f4fc5..8ea86fa0de2 100644 --- a/solr/core/src/java/org/apache/solr/update/UpdateLog.java +++ b/solr/core/src/java/org/apache/solr/update/UpdateLog.java @@ -24,6 +24,7 @@ import java.io.File; import java.io.FileNotFoundException; import java.io.FilenameFilter; import java.io.IOException; +import java.text.DecimalFormat; import java.util.ArrayList; import java.util.Arrays; import java.util.Collection; @@ -68,6 +69,7 @@ import org.slf4j.LoggerFactory; /** @lucene.experimental */ public class UpdateLog implements PluginInfoInitialized { + private static final long STATUS_TIME = TimeUnit.NANOSECONDS.convert(60, TimeUnit.SECONDS); public static String LOG_FILENAME_PATTERN = "%s.%019d"; public static String TLOG_NAME="tlog"; @@ -1243,7 +1245,7 @@ public class UpdateLog implements PluginInfoInitialized { public void doReplay(TransactionLog translog) { try { loglog.warn("Starting log replay " + translog + " active="+activeLog + " starting pos=" + recoveryInfo.positionOfStart); - + long lastStatusTime = System.nanoTime(); tlogReader = translog.getReader(recoveryInfo.positionOfStart); // NOTE: we don't currently handle a core reload during recovery. This would cause the core @@ -1254,12 +1256,27 @@ public class UpdateLog implements PluginInfoInitialized { long commitVersion = 0; int operationAndFlags = 0; + long nextCount = 0; for(;;) { Object o = null; if (cancelApplyBufferUpdate) break; try { if (testing_logReplayHook != null) testing_logReplayHook.run(); + if (nextCount++ % 1000 == 0) { + long now = System.nanoTime(); + if (now - lastStatusTime > STATUS_TIME) { + lastStatusTime = now; + long cpos = tlogReader.currentPos(); + long csize = tlogReader.currentSize(); + loglog.info( + "log replay status {} active={} starting pos={} current pos={} current size={} % read={}", + translog, activeLog, recoveryInfo.positionOfStart, cpos, csize, + new DecimalFormat("###").format(cpos / (double) csize * 100)); + + } + } + o = null; o = tlogReader.next(); if (o == null && activeLog) {