Skip to content

Commit

Permalink
HBASE-23037 Make the split WAL related log more readable (#632)
Browse files Browse the repository at this point in the history
Signed-off-by: Duo Zhang <[email protected]>
  • Loading branch information
infraio authored Sep 18, 2019
1 parent 18ac610 commit 25bcc91
Show file tree
Hide file tree
Showing 3 changed files with 24 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,7 @@
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;
Expand Down Expand Up @@ -289,10 +290,12 @@ public long splitLogDistributed(final Set<ServerName> serverNames, final List<Pa
}
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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,6 @@

import java.io.IOException;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
Expand Down Expand Up @@ -73,7 +72,7 @@ boolean executeCloseTask(CompletionService<Void> completionService, List<IOExcep
for (final Map.Entry<byte[], WALSplitter.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 {
Expand Down Expand Up @@ -148,4 +147,4 @@ private Path writeThenClose(WALSplitter.RegionEntryBuffer buffer) throws IOExcep
}
return dst;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -44,11 +44,13 @@
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.procedure2.util.StringUtils;
import org.apache.hadoop.hbase.regionserver.LastSequenceId;
import org.apache.hadoop.hbase.regionserver.wal.WALCellCodec;
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.EnvironmentEdgeManager;
import org.apache.hadoop.hbase.util.FSUtils;
import org.apache.hadoop.hbase.wal.WAL.Entry;
import org.apache.hadoop.hbase.wal.WAL.Reader;
Expand Down Expand Up @@ -221,9 +223,11 @@ boolean splitLogFile(FileStatus logfile, CancelableProgressable reporter) throws
"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;
Expand All @@ -234,13 +238,16 @@ boolean splitLogFile(FileStatus logfile, CancelableProgressable reporter) throws
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);
outputSink.startWriterThreads();
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);
Expand Down Expand Up @@ -324,11 +331,13 @@ boolean splitLogFile(FileStatus logfile, CancelableProgressable reporter) throws
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);
}
Expand Down

0 comments on commit 25bcc91

Please sign in to comment.