From 67069d24393ea14083df882555ec13ce51bac05c Mon Sep 17 00:00:00 2001 From: Nick Dimiduk Date: Thu, 29 Feb 2024 12:06:46 +0100 Subject: [PATCH] HBASE-28403 Improve debugging for failures in procedure tests (#5709) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit We see unit test failures in Jenkins that look like this: ``` java.lang.IllegalArgumentException: run queue not empty at org.apache.hbase.thirdparty.com.google.common.base.Preconditions.checkArgument(Preconditions.java:143) at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.load(ProcedureExecutor.java:332) at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.init(ProcedureExecutor.java:665) at org.apache.hadoop.hbase.procedure2.ProcedureTestingUtility.restart(ProcedureTestingUtility.java:132) at org.apache.hadoop.hbase.procedure2.ProcedureTestingUtility.restart(ProcedureTestingUtility.java:100) at org.apache.hadoop.hbase.master.procedure.MasterProcedureTestingUtility.restartMasterProcedureExecutor(MasterProcedureTestingUtility.java:85) at org.apache.hadoop.hbase.master.assignment.TestRollbackSCP.testFailAndRollback(TestRollbackSCP.java:180) ``` This isn't enough information to debug the situation. The test code in question looks reasonable enough – it clears the object for re-use between tests. However, somewhere between stop/clear/start we miss something. Add some toString implementations and dump the objects in the preconditions. Signed-off-by: Duo Zhang --- .../AbstractProcedureScheduler.java | 8 +++++ .../hadoop/hbase/procedure2/LockAndQueue.java | 11 ++++--- .../hadoop/hbase/procedure2/LockStatus.java | 12 +++++++ .../hbase/procedure2/ProcedureExecutor.java | 9 +++--- .../procedure2/SimpleProcedureScheduler.java | 8 +++++ .../hbase/master/procedure/GlobalQueue.java | 8 +++++ .../procedure/MasterProcedureScheduler.java | 28 ++++++++++++++++ .../hbase/master/procedure/MetaQueue.java | 8 +++++ .../hbase/master/procedure/PeerQueue.java | 8 +++++ .../hadoop/hbase/master/procedure/Queue.java | 9 +++--- .../hbase/master/procedure/SchemaLocking.java | 32 ++++++++----------- .../hbase/master/procedure/ServerQueue.java | 8 +++++ .../hbase/master/procedure/TableQueue.java | 8 +++++ 13 files changed, 125 insertions(+), 32 deletions(-) diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/AbstractProcedureScheduler.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/AbstractProcedureScheduler.java index 61f73544b1bb..04b506594774 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/AbstractProcedureScheduler.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/AbstractProcedureScheduler.java @@ -21,6 +21,8 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.locks.Condition; import java.util.concurrent.locks.ReentrantLock; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.yetus.audience.InterfaceAudience; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -293,4 +295,10 @@ protected void wakePollIfNeeded(final int waitingCount) { schedWaitCond.signalAll(); } } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).append("running", running) + .build(); + } } diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockAndQueue.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockAndQueue.java index fa6c72c490fc..bcf3982de7f0 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockAndQueue.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockAndQueue.java @@ -20,6 +20,8 @@ import java.util.function.Function; import java.util.function.Predicate; import java.util.stream.Stream; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.yetus.audience.InterfaceAudience; /** @@ -36,8 +38,9 @@ * NOT thread-safe. Needs external concurrency control: e.g. uses in MasterProcedureScheduler are * guarded by schedLock().
* There is no need of 'volatile' keyword for member variables because of memory synchronization - * guarantees of locks (see 'Memory Synchronization', - * http://docs.oracle.com/javase/8/docs/api/java/util/concurrent/locks/Lock.html)
+ * guarantees of locks (see + * Memory + * Synchronization)
* We do not implement Lock interface because we need exclusive and shared locking, and also because * try-lock functions require procedure id.
* We do not use ReentrantReadWriteLock directly because of its high memory overhead. @@ -182,7 +185,7 @@ public Stream filterWaitingQueue(Predicate predicate) { @Override public String toString() { - return "exclusiveLockOwner=" + (hasExclusiveLock() ? getExclusiveLockProcIdOwner() : "NONE") - + ", sharedLockCount=" + getSharedLockCount() + ", waitingProcCount=" + queue.size(); + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE) + .appendSuper(describeLockStatus()).append("waitingProcCount", queue.size()).build(); } } diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockStatus.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockStatus.java index d3723e1a35a7..61b302b0c8b1 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockStatus.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/LockStatus.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.procedure2; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.yetus.audience.InterfaceAudience; /** @@ -68,4 +70,14 @@ default long getExclusiveLockProcIdOwner() { * Get the number of procedures which hold the shared lock. */ int getSharedLockCount(); + + default String describeLockStatus() { + ToStringBuilder builder = new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE) + .append("exclusiveLock", hasExclusiveLock()); + if (hasExclusiveLock()) { + builder.append("exclusiveLockProcIdOwner", getExclusiveLockProcIdOwner()); + } + builder.append("sharedLockCount", getSharedLockCount()); + return builder.build(); + } } diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java index e01a27d74675..8a5062be7918 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/ProcedureExecutor.java @@ -326,10 +326,11 @@ public ProcedureExecutor(final Configuration conf, final TEnvironment environmen } private void load(final boolean abortOnCorruption) throws IOException { - Preconditions.checkArgument(completed.isEmpty(), "completed not empty"); - Preconditions.checkArgument(rollbackStack.isEmpty(), "rollback state not empty"); - Preconditions.checkArgument(procedures.isEmpty(), "procedure map not empty"); - Preconditions.checkArgument(scheduler.size() == 0, "run queue not empty"); + Preconditions.checkArgument(completed.isEmpty(), "completed not empty: %s", completed); + Preconditions.checkArgument(rollbackStack.isEmpty(), "rollback state not empty: %s", + rollbackStack); + Preconditions.checkArgument(procedures.isEmpty(), "procedure map not empty: %s", procedures); + Preconditions.checkArgument(scheduler.size() == 0, "scheduler queue not empty: %s", scheduler); store.load(new ProcedureStore.ProcedureLoader() { @Override diff --git a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/SimpleProcedureScheduler.java b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/SimpleProcedureScheduler.java index f2b4d4820da7..8998d3bebb2f 100644 --- a/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/SimpleProcedureScheduler.java +++ b/hbase-procedure/src/main/java/org/apache/hadoop/hbase/procedure2/SimpleProcedureScheduler.java @@ -19,6 +19,8 @@ import java.util.Collections; import java.util.List; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.yetus.audience.InterfaceAudience; import org.apache.yetus.audience.InterfaceStability; @@ -82,4 +84,10 @@ public List getLocks() { public LockedResource getLockResource(LockedResourceType resourceType, String resourceName) { return null; } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .append("runnables", runnables).build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/GlobalQueue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/GlobalQueue.java index 1633dc4856e7..541bbccc6d21 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/GlobalQueue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/GlobalQueue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; import org.apache.yetus.audience.InterfaceAudience; @@ -32,4 +34,10 @@ public GlobalQueue(String globalId, LockStatus lockStatus) { boolean requireExclusiveLock(Procedure proc) { return true; } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MasterProcedureScheduler.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MasterProcedureScheduler.java index fbf0eb8abf32..a5ef7c5d9239 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MasterProcedureScheduler.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MasterProcedureScheduler.java @@ -22,6 +22,8 @@ import java.util.List; import java.util.function.Function; import java.util.function.Supplier; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.HConstants; import org.apache.hadoop.hbase.ServerName; import org.apache.hadoop.hbase.TableExistsException; @@ -1129,4 +1131,30 @@ public String dumpLocks() throws IOException { schedUnlock(); } } + + private void serverBucketToString(ToStringBuilder builder, String queueName, Queue queue) { + int size = queueSize(queue); + if (size != 0) { + builder.append(queueName, queue); + } + } + + @Override + public String toString() { + ToStringBuilder builder = + new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()); + schedLock(); + try { + for (int i = 0; i < serverBuckets.length; i++) { + serverBucketToString(builder, "serverBuckets[" + i + "]", serverBuckets[i]); + } + builder.append("tableMap", tableMap); + builder.append("peerMap", peerMap); + builder.append("metaMap", metaMap); + builder.append("globalMap", globalMap); + } finally { + schedUnlock(); + } + return builder.build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MetaQueue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MetaQueue.java index 3eea59ef23be..3d313c9ac3ab 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MetaQueue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/MetaQueue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.TableName; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; @@ -38,4 +40,10 @@ protected MetaQueue(LockStatus lockStatus) { boolean requireExclusiveLock(Procedure proc) { return true; } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/PeerQueue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/PeerQueue.java index 3d07953c6f1e..7a2d917eb918 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/PeerQueue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/PeerQueue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.master.procedure.PeerProcedureInterface.PeerOperationType; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; @@ -42,4 +44,10 @@ private static boolean requirePeerExclusiveLock(PeerProcedureInterface proc) { && proc.getPeerOperationType() != PeerOperationType.SYNC_REPLICATION_REPLAY_WAL && proc.getPeerOperationType() != PeerOperationType.SYNC_REPLICATION_REPLAY_WAL_REMOTE; } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/Queue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/Queue.java index 621c7ea69569..3ba79f8c41f6 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/Queue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/Queue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; import org.apache.hadoop.hbase.procedure2.ProcedureDeque; @@ -105,10 +107,7 @@ public int compareTo(Queue other) { @Override public String toString() { - return String.format("%s(%s, xlock=%s sharedLock=%s size=%s)", getClass().getSimpleName(), key, - lockStatus.hasExclusiveLock() - ? "true (" + lockStatus.getExclusiveLockProcIdOwner() + ")" - : "false", - lockStatus.getSharedLockCount(), size()); + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).append("key", key) + .append("lockStatus", lockStatus.describeLockStatus()).append("size", size()).build(); } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/SchemaLocking.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/SchemaLocking.java index 853d13b0c93b..642df36d535f 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/SchemaLocking.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/SchemaLocking.java @@ -22,6 +22,9 @@ import java.util.List; import java.util.Map; import java.util.function.Function; +import java.util.stream.Collectors; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.ServerName; import org.apache.hadoop.hbase.TableName; import org.apache.hadoop.hbase.master.locking.LockProcedure; @@ -227,27 +230,18 @@ void clear() { @Override public String toString() { - return "serverLocks=" + filterUnlocked(this.serverLocks) + ", namespaceLocks=" - + filterUnlocked(this.namespaceLocks) + ", tableLocks=" + filterUnlocked(this.tableLocks) - + ", regionLocks=" + filterUnlocked(this.regionLocks) + ", peerLocks=" - + filterUnlocked(this.peerLocks) + ", metaLocks=" - + filterUnlocked(ImmutableMap.of(TableName.META_TABLE_NAME, metaLock)) + ", globalLocks=" - + filterUnlocked(globalLocks); + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE) + .append("serverLocks", filterUnlocked(serverLocks)) + .append("namespaceLocks", filterUnlocked(namespaceLocks)) + .append("tableLocks", filterUnlocked(tableLocks)) + .append("regionLocks", filterUnlocked(regionLocks)) + .append("peerLocks", filterUnlocked(peerLocks)) + .append("metaLocks", filterUnlocked(ImmutableMap.of(TableName.META_TABLE_NAME, metaLock))) + .append("globalLocks", filterUnlocked(globalLocks)).build(); } private String filterUnlocked(Map locks) { - StringBuilder sb = new StringBuilder("{"); - int initialLength = sb.length(); - for (Map.Entry entry : locks.entrySet()) { - if (!entry.getValue().isLocked()) { - continue; - } - if (sb.length() > initialLength) { - sb.append(", "); - } - sb.append("{").append(entry.getKey()).append("=").append(entry.getValue()).append("}"); - } - sb.append("}"); - return sb.toString(); + return locks.entrySet().stream().filter(val -> !val.getValue().isLocked()) + .collect(Collectors.toMap(Map.Entry::getKey, Map.Entry::getValue)).toString(); } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/ServerQueue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/ServerQueue.java index 9ed6cfacd860..a3144cc157a1 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/ServerQueue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/ServerQueue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.ServerName; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; @@ -47,4 +49,10 @@ public boolean requireExclusiveLock(Procedure proc) { } throw new UnsupportedOperationException("unexpected type " + spi.getServerOperationType()); } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .build(); + } } diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/TableQueue.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/TableQueue.java index 2f0cec77e18c..36c9df6e794e 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/TableQueue.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/master/procedure/TableQueue.java @@ -17,6 +17,8 @@ */ package org.apache.hadoop.hbase.master.procedure; +import org.apache.commons.lang3.builder.ToStringBuilder; +import org.apache.commons.lang3.builder.ToStringStyle; import org.apache.hadoop.hbase.TableName; import org.apache.hadoop.hbase.procedure2.LockStatus; import org.apache.hadoop.hbase.procedure2.Procedure; @@ -76,4 +78,10 @@ private static boolean requireTableExclusiveLock(TableProcedureInterface proc) { } throw new UnsupportedOperationException("unexpected type " + proc.getTableOperationType()); } + + @Override + public String toString() { + return new ToStringBuilder(this, ToStringStyle.SHORT_PREFIX_STYLE).appendSuper(super.toString()) + .append("namespaceLockStatus", namespaceLockStatus.describeLockStatus()).build(); + } }