You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hbase.apache.org by zg...@apache.org on 2019/09/19 00:38:48 UTC
[hbase] 02/02: HBASE-23037 Make the split WAL related log more
readable (#632)
This is an automated email from the ASF dual-hosted git repository.
zghao pushed a commit to branch branch-2.1
in repository https://gitbox.apache.org/repos/asf/hbase.git
commit 79e6a959ab0826655e64c3bffb2690386d09cfa7
Author: Guanghao Zhang <zg...@apache.org>
AuthorDate: Wed Sep 18 21:44:05 2019 +0800
HBASE-23037 Make the split WAL related log more readable (#632)
Signed-off-by: Duo Zhang <zh...@apache.org>
---
.../hadoop/hbase/master/SplitLogManager.java | 11 +++++++----
.../org/apache/hadoop/hbase/wal/WALSplitter.java | 23 +++++++++++++++-------
2 files changed, 23 insertions(+), 11 deletions(-)
diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/SplitLogManager.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/SplitLogManager.java
index 414fc98..f0411d4 100644
--- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/SplitLogManager.java
+++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/SplitLogManager.java
@@ -51,6 +51,7 @@ import org.apache.hadoop.hbase.coordination.SplitLogManagerCoordination.SplitLog
import org.apache.hadoop.hbase.log.HBaseMarkers;
import org.apache.hadoop.hbase.monitoring.MonitoredTask;
import org.apache.hadoop.hbase.monitoring.TaskMonitor;
+import org.apache.hadoop.hbase.procedure2.util.StringUtils;
import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
import org.apache.hadoop.hbase.util.FSUtils;
import org.apache.hadoop.hbase.util.HasThread;
@@ -289,10 +290,12 @@ public class SplitLogManager {
}
SplitLogCounters.tot_mgr_log_split_batch_success.increment();
}
- String msg = "Finished splitting (more than or equal to) " + totalSize +
- " bytes in " + ((batch == null)? 0: batch.installed) +
- " log files in " + logDirs + " in " +
- ((startTime == 0)? startTime: (EnvironmentEdgeManager.currentTime() - startTime)) + "ms";
+ String msg =
+ "Finished splitting (more than or equal to) " + StringUtils.humanSize(totalSize) + " (" +
+ totalSize + " bytes) in " + ((batch == null) ? 0 : batch.installed) + " log files in " +
+ logDirs + " in " +
+ ((startTime == 0) ? startTime : (EnvironmentEdgeManager.currentTime() - startTime)) +
+ "ms";
status.markComplete(msg);
LOG.info(msg);
return totalSize;
diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/wal/WALSplitter.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/wal/WALSplitter.java
index fd56d73..afc36d0 100644
--- a/hbase-server/src/main/java/org/apache/hadoop/hbase/wal/WALSplitter.java
+++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/wal/WALSplitter.java
@@ -71,6 +71,7 @@ import org.apache.hadoop.hbase.master.SplitLogManager;
import org.apache.hadoop.hbase.monitoring.MonitoredTask;
import org.apache.hadoop.hbase.monitoring.TaskMonitor;
import org.apache.hadoop.hbase.regionserver.HRegion;
+import org.apache.hadoop.hbase.procedure2.util.StringUtils;
import org.apache.hadoop.hbase.regionserver.LastSequenceId;
import org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL;
import org.apache.hadoop.hbase.regionserver.wal.WALCellCodec;
@@ -78,6 +79,7 @@ import org.apache.hadoop.hbase.util.Bytes;
import org.apache.hadoop.hbase.util.CancelableProgressable;
import org.apache.hadoop.hbase.util.ClassSize;
import org.apache.hadoop.hbase.util.CollectionUtils.IOExceptionSupplier;
+import org.apache.hadoop.hbase.util.EnvironmentEdgeManager;
import org.apache.hadoop.hbase.util.FSUtils;
import org.apache.hadoop.hbase.util.Pair;
import org.apache.hadoop.hbase.util.Threads;
@@ -246,9 +248,11 @@ public class WALSplitter {
"Splitting log file " + logfile.getPath() + "into a temporary staging area.");
Reader logFileReader = null;
this.fileBeingSplit = logfile;
+ long startTS = EnvironmentEdgeManager.currentTime();
try {
long logLength = logfile.getLen();
- LOG.info("Splitting WAL={}, length={}", logPath, logLength);
+ LOG.info("Splitting WAL={}, size={} ({} bytes)", logPath, StringUtils.humanSize(logLength),
+ logLength);
status.setStatus("Opening log file");
if (reporter != null && !reporter.progress()) {
progress_failed = true;
@@ -259,6 +263,8 @@ public class WALSplitter {
LOG.warn("Nothing to split in WAL={}", logPath);
return true;
}
+ long openCost = EnvironmentEdgeManager.currentTime() - startTS;
+ LOG.info("Open WAL={} cost {} ms", logPath, openCost);
int numOpenedFilesBeforeReporting = conf.getInt("hbase.splitlog.report.openedfiles", 3);
int numOpenedFilesLastCheck = 0;
outputSink.setReporter(reporter);
@@ -266,6 +272,7 @@ public class WALSplitter {
outputSinkStarted = true;
Entry entry;
Long lastFlushedSequenceId = -1L;
+ startTS = EnvironmentEdgeManager.currentTime();
while ((entry = getNextLogLine(logFileReader, logPath, skipErrors)) != null) {
byte[] region = entry.getKey().getEncodedRegionName();
String encodedRegionNameAsStr = Bytes.toString(region);
@@ -349,11 +356,13 @@ public class WALSplitter {
progress_failed = outputSink.finishWritingAndClose() == null;
}
} finally {
- String msg =
- "Processed " + editsCount + " edits across " + outputSink.getNumberOfRecoveredRegions()
- + " regions; edits skipped=" + editsSkipped + "; log file=" + logPath +
- ", length=" + logfile.getLen() + // See if length got updated post lease recovery
- ", corrupted=" + isCorrupted + ", progress failed=" + progress_failed;
+ long processCost = EnvironmentEdgeManager.currentTime() - startTS;
+ // See if length got updated post lease recovery
+ String msg = "Processed " + editsCount + " edits across " +
+ outputSink.getNumberOfRecoveredRegions() + " regions cost " + processCost +
+ " ms; edits skipped=" + editsSkipped + "; WAL=" + logPath + ", size=" +
+ StringUtils.humanSize(logfile.getLen()) + ", length=" + logfile.getLen() +
+ ", corrupted=" + isCorrupted + ", progress failed=" + progress_failed;
LOG.info(msg);
status.markComplete(msg);
}
@@ -1707,7 +1716,7 @@ public class WALSplitter {
throws InterruptedException, ExecutionException {
for (final Map.Entry<byte[], RegionEntryBuffer> buffer : entryBuffers.buffers.entrySet()) {
LOG.info("Submitting writeThenClose of {}",
- Arrays.toString(buffer.getValue().encodedRegionName));
+ Bytes.toString(buffer.getValue().encodedRegionName));
completionService.submit(new Callable<Void>() {
@Override
public Void call() throws Exception {