Backport "HBASE-28403 Improve debugging for failures in procedure tests (#5709)" to branch-3

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();
+  }
 }

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(). <br/>
  * 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) <br/>
+ * guarantees of locks (see
+ * <a href="http://docs.oracle.com/javase/8/docs/api/java/util/concurrent/locks/Lock.html">Memory
+ * Synchronization</a>) <br/>
  * We do not implement Lock interface because we need exclusive and shared locking, and also because
  * try-lock functions require procedure id. <br/>
  * We do not use ReentrantReadWriteLock directly because of its high memory overhead.
@@ -182,7 +185,7 @@ public Stream<Procedure> filterWaitingQueue(Predicate<Procedure> 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();
   }
 }

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();
+  }
 }

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

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<LockedResource> 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();
+  }
 }

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();
+  }
 }

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();
+  }
 }

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();
+  }
 }

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();
+  }
 }

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<TKey> 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();
   }
 }

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<?, LockAndQueue> locks) {
-    StringBuilder sb = new StringBuilder("{");
-    int initialLength = sb.length();
-    for (Map.Entry<?, LockAndQueue> 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();
   }
 }

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();
+  }
 }

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();
+  }
 }