This is an automated email from the ASF dual-hosted git repository.
apurtell pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/hbase.git
The following commit(s) were added to refs/heads/master by this push:
new cc88cf0 HBASE-25847 More DEBUG and TRACE level logging in
CatalogJanitor and HbckChore (#3230)
cc88cf0 is described below
commit cc88cf0ecff32d38d55c55b414a621d6d91509b0
Author: Andrew Purtell <[email protected]>
AuthorDate: Wed May 5 17:01:00 2021 -0700
HBASE-25847 More DEBUG and TRACE level logging in CatalogJanitor and
HbckChore (#3230)
Signed-off-by: Bharath Vissapragada <[email protected]>
Signed-off-by: Michael Stack <[email protected]>
---
.../org/apache/hadoop/hbase/master/HbckChore.java | 29 ++++++++-
.../hbase/master/janitor/CatalogJanitor.java | 76 ++++++++++++++++++----
2 files changed, 89 insertions(+), 16 deletions(-)
diff --git
a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/HbckChore.java
b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/HbckChore.java
index 4167e37..917a8d3 100644
--- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/HbckChore.java
+++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/HbckChore.java
@@ -223,7 +223,7 @@ public class HbckChore extends ScheduledChore {
.isTableState(regionInfo.getTable(), TableState.State.DISABLED)) {
disabledTableRegions.add(regionInfo.getRegionNameAsString());
}
- if (regionInfo.isSplitParent()) {
+ if (regionState.isSplit()) {
splitParentRegions.add(regionInfo.getRegionNameAsString());
}
HbckRegionInfo.MetaEntry metaEntry =
@@ -231,7 +231,30 @@ public class HbckChore extends ScheduledChore {
regionState.getStamp());
regionInfoMap.put(regionInfo.getEncodedName(), new
HbckRegionInfo(metaEntry));
}
- LOG.info("Loaded {} regions from in-memory state of AssignmentManager",
regionStates.size());
+ LOG.info("Loaded {} regions ({} disabled, {} split parents) from in-memory
state",
+ regionStates.size(), disabledTableRegions.size(),
splitParentRegions.size());
+ if (LOG.isDebugEnabled()) {
+ Map<RegionState.State,Integer> stateCountMap = new HashMap<>();
+ for (RegionState regionState : regionStates) {
+ stateCountMap.compute(regionState.getState(), (k, v) -> (v == null) ?
1 : v + 1);
+ }
+ StringBuffer sb = new StringBuffer();
+ sb.append("Regions by state: ");
+ stateCountMap.entrySet().forEach(e -> {
+ sb.append(e.getKey());
+ sb.append('=');
+ sb.append(e.getValue());
+ sb.append(' ');
+ }
+ );
+ LOG.debug(sb.toString());
+ }
+ if (LOG.isTraceEnabled()) {
+ for (RegionState regionState : regionStates) {
+ LOG.trace("{}: {}, serverName=", regionState.getRegion(),
regionState.getState(),
+ regionState.getServerName());
+ }
+ }
}
private void loadRegionsFromRSReport() {
@@ -307,7 +330,7 @@ public class HbckChore extends ScheduledChore {
}
numRegions += regionDirs.size();
}
- LOG.info("Loaded {} tables {} regions from filesyetem and found {} orphan
regions",
+ LOG.info("Loaded {} tables {} regions from filesystem and found {} orphan
regions",
tableDirs.size(), numRegions, orphanRegionsOnFS.size());
}
diff --git
a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/janitor/CatalogJanitor.java
b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/janitor/CatalogJanitor.java
index 0e26c2a..0914d53 100644
---
a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/janitor/CatalogJanitor.java
+++
b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/janitor/CatalogJanitor.java
@@ -74,6 +74,8 @@ import org.slf4j.LoggerFactory;
@InterfaceAudience.Private
public class CatalogJanitor extends ScheduledChore {
+ public static final int DEFAULT_HBASE_CATALOGJANITOR_INTERVAL = 300 * 1000;
+
private static final Logger LOG =
LoggerFactory.getLogger(CatalogJanitor.class.getName());
private final AtomicBoolean alreadyRunning = new AtomicBoolean(false);
@@ -88,7 +90,8 @@ public class CatalogJanitor extends ScheduledChore {
public CatalogJanitor(final MasterServices services) {
super("CatalogJanitor-" + services.getServerName().toShortString(),
services,
- services.getConfiguration().getInt("hbase.catalogjanitor.interval",
300000));
+ services.getConfiguration().getInt("hbase.catalogjanitor.interval",
+ DEFAULT_HBASE_CATALOGJANITOR_INTERVAL));
this.services = services;
}
@@ -158,20 +161,30 @@ public class CatalogJanitor extends ScheduledChore {
int gcs = 0;
try {
if (!alreadyRunning.compareAndSet(false, true)) {
- LOG.debug("CatalogJanitor already running");
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("CatalogJanitor already running");
+ }
// -1 indicates previous scan is in progress
return -1;
}
this.lastReport = scanForReport();
if (!this.lastReport.isEmpty()) {
LOG.warn(this.lastReport.toString());
+ } else {
+ if (LOG.isDebugEnabled()) {
+ LOG.debug(this.lastReport.toString());
+ }
}
+
updateAssignmentManagerMetrics();
Map<RegionInfo, Result> mergedRegions = this.lastReport.mergedRegions;
for (Map.Entry<RegionInfo, Result> e : mergedRegions.entrySet()) {
if (this.services.isInMaintenanceMode()) {
// Stop cleaning if the master is in maintenance mode
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("In maintenence mode, not cleaning");
+ }
break;
}
@@ -188,6 +201,9 @@ public class CatalogJanitor extends ScheduledChore {
for (Map.Entry<RegionInfo, Result> e : splitParents.entrySet()) {
if (this.services.isInMaintenanceMode()) {
// Stop cleaning if the master is in maintenance mode
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("In maintenence mode, not cleaning");
+ }
break;
}
@@ -235,6 +251,9 @@ public class CatalogJanitor extends ScheduledChore {
*/
private boolean cleanMergeRegion(final RegionInfo mergedRegion,
List<RegionInfo> parents)
throws IOException {
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Cleaning merged region {}", mergedRegion);
+ }
FileSystem fs = this.services.getMasterFileSystem().getFileSystem();
Path rootdir = this.services.getMasterFileSystem().getRootDir();
Path tabledir = CommonFSUtils.getTableDir(rootdir,
mergedRegion.getTable());
@@ -247,16 +266,23 @@ public class CatalogJanitor extends ScheduledChore {
LOG.warn("Merged region does not exist: " +
mergedRegion.getEncodedName());
}
if (regionFs == null || !regionFs.hasReferences(htd)) {
- LOG.debug(
- "Deleting parents ({}) from fs; merged child {} no longer holds
references", parents
- .stream().map(r ->
RegionInfo.getShortNameToLog(r)).collect(Collectors.joining(", ")),
- mergedRegion);
+ if (LOG.isDebugEnabled()) {
+ LOG.debug(
+ "Deleting parents ({}) from fs; merged child {} no longer holds
references", parents
+ .stream().map(r ->
RegionInfo.getShortNameToLog(r)).collect(Collectors.joining(", ")),
+ mergedRegion);
+ }
ProcedureExecutor<MasterProcedureEnv> pe =
this.services.getMasterProcedureExecutor();
- pe.submitProcedure(
- new GCMultipleMergedRegionsProcedure(pe.getEnvironment(),
mergedRegion, parents));
+ GCMultipleMergedRegionsProcedure mergeRegionProcedure =
+ new GCMultipleMergedRegionsProcedure(pe.getEnvironment(),
mergedRegion, parents);
+ pe.submitProcedure(mergeRegionProcedure);
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Submitted procedure {} for merged region {}",
mergeRegionProcedure,
+ mergedRegion);
+ }
+ // TODO: The above scheduled GCMultipleMergedRegionsProcedure does the
below.
+ // Do we need this?
for (RegionInfo ri : parents) {
- // The above scheduled GCMultipleMergedRegionsProcedure does the below.
- // Do we need this?
this.services.getAssignmentManager().getRegionStates().deleteRegion(ri);
this.services.getServerManager().removeRegion(ri);
}
@@ -300,9 +326,15 @@ public class CatalogJanitor extends ScheduledChore {
static boolean cleanParent(MasterServices services, RegionInfo parent,
Result rowContent)
throws IOException {
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Cleaning parent region {}", parent);
+ }
// Check whether it is a merged region and if it is clean of references.
if (CatalogFamilyFormat.hasMergeRegions(rowContent.rawCells())) {
// Wait until clean of merge parent regions first
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Region {} has merge parents, cleaning them first", parent);
+ }
return false;
}
// Run checks on each daughter split.
@@ -314,14 +346,32 @@ public class CatalogJanitor extends ScheduledChore {
daughters.getFirst() != null ?
daughters.getFirst().getShortNameToLog() : "null";
String daughterB =
daughters.getSecond() != null ?
daughters.getSecond().getShortNameToLog() : "null";
- LOG.debug("Deleting region " + parent.getShortNameToLog() + " because
daughters -- " +
- daughterA + ", " + daughterB + " -- no longer hold references");
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Deleting region " + parent.getShortNameToLog() + " because
daughters -- " +
+ daughterA + ", " + daughterB + " -- no longer hold references");
+ }
ProcedureExecutor<MasterProcedureEnv> pe =
services.getMasterProcedureExecutor();
- pe.submitProcedure(new GCRegionProcedure(pe.getEnvironment(), parent));
+ GCRegionProcedure gcRegionProcedure = new
GCRegionProcedure(pe.getEnvironment(), parent);
+ pe.submitProcedure(gcRegionProcedure);
+ if (LOG.isDebugEnabled()) {
+ LOG.debug("Submitted procedure {} for split parent {}",
gcRegionProcedure, parent);
+ }
// Remove from in-memory states
+ // TODO: The above scheduled GCRegionProcedure does the below. Do we
need this?
services.getAssignmentManager().getRegionStates().deleteRegion(parent);
services.getServerManager().removeRegion(parent);
return true;
+ } else {
+ if (LOG.isDebugEnabled()) {
+ if (!hasNoReferences(a)) {
+ LOG.debug("Deferring removal of region {} because daughter {} still
has references",
+ parent, daughters.getFirst());
+ }
+ if (!hasNoReferences(b)) {
+ LOG.debug("Deferring removal of region {} because daughter {} still
has references",
+ parent, daughters.getSecond());
+ }
+ }
}
return false;
}
