Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HBASE-25847 More DEBUG and TRACE level logging in CatalogJanitor and HbckChore #3230

Merged
merged 3 commits into from
May 6, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -223,15 +223,38 @@ private void loadRegionsFromInMemoryState() {
.isTableState(regionInfo.getTable(), TableState.State.DISABLED)) {
disabledTableRegions.add(regionInfo.getRegionNameAsString());
}
if (regionInfo.isSplitParent()) {
if (regionState.isSplit()) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Most of this patch is just more logging. This is a real bug fix, though. Right now it just affects logging (numbers printed in a debug log line) but if in the future code depends on splitParentRegions to be properly populated, this will be needed.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

+1 on this change.

Was always odd have a Regions' split state recorded in its RegionInfo; RegionInfo does not keep internally if it is being merged or if open, etc. Regions are manipulated by other entities so state belongs elsewhere. +1 on move to regionstate checking instead.

splitParentRegions.add(regionInfo.getRegionNameAsString());
}
HbckRegionInfo.MetaEntry metaEntry =
new HbckRegionInfo.MetaEntry(regionInfo, regionState.getServerName(),
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() {
Expand Down Expand Up @@ -307,7 +330,7 @@ private void loadRegionsFromFS(final HashSet<String> mergedParentRegions) throws
}
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());
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,8 @@
@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);
Expand All @@ -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;
}

Expand Down Expand Up @@ -158,20 +161,30 @@ public int scan() throws IOException {
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");
}
apurtell marked this conversation as resolved.
Show resolved Hide resolved
break;
}

Expand All @@ -188,6 +201,9 @@ public int scan() throws IOException {
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;
}

Expand Down Expand Up @@ -235,6 +251,9 @@ public Report getLastReport() {
*/
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());
Expand All @@ -247,16 +266,23 @@ private boolean cleanMergeRegion(final RegionInfo mergedRegion, List<RegionInfo>
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.
apurtell marked this conversation as resolved.
Show resolved Hide resolved
// Do we need this?
this.services.getAssignmentManager().getRegionStates().deleteRegion(ri);
this.services.getServerManager().removeRegion(ri);
}
Expand Down Expand Up @@ -300,9 +326,15 @@ public int compare(RegionInfo left, RegionInfo right) {

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.
Expand All @@ -314,14 +346,32 @@ static boolean cleanParent(MasterServices services, RegionInfo parent, Result ro
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
apurtell marked this conversation as resolved.
Show resolved Hide resolved
// 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;
}
Expand Down