Skip to content

Commit

Permalink
Add a watcher (JUnit 3) test rule (JUnit 4) for hanging test logging
Browse files Browse the repository at this point in the history
Tests may be (and actually are every now and then) hanging for different
reasons, such as livelocks or deadlocks. A hanging test does not log
anything on its own anymore, which makes it difficult to identify a
hanging test and the reasons for that. To this end, it would be useful
to have an additional entity that logs the state of all threads, i.e., a
thread dump, when a test takes longer than a defined threshold.

Since several tests need to run in the UI thread, the JUnit Timeout rule
cannot be used, as it executes a test in a different thread that can
even be terminated preemptively after a timeout. Instead, this change
introduces a HangingTestRule that spawns a watcher thread that writes a
thread dump whenever a test (that is run in the UI thread) takes more
time than a defined timeout.
In total, this change does the following:
- Makes the thread dump logic currently placed in TestBarrier2 reusable
in a central TestUtil
- Adds a HangingTestWatcher that writes a thread dump if not stopped
after a given timeout (compatible with JUnit 3)
- Adds a HangingTestRule that wraps the HangingTestWatcher into a JUnit
4 rule
- Adds the HangingTestWatcher to the JUnit 3 CoreTest class to apply the
logging to all subclasses of CoreTest
  • Loading branch information
HeikoKlare committed Oct 27, 2023
1 parent 4e9eaab commit 112221b
Show file tree
Hide file tree
Showing 6 changed files with 214 additions and 24 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ Bundle-SymbolicName: org.eclipse.core.tests.harness;singleton:=true
Bundle-Version: 3.15.200.qualifier
Bundle-Vendor: Eclipse.org
Export-Package: org.eclipse.core.tests.harness;version="2.0",
org.eclipse.core.tests.harness.rules;version="1.0",
org.eclipse.core.tests.session;version="2.0"
Require-Bundle: org.junit,
org.eclipse.test.performance,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
import java.io.InputStream;
import java.io.OutputStream;
import java.io.PrintStream;
import java.time.Duration;
import junit.framework.AssertionFailedError;
import junit.framework.TestCase;
import org.eclipse.core.runtime.CoreException;
Expand All @@ -33,18 +34,38 @@
import org.eclipse.core.runtime.IStatus;
import org.eclipse.core.runtime.Platform;
import org.eclipse.core.runtime.Status;
import org.eclipse.core.tests.harness.rules.HangingTestWatcher;
import org.junit.Assume;

/**
* @since 3.1
*/
public class CoreTest extends TestCase {
private static final Duration TIMEOUT = Duration.ofSeconds(60);

private HangingTestWatcher hangingTestWatcher;

/** counter for generating unique random file system locations */
protected static int nextLocationCounter = 0;

// plug-in identified for the core.tests.harness plug-in.
public static final String PI_HARNESS = "org.eclipse.core.tests.harness";

@Override
protected void setUp() throws Exception {
super.setUp();
hangingTestWatcher = HangingTestWatcher.createAndStart(TIMEOUT, getName());
}

@Override
protected void tearDown() throws Exception {
if (hangingTestWatcher != null) {
hangingTestWatcher.stop();
hangingTestWatcher = null;
}
super.tearDown();
}

public static void debug(String message) {
String id = "org.eclipse.core.tests.harness/debug";
String option = Platform.getDebugOption(id);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,13 +13,7 @@
*******************************************************************************/
package org.eclipse.core.tests.harness;

import java.text.SimpleDateFormat;
import java.util.Comparator;
import java.util.Date;
import java.util.Map;
import java.util.Map.Entry;
import java.util.concurrent.atomic.AtomicIntegerArray;
import java.util.stream.Collectors;
import org.junit.Assert;

/**
Expand Down Expand Up @@ -103,24 +97,7 @@ private static void doWaitForStatus(AtomicIntegerArray statuses, int index, int
}

public static String getThreadDump() {
StringBuilder out = new StringBuilder();
out.append(" [ThreadDump taken from thread '" + Thread.currentThread().getName() + "' at "
+ new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date(System.currentTimeMillis())) + ":\n");
Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
Comparator<Entry<Thread, StackTraceElement[]>> byId = Comparator.comparing(e -> e.getKey().getId());
for (Entry<Thread, StackTraceElement[]> entry : stackTraces.entrySet().stream().sorted(byId)
.collect(Collectors.toList())) {
Thread thread = entry.getKey();
String name = thread.getName();
out.append(" Thread \"" + name + "\" #" + thread.getId() + " prio=" + thread.getPriority() + " "
+ thread.getState() + "\n");
StackTraceElement[] stack = entry.getValue();
for (StackTraceElement se : stack) {
out.append(" at " + se + "\n");
}
}
out.append(" ] // ThreadDump end\n");
return out.toString();
return TestUtil.createThreadDump();
}

private static String getStatus(int status) {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
/*******************************************************************************
* Copyright (c) 2023 Vector Informatik GmbH and others.
*
* This program and the accompanying materials
* are made available under the terms of the Eclipse Public License v2.0
* which accompanies this distribution, and is available at
* https://www.eclipse.org/legal/epl-2.0/
*
* SPDX-License-Identifier: EPL-2.0
*
*******************************************************************************/
package org.eclipse.core.tests.harness;

import java.text.SimpleDateFormat;
import java.util.Comparator;
import java.util.Date;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;
import java.util.stream.Collectors;

public final class TestUtil {
private TestUtil() {
}

/**
* Creates a multi-line string representing a current thread dump consisting of
* all thread's stacks.
*
* @return a multi-line string containing a current thread dump
*/
public static String createThreadDump() {
return ThreadDump.create();
}

private static final class ThreadDump {

public static String create() {
StringBuilder out = new StringBuilder();
String staticIndent = " ";
String indentPerLevel = " ";
out.append(staticIndent + "[ThreadDump taken from thread '" + Thread.currentThread().getName() + "' at "
+ new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS").format(new Date(System.currentTimeMillis())) + ":"
+ System.lineSeparator());
List<Entry<Thread, StackTraceElement[]>> stackTraces = getStacksOfAllThreads();
for (Entry<Thread, StackTraceElement[]> entry : stackTraces) {
Thread thread = entry.getKey();
out.append(staticIndent + indentPerLevel).append("Thread \"").append(thread.getName()).append("\" ") //
.append("#").append(thread.getId()).append(" ") //
.append("prio=").append(thread.getPriority()).append(" ") //
.append(thread.getState()).append(System.lineSeparator());
StackTraceElement[] stack = entry.getValue();
for (StackTraceElement stackEntry : stack) {
out.append(staticIndent + indentPerLevel + indentPerLevel).append("at ").append(stackEntry)
.append(System.lineSeparator());
}
}
out.append(staticIndent).append("] // ThreadDump end").append(System.lineSeparator());
return out.toString();
}

private static List<Entry<Thread, StackTraceElement[]>> getStacksOfAllThreads() {
Comparator<Entry<Thread, StackTraceElement[]>> threadIdComparator = Comparator
.comparing(e -> e.getKey().getId());
Map<Thread, StackTraceElement[]> stackTraces = Thread.getAllStackTraces();
return stackTraces.entrySet().stream().sorted(threadIdComparator).collect(Collectors.toList());
}
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
/*******************************************************************************
* Copyright (c) 2023 Vector Informatik GmbH and others.
*
* This program and the accompanying materials
* are made available under the terms of the Eclipse Public License v2.0
* which accompanies this distribution, and is available at
* https://www.eclipse.org/legal/epl-2.0/
*
* SPDX-License-Identifier: EPL-2.0
*
*******************************************************************************/
package org.eclipse.core.tests.harness.rules;

import java.time.Duration;
import org.junit.rules.TestWatcher;
import org.junit.rules.Timeout;
import org.junit.runner.Description;

/**
* A test rule that watches for a hanging test. It logs a thread dump in case a
* test runs longer than a given timeout and sends an interrupt to the thread
* that executes this rule. In contrast to the JUnit {@link Timeout} rule, it
* still executes the test in the original thread.
*/
public class HangingTestRule extends TestWatcher {

private final Duration timeout;

private HangingTestWatcher hangingTestWatcher;

public HangingTestRule(Duration timeout) {
this.timeout = timeout;
}

@Override
protected void starting(Description description) {
hangingTestWatcher = HangingTestWatcher.createAndStart(timeout, description.getDisplayName());
}

@Override
protected void finished(Description description) {
hangingTestWatcher.stop();
}

}
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
/*******************************************************************************
* Copyright (c) 2023 Vector Informatik GmbH and others.
*
* This program and the accompanying materials
* are made available under the terms of the Eclipse Public License v2.0
* which accompanies this distribution, and is available at
* https://www.eclipse.org/legal/epl-2.0/
*
* SPDX-License-Identifier: EPL-2.0
*
*******************************************************************************/
package org.eclipse.core.tests.harness.rules;

import java.time.Duration;
import java.util.Timer;
import java.util.TimerTask;
import org.eclipse.core.tests.harness.TestUtil;

/**
* Logs a thread dump to the console and sends an interrupt to the calling
* thread after the specified timeout. Is initialized and started via
* {@link #createAndStart(Duration, String)} and can be stopped before the
* timeout occurs via {@link #stop()}.
*
* This class is supposed to be used by the {@link HangingTestRule}, but
* may also be useful to emulate the rule in JUnit 3 tests until they are
* migrated to a newer JUnit versions.
*/
public class HangingTestWatcher {
private final Duration timeout;

private Timer timer;

private String testName;

private HangingTestWatcher(Duration timeout, String testName) {
this.timeout = timeout;
this.testName = testName;
this.timer = new Timer();
}

private void start() {
final Thread originalThread = Thread.currentThread();
timer.schedule(new TimerTask() {
@Override
public void run() {
logHangingThread();
originalThread.interrupt();
}
}, timeout.toMillis());
}

private void logHangingThread() {
System.out.println(getTimeoutMessage());
}

private String getTimeoutMessage() {
return """
%s ran into a timeout (%s ms) with the following thread dump:
%s
""".formatted(testName, timeout.toMillis(), TestUtil.createThreadDump());
}

/**
* Stops this logger such that
*/
public void stop() {
timer.cancel();
}

public static HangingTestWatcher createAndStart(Duration timeout, String testName) {
HangingTestWatcher watcher = new HangingTestWatcher(timeout, testName);
watcher.start();
return watcher;
}
}

0 comments on commit 112221b

Please sign in to comment.