From 3fe8649b2c9ba1271c25e8f476548907e4c7a90d Mon Sep 17 00:00:00 2001 From: Duo Zhang Date: Wed, 24 Oct 2018 15:41:56 +0800 Subject: [PATCH] HBASE-21377 Add debug log for catching the root cause --- .../hbase/procedure2/RootProcedureState.java | 5 +++ .../store/wal/WALProcedureTree.java | 3 ++ .../TestMergeTableRegionsProcedure.java | 39 +++++++++++-------- 3 files changed, 30 insertions(+), 17 deletions(-) diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/RootProcedureState.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/RootProcedureState.java index 2fc00301e91..a7cdaabb248 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/RootProcedureState.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/RootProcedureState.java @@ -24,6 +24,8 @@ import java.util.List; import java.util.Set; import org.apache.yetus.audience.InterfaceAudience; import org.apache.yetus.audience.InterfaceStability; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.apache.hadoop.hbase.shaded.protobuf.generated.ProcedureProtos.ProcedureState; @@ -42,6 +44,8 @@ import org.apache.hadoop.hbase.shaded.protobuf.generated.ProcedureProtos.Procedu @InterfaceStability.Evolving class RootProcedureState { + private static final Logger LOG = LoggerFactory.getLogger(RootProcedureState.class); + private enum State { RUNNING, // The Procedure is running or ready to run FAILED, // The Procedure failed, waiting for the rollback executing @@ -146,6 +150,7 @@ class RootProcedureState { subprocStack = new ArrayList<>(); } proc.addStackIndex(subprocStack.size()); + LOG.debug("Add procedure {} as the {}th rollback step", proc, subprocStack.size()); subprocStack.add(proc); } diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/store/wal/WALProcedureTree.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/store/wal/WALProcedureTree.java index c32bd7f6d8c..6e624b4fca2 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/store/wal/WALProcedureTree.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/store/wal/WALProcedureTree.java @@ -145,6 +145,9 @@ public final class WALProcedureTree { private void collectStackId(Entry entry, Map> stackId2Proc, MutableInt maxStackId) { + if (LOG.isDebugEnabled()) { + LOG.debug("Procedure {} stack ids={}", entry, entry.proc.getStackIdList()); + } for (int i = 0, n = entry.proc.getStackIdCount(); i < n; i++) { int stackId = entry.proc.getStackId(i); if (stackId > maxStackId.intValue()) { diff --git a/hbase-server/src/test/java/org/apache/hadoop/hbase/master/assignment/TestMergeTableRegionsProcedure.java b/hbase-server/src/test/java/org/apache/hadoop/hbase/master/assignment/TestMergeTableRegionsProcedure.java index 858d20ca9d6..b2236904c85 100644 --- a/hbase-server/src/test/java/org/apache/hadoop/hbase/master/assignment/TestMergeTableRegionsProcedure.java +++ b/hbase-server/src/test/java/org/apache/hadoop/hbase/master/assignment/TestMergeTableRegionsProcedure.java @@ -275,31 +275,36 @@ public class TestMergeTableRegionsProcedure { @Test public void testMergeWithoutPONR() throws Exception { - final TableName tableName = TableName.valueOf("testMergeWithoutPONR"); - final ProcedureExecutor procExec = getMasterProcedureExecutor(); + try { + final TableName tableName = TableName.valueOf("testMergeWithoutPONR"); + final ProcedureExecutor procExec = getMasterProcedureExecutor(); - List tableRegions = createTable(tableName); + List tableRegions = createTable(tableName); - ProcedureTestingUtility.waitNoProcedureRunning(procExec); - ProcedureTestingUtility.setKillAndToggleBeforeStoreUpdate(procExec, true); + ProcedureTestingUtility.waitNoProcedureRunning(procExec); + ProcedureTestingUtility.setKillAndToggleBeforeStoreUpdate(procExec, true); - RegionInfo[] regionsToMerge = new RegionInfo[2]; - regionsToMerge[0] = tableRegions.get(0); - regionsToMerge[1] = tableRegions.get(1); + RegionInfo[] regionsToMerge = new RegionInfo[2]; + regionsToMerge[0] = tableRegions.get(0); + regionsToMerge[1] = tableRegions.get(1); - long procId = procExec.submitProcedure( + long procId = procExec.submitProcedure( new MergeTableRegionsProcedure(procExec.getEnvironment(), regionsToMerge, true)); - // Execute until step 9 of split procedure - // NOTE: step 9 is after step MERGE_TABLE_REGIONS_UPDATE_META - MasterProcedureTestingUtility.testRecoveryAndDoubleExecution(procExec, procId, 9, false); + // Execute until step 9 of split procedure + // NOTE: step 9 is after step MERGE_TABLE_REGIONS_UPDATE_META + MasterProcedureTestingUtility.testRecoveryAndDoubleExecution(procExec, procId, 9, false); - // Unset Toggle Kill and make ProcExec work correctly - ProcedureTestingUtility.setKillAndToggleBeforeStoreUpdate(procExec, false); - MasterProcedureTestingUtility.restartMasterProcedureExecutor(procExec); - ProcedureTestingUtility.waitProcedure(procExec, procId); + // Unset Toggle Kill and make ProcExec work correctly + ProcedureTestingUtility.setKillAndToggleBeforeStoreUpdate(procExec, false); + MasterProcedureTestingUtility.restartMasterProcedureExecutor(procExec); + ProcedureTestingUtility.waitProcedure(procExec, procId); - assertRegionCount(tableName, initialRegionCount - 1); + assertRegionCount(tableName, initialRegionCount - 1); + } catch (Throwable t) { + LOG.error("error!", t); + throw t; + } } private List createTable(final TableName tableName) throws Exception {