Skip to content

Commit

Permalink
When outputting a thread dump for a slow interruption, group threads …
Browse files Browse the repository at this point in the history
…with the same stack trace together, sort the dump by stack length (longer stacks are more likely to be interesting), and insert the longest stack in the remote bug report, for easier triage. Also log stack traces and thread names in one single logline: makes it much easier to read these lines and to search over them. The length should still be manageable, and if there are thousands of threads for a single stack trace, it's unlikely they're doing anything very interesting.

I didn't try too hard to minimize CPU/garbage, but if some of the slow interrupts are due to an overloaded server, it's possible this will have some negative effects and need to be optimized.

PiperOrigin-RevId: 388311331
  • Loading branch information
janakdr authored and copybara-github committed Aug 2, 2021
1 parent 262cd8a commit 8eba488
Showing 1 changed file with 109 additions and 13 deletions.
122 changes: 109 additions & 13 deletions src/main/java/com/google/devtools/build/lib/util/ThreadUtils.java
Original file line number Diff line number Diff line change
Expand Up @@ -13,36 +13,132 @@
// limitations under the License.
package com.google.devtools.build.lib.util;

import static java.util.stream.Collectors.toCollection;

import com.google.common.flogger.GoogleLogger;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Comparator;
import java.util.Map;
import java.util.concurrent.atomic.AtomicReference;
import java.util.logging.Level;
import java.util.stream.Collector;
import java.util.stream.Collectors;

/**
* Utility methods relating to threads and stack traces.
*/
/** Utility to dump stack traces to logs and remotely log on slow interrupt. */
public class ThreadUtils {
private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final Comparator<
Map.Entry<StackTraceAndState, ArrayList<Map.Entry<Thread, StackTraceElement[]>>>>
STACK_SIZE_THEN_THREAD_COUNT_BOTH_DESCENDING_COMPARATOR =
Map.Entry
.<StackTraceAndState, ArrayList<Map.Entry<Thread, StackTraceElement[]>>>
comparingByKey()
.thenComparingInt(o -> o.getValue().size())
.reversed();
private static final Collector<
Map.Entry<Thread, StackTraceElement[]>,
?,
Map<StackTraceAndState, ArrayList<Map.Entry<Thread, StackTraceElement[]>>>>
MAP_WITH_ARRAY_LIST_VALUES_COLLECTOR =
Collectors.groupingBy(StackTraceAndState::new, toCollection(ArrayList::new));

private ThreadUtils() {
}

/** Write a thread dump to the blaze.INFO log if interrupt took too long. */
public static synchronized void warnAboutSlowInterrupt() {
logger.atWarning().log("Interrupt took too long. Dumping thread state.");
for (Map.Entry <Thread, StackTraceElement[]> e : Thread.getAllStackTraces().entrySet()) {
Thread t = e.getKey();
logger.atWarning().log("\"%s\" Thread id=%d %s", t.getName(), t.getId(), t.getState());
for (StackTraceElement line : e.getValue()) {
logger.atWarning().log("\t%s", line);
AtomicReference<StackTraceAndState> firstTrace = new AtomicReference<>();
Thread.getAllStackTraces().entrySet().stream()
.collect(MAP_WITH_ARRAY_LIST_VALUES_COLLECTOR)
.entrySet()
.stream()
.sorted(STACK_SIZE_THEN_THREAD_COUNT_BOTH_DESCENDING_COMPARATOR)
.forEach(
e -> {
StackTraceAndState stackTraceAndState = e.getKey();
firstTrace.compareAndSet(null, stackTraceAndState);
logger.atWarning().log(
"%s %s%s",
stackTraceAndState.state,
makeThreadInfoString(e.getValue()),
makeString(stackTraceAndState.trace));
});

Exception inner = new Exception("Wrapper exception for longest stack trace");
inner.setStackTrace(firstTrace.get().trace);
SlowInterruptException ex = new SlowInterruptException(inner);
LoggingUtil.logToRemote(Level.WARNING, "Slow interrupt", ex);
}

private static final class SlowInterruptException extends RuntimeException {
public SlowInterruptException(Exception inner) {
super("Slow interruption...", inner);
}
}

private static final class StackTraceAndState implements Comparable<StackTraceAndState> {
private final StackTraceElement[] trace;
private final Thread.State state;

StackTraceAndState(Map.Entry<Thread, StackTraceElement[]> threadEntry) {
this.trace = threadEntry.getValue();
this.state = threadEntry.getKey().getState();
}

@Override
public int hashCode() {
return 31 * state.hashCode() + Arrays.hashCode(trace);
}

@Override
public boolean equals(Object obj) {
if (obj == this) {
return true;
}
if (!(obj instanceof StackTraceAndState)) {
return false;
}
logger.atWarning().log("");
StackTraceAndState that = (StackTraceAndState) obj;
return Arrays.equals(this.trace, that.trace) && this.state.equals(that.state);
}

@Override
public int compareTo(StackTraceAndState o) {
return Integer.compare(trace.length, o.trace.length);
}
LoggingUtil.logToRemote(Level.WARNING, "Slow interrupt", new SlowInterruptException());
}

private static final class SlowInterruptException extends RuntimeException {
public SlowInterruptException() {
super("Slow interruption...");
private static String makeString(StackTraceElement[] stackTrace) {
StringBuilder builder = new StringBuilder();
for (StackTraceElement elt : stackTrace) {
builder.append('\n').append('\t').append(elt);
}
return builder.toString();
}

private static final Comparator<Map.Entry<Thread, StackTraceElement[]>> THREAD_NAME_THEN_ID =
Comparator.comparing((Map.Entry<Thread, StackTraceElement[]> o) -> o.getKey().getName())
.thenComparingLong(o -> o.getKey().getId());

private static String makeThreadInfoString(
ArrayList<Map.Entry<Thread, StackTraceElement[]>> entries) {
StringBuilder builder = new StringBuilder();
if (entries.size() > 10) {
builder.append(entries.size()).append(" threads, ");
}
entries.sort(THREAD_NAME_THEN_ID);
boolean first = true;
for (Map.Entry<Thread, StackTraceElement[]> entry : entries) {
if (first) {
first = false;
} else {
builder.append(", ");
}
Thread thread = entry.getKey();
builder.append('<').append(thread.getName()).append(' ').append(thread.getId()).append('>');
}
return builder.toString();
}
}

0 comments on commit 8eba488

Please sign in to comment.