Skip to content

Commit

Permalink
HBASE-28403 Improve debugging for failures in procedure tests (#5709)
Browse files Browse the repository at this point in the history
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 <[email protected]>
  • Loading branch information
ndimiduk committed Feb 29, 2024
1 parent 441b2fe commit 67069d2
Show file tree
Hide file tree
Showing 13 changed files with 125 additions and 32 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;

/**
Expand All @@ -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.
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;

/**
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
}

0 comments on commit 67069d2

Please sign in to comment.