-
Notifications
You must be signed in to change notification settings - Fork 99
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Add a watcher (JUnit 3) test rule (JUnit 4) for hanging test logging
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
1 parent
355490a
commit eb4e669
Showing
6 changed files
with
232 additions
and
24 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
70 changes: 70 additions & 0 deletions
70
...ime/tests/org.eclipse.core.tests.harness/src/org/eclipse/core/tests/harness/TestUtil.java
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| 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()); | ||
| } | ||
| } | ||
|
|
||
| } |
45 changes: 45 additions & 0 deletions
45
....eclipse.core.tests.harness/src/org/eclipse/core/tests/harness/rules/HangingTestRule.java
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| 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(); | ||
| } | ||
|
|
||
| } |
97 changes: 97 additions & 0 deletions
97
...lipse.core.tests.harness/src/org/eclipse/core/tests/harness/rules/HangingTestWatcher.java
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,97 @@ | ||
| /******************************************************************************* | ||
| * 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.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 Thread watchingThread; | ||
|
|
||
| private String testName; | ||
|
|
||
| private HangingTestWatcher(Duration timeout, String testName) { | ||
| this.timeout = timeout; | ||
| this.testName = testName; | ||
| } | ||
|
|
||
| private void start() { | ||
| final Thread originalThread = Thread.currentThread(); | ||
| final long startTimeInNanos = System.nanoTime(); | ||
| watchingThread = new Thread(() -> { | ||
| while (!isAborted()) { | ||
| long timeElapsedInNanos = System.nanoTime() - startTimeInNanos; | ||
| if (timeElapsedInNanos >= timeout.getNano()) { | ||
| logHangingThread(); | ||
| originalThread.interrupt(); | ||
| return; | ||
| } | ||
| } | ||
| }); | ||
| watchingThread.start(); | ||
| } | ||
|
|
||
| private boolean isAborted() { | ||
| boolean aborted = false; | ||
| if (!Thread.interrupted()) { | ||
| try { | ||
| Thread.sleep(50); | ||
| } catch (InterruptedException e) { | ||
| aborted = true; | ||
| } | ||
| } else { | ||
| aborted = true; | ||
| } | ||
| return aborted; | ||
| } | ||
|
|
||
| private void logHangingThread() { | ||
| System.out.println(getTimeoutMessage()); | ||
| } | ||
|
|
||
| private String getTimeoutMessage() { | ||
| return """ | ||
| %s ran into a timeout (%s seconds) with the following thread dump: | ||
| %s | ||
| """.formatted(testName, timeout.getSeconds(), TestUtil.createThreadDump()); | ||
| } | ||
|
|
||
| /** | ||
| * Stops this logger such that | ||
| */ | ||
| public void stop() { | ||
| watchingThread.interrupt(); | ||
| try { | ||
| watchingThread.join(); | ||
| } catch (InterruptedException e) { | ||
| throw new IllegalStateException(e); | ||
| } | ||
| } | ||
|
|
||
| public static HangingTestWatcher createAndStart(Duration timeout, String testName) { | ||
| HangingTestWatcher watcher = new HangingTestWatcher(timeout, testName); | ||
| watcher.start(); | ||
| return watcher; | ||
| } | ||
| } |