Skip to content

JAVA-6155 add thread dumps to evergreen logs on failed test cases#1932

Open
strogiyotec wants to merge 4 commits into
mongodb:mainfrom
strogiyotec:JAVA-6155
Open

JAVA-6155 add thread dumps to evergreen logs on failed test cases#1932
strogiyotec wants to merge 4 commits into
mongodb:mainfrom
strogiyotec:JAVA-6155

Conversation

@strogiyotec

@strogiyotec strogiyotec commented Apr 1, 2026

Copy link
Copy Markdown
Contributor

JAVA-6155
This PR adds thread dumps whenever test fails
The motivation behind this PR was a failing test case poolClearedExceptionMustBeRetryable
Claude identified a deadlock that I wasn't able to reproduce locally
With this PR develop could easily see thread dumps of all the threads directly in evergreen and locally

Here is an example of a patch that deliberately makes a test case fail and it's output

@strogiyotec strogiyotec requested a review from a team as a code owner April 1, 2026 18:21
@strogiyotec strogiyotec requested review from Copilot and nhachicha and removed request for nhachicha April 1, 2026 18:21

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR introduces a JUnit 5 TestWatcher extension that emits a full JVM thread dump to the test logs whenever a test fails, making deadlocks and hung-thread scenarios easier to diagnose in Evergreen and locally.

Changes:

  • Add ThreadDumpOnFailureExtension (JUnit Jupiter TestWatcher) that logs a thread dump on test failure.
  • Register the extension via META-INF/services/... and enable JUnit Jupiter extension autodetection via junit-platform.properties.

Reviewed changes

Copilot reviewed 3 out of 3 changed files in this pull request and generated 3 comments.

File Description
driver-core/src/test/unit/com/mongodb/internal/diagnostics/ThreadDumpOnFailureExtension.java Adds the failure hook and thread-dump collection logic.
driver-core/src/test/resources/META-INF/services/org.junit.jupiter.api.extension.Extension Registers the extension for ServiceLoader-based autodetection.
driver-core/src/test/resources/junit-platform.properties Enables JUnit Jupiter extension autodetection so the extension is picked up automatically.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

public void testFailed(final ExtensionContext context, final Throwable cause) {
String testName = context.getDisplayName();
String threadDump = getAllThreadsDump();
LOGGER.error("Test failed: " + testName + "\nThread dump:\n" + threadDump);

Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

testFailed ignores the provided cause, so the log entry won’t include the exception/stack trace that triggered the failure. Logging the throwable (e.g., using the error(String, Throwable) overload) would keep the failure reason adjacent to the thread dump in Evergreen/local logs.

Suggested change
LOGGER.error("Test failed: " + testName + "\nThread dump:\n" + threadDump);
LOGGER.error("Test failed: " + testName + "\nThread dump:\n" + threadDump, cause);

Copilot uses AI. Check for mistakes.

@strogiyotec strogiyotec Apr 1, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the cause will already be provided on assertion fail I don't think duplicating it for thread dumps makes sense

Comment on lines +39 to +50
public void testFailed(final ExtensionContext context, final Throwable cause) {
String testName = context.getDisplayName();
String threadDump = getAllThreadsDump();
LOGGER.error("Test failed: " + testName + "\nThread dump:\n" + threadDump);
}

private static String getAllThreadsDump() {
final ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
ThreadInfo[] threadInfos = threadMXBean.dumpAllThreads(
threadMXBean.isObjectMonitorUsageSupported(),
threadMXBean.isSynchronizerUsageSupported()
);

Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

getAllThreadsDump() (via ThreadMXBean.dumpAllThreads) can throw at runtime (e.g., SecurityException). If this happens inside testFailed, the extension itself may error and you’ll lose the diagnostic output. Consider wrapping thread-dump generation in a try/catch and logging a clear fallback message so the original test failure reporting isn’t impacted.

Copilot uses AI. Check for mistakes.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

good point, wrapped it with try catch

*/
public final class ThreadDumpOnFailureExtension implements TestWatcher {

private static final Logger LOGGER = Loggers.getLogger(ThreadDumpOnFailureExtension.class.getName());

Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Logger naming is inconsistent with other driver-core tests: most use a short suffix like ClassName.class.getSimpleName() (e.g., ConnectionPoolTest / ConnectionPoolAsyncTest). Passing class.getName() here yields a very long logger name (org.mongodb.driver.com.mongodb...) that’s harder to filter/read in logs; consider switching to getSimpleName() or a conventional test logger suffix.

Suggested change
private static final Logger LOGGER = Loggers.getLogger(ThreadDumpOnFailureExtension.class.getName());
private static final Logger LOGGER = Loggers.getLogger(ThreadDumpOnFailureExtension.class.getSimpleName());

Copilot uses AI. Check for mistakes.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

replaced to use simple name

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 3 out of 3 changed files in this pull request and generated 3 comments.


💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +19 to +30
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;


import com.mongodb.internal.diagnostics.logging.Logger;
import com.mongodb.internal.diagnostics.logging.Loggers;

import org.junit.jupiter.api.extension.ExtensionContext;
import org.junit.jupiter.api.extension.TestWatcher;


Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Import order/grouping here is inconsistent with the repo’s established convention (typically project com.mongodb.* imports first, then org.*, then java.*, e.g. driver-core/src/test/unit/com/mongodb/internal/connection/ConnectionPoolTest.java:19-28). Reorder the imports to match the surrounding codebase style to keep diffs consistent and reduce merge noise.

Suggested change
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import com.mongodb.internal.diagnostics.logging.Logger;
import com.mongodb.internal.diagnostics.logging.Loggers;
import org.junit.jupiter.api.extension.ExtensionContext;
import org.junit.jupiter.api.extension.TestWatcher;
import com.mongodb.internal.diagnostics.logging.Logger;
import com.mongodb.internal.diagnostics.logging.Loggers;
import org.junit.jupiter.api.extension.ExtensionContext;
import org.junit.jupiter.api.extension.TestWatcher;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;

Copilot uses AI. Check for mistakes.
Comment on lines +39 to +43
public void testFailed(final ExtensionContext context, final Throwable cause) {
String testName = context.getDisplayName();
String threadDump = getAllThreadsDump();
LOGGER.error("Test failed: " + testName + "\nThread dump:\n" + threadDump);
}

Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logs a full JVM thread dump on every failed test. When failures cascade (e.g., environment outage causing many tests to fail), this can produce very large Evergreen logs and make the original failures harder to find. Consider throttling (e.g., only dump once per JVM via an AtomicBoolean, or once per test class) and/or adding a clear header/footer delimiter so each dump is easy to locate in the log stream.

Copilot uses AI. Check for mistakes.
@@ -0,0 +1 @@
junit.jupiter.extensions.autodetection.enabled=true

Copilot AI Apr 1, 2026

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

junit-platform.properties is included in driver-core’s testArtifacts JAR (see buildSrc/src/main/kotlin/conventions/test-artifacts.gradle.kts:26-29), and several other modules depend on :driver-core:testArtifacts for their tests (e.g., driver-sync/build.gradle.kts:37-39). That means this setting may unintentionally enable JUnit Jupiter extension autodetection beyond driver-core depending on classpath resource resolution. If the intent is to scope this behavior to a specific module/test task, consider enabling it via the Gradle Test task/system property instead, or placing a shared properties file in a deliberately shared test-resources location.

Suggested change
junit.jupiter.extensions.autodetection.enabled=true
# NOTE:
# This file is included in driver-core's testArtifacts JAR and is therefore
# visible on the test classpath of other modules that depend on :driver-core:testArtifacts.
# Enabling JUnit Jupiter extension autodetection here would unintentionally
# turn it on for those modules as well.
#
# If you need autodetection, configure it in the specific module or Gradle
# Test task instead (e.g. via system property junit.jupiter.extensions.autodetection.enabled=true),
# or in a module-local junit-platform.properties that is not shared via testArtifacts.
#
# Example (do NOT uncomment here unless you really want it shared globally):
# junit.jupiter.extensions.autodetection.enabled=true

Copilot uses AI. Check for mistakes.

@nhachicha nhachicha left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

AI review (Opus 3.8 1M)

driver-core/src/test/resources/junit-platform.properties

  • 🟡 [important] L1: Autodetection leaks to downstream modules via testArtifacts.
    Verified: buildSrc/.../test-artifacts.gradle.kts builds the test JAR with from(sourceSets.test.get().output), which bundles processed test resources (including this file and the META-INF/services
    registration) alongside compiled test classes. driver-sync/build.gradle.kts:38 (and other modules) declare testImplementation(project(path = ":driver-core", configuration = "testArtifacts")). Net effect:
    junit.jupiter.extensions.autodetection.enabled=true and the ThreadDumpOnFailureExtension get activated for every consuming module's test run, not just driver-core. Two risks: (a) unintended global
    activation the author may not have planned for; (b) if any consuming module ships its own junit-platform.properties, JUnit Platform's classpath resolution of a single junit-platform.properties becomes
    order-dependent/non-deterministic. If global activation is actually desired, that's defensible — but it should be a deliberate, documented decision. Otherwise scope it via the Gradle Test task system
    property (systemProperty("junit.jupiter.extensions.autodetection.enabled", true)) in the relevant module(s).

driver-core/src/test/unit/com/mongodb/internal/diagnostics/ThreadDumpOnFailureExtension.java

  • 🟡 [important] L44-54: ThreadInfo.toString() truncates each stack to 8 frames.
    The JDK's ThreadInfo.toString() is hardcoded to emit at most MAX_FRAMES = 8 stack frames per thread, then prints .... Given the stated motivation (diagnosing a deadlock), 8 frames is often too shallow
    to see where threads are actually blocked. For a complete dump, iterate frames yourself, e.g. build the header from ThreadInfo and append the full info.getStackTrace(). The lock/monitor info you correctly
    enabled (below) also only renders for frames within that 8-frame window when using toString().

  • 🟢 [nit] L46-49: Captures dumps only for tests that fail, not tests that hang.
    TestWatcher.testFailed fires only when a test produces a failure. A true deadlock that hangs until the Gradle/JVM test timeout kills the process never reaches testFailed, so no dump is produced for that
    case. Worth being aware of relative to the deadlock-diagnosis goal; a JVM-level/@Timeout-driven approach would be needed to cover hangs. Not blocking for the failure-path use case.

  • 🟢 [nit] L20-31: Import grouping and double blank lines.
    Imports are grouped java.* first then com.mongodb.*/org.*, with doubled blank lines (L21-22, L29-30). I checked config/checkstyle/checkstyle.xml — only RedundantImport/UnusedImports are enforced,
    so this will not fail CI. Purely cosmetic; tidy up the consecutive blank lines if touching the file.

  • 🟢 [nit] L48-52: No delimiter between concatenated thread entries.
    sb.append(info) relies on each ThreadInfo.toString() trailing newline. A clear header/footer (e.g. ===== THREAD DUMP (test: X) =====) would make dumps far easier to locate and bound in large Evergreen
    logs.

  • 🎉 [praise] L46-49: Good defensive dumpAllThreads call — passing isObjectMonitorUsageSupported() / isSynchronizerUsageSupported() captures lock-ownership info, which is exactly what's useful for
    deadlock analysis. Nicely done, and the SecurityException fallback keeps the extension from masking the real test failure.

Prior Review Comments

  • 🎉 [praise] Extension.java:50Wrap thread-dump generation in try/catch. Addressed — current code catches SecurityException and returns a fallback message.
  • 🎉 [praise] Extension.java:36Logger naming should use a short suffix. Addressed — now Loggers.getLogger(ThreadDumpOnFailureExtension.class.getSimpleName()). Confirmed against
    Loggers.getLogger (prepends org.mongodb.driver.), so getSimpleName() is the right convention.
  • 💡 [suggestion] Extension.java:42Log the cause too. Disputed by the author ("the cause will already be provided on assertion fail"). Reasonable: JUnit already reports the failure cause
    independently, so this is largely redundant. Minor counterpoint — logging the cause keeps it adjacent to the dump in the same log line for correlation — but not worth blocking.
  • 🟡 [important] junit-platform.properties:1testArtifacts JAR propagates this setting to other modules. Unaddressed. Merged with the L1 finding above; I independently verified the build wiring
    confirms the concern.
  • 🟢 [nit] Extension.java:43Full dump on every failed test can flood logs on cascading failures. Unaddressed. Valid for failure storms; consider throttling (once per JVM via AtomicBoolean)
    and/or the delimiter suggested above. Low priority for a diagnostic util.
  • 🟢 [nit] Extension.java:30Import order inconsistent with repo convention. Unaddressed. Cosmetic only (not Checkstyle-enforced) — see nit above.

Decision:

  1. junit-platform.properties propagation — confirm whether enabling autodetection + the extension across all :driver-core testArtifacts consumers (driver-sync, etc.) is intended. If yes, add a
    comment in the properties file documenting it. If no, scope it via a per-module Gradle Test system property instead.
  2. 8-frame truncation — replace ThreadInfo.toString() with explicit iteration over info.getStackTrace() so deep deadlock stacks aren't cut off at 8 frames.
AI review copilot (GPT 5.5) Medium — driver-core/src/test/resources/junit-platform.properties:1

Placing junit-platform.properties under driver-core/src/test/resources means it is packaged into driver-core:testArtifacts, which is consumed by driver-sync, driver-reactive-streams, driver-scala, anddriver-legacy. Those modules will unintentionally inherit JUnit extension autodetection and load ThreadDumpOnFailureExtension for all their test failures.

That changes behavior outside driver-core and could produce very large logs during broad/cascading failures. Suggested fix: avoid classpath-wide autodetection from shared test artifacts, or configure it per module via Gradle/system property if global behavior is intended.

@@ -0,0 +1 @@
junit.jupiter.extensions.autodetection.enabled=true

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use ExtendWith instead to control the blast radius (i.e accidentally enabling other extensions)

@ExtendWith(ThreadDumpOnFailureExtension.class)
@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
public @interface ThreadDumpEnabledTest {
}

@nhachicha

Copy link
Copy Markdown
Collaborator

More AI Fable review below, as discussed on Zoom I think the one worth checking is the deadlock detection, the 8 frames hard caps and the explicit registration of the extension

AI review

1. ThreadInfo.toString() truncates stack traces to 8 frames

File: ThreadDumpOnFailureExtension.java (sb.append(info))

The JDK hardcodes MAX_FRAMES = 8 in ThreadInfo.toString(), appending .... For a
deadlock in DefaultConnectionPool, the top 8 frames are usually JUnit/Unsafe.park
frames — the lock-acquisition site is cut off, defeating the PR's purpose.

Fix: Format the dump manually (JDK 8-compatible; the dumpAllThreads(..., int maxDepth)
overload is Java 10+): build the header from ThreadInfo fields, iterate the full
info.getStackTrace(), and interleave getLockedMonitors() / getLockedSynchronizers().
Bonus: call threadMXBean.findDeadlockedThreads() and prepend a DEADLOCK DETECTED line.

2. Hung (never-completing) tests never trigger testFailed

TestWatcher.testFailed only fires when a test completes with a failure. A true
deadlock hangs until Evergreen kills the task — no dump is ever produced, which is the
exact scenario that motivated the PR.

Workarounds:

  • Add a global Jupiter timeout so hangs become failures that trigger the watcher:
    junit.jupiter.execution.timeout.testable.method.default = 10 m
  • CI belt-and-suspenders: an Evergreen watchdog that runs jstack / kill -3 on the
    test JVM shortly before task timeout (covers all engines, no code needed).
  • At minimum, document the limitation in the class javadoc.

3. Extension is Jupiter-only — Spock and JUnit 4 (vintage) tests are silent

The repo has hundreds of Groovy/Spock specs and vintage tests; those engines never invoke
Jupiter TestWatcher callbacks, so "thread dumps whenever test fails" doesn't hold for them.

Fix (best leverage): Rewrite as a JUnit Platform TestExecutionListener
(executionFinished + TestExecutionResult.Status.FAILED), registered via
META-INF/services/org.junit.platform.launcher.TestExecutionListener. Platform listeners
cover every engine (Jupiter, vintage, Spock 2.x) and are ServiceLoader-discovered by
default
— which also lets you delete junit-platform.properties, fixing #5 for free.

4. Modules not depending on driver-core's testArtifacts get no dumps

.evg.yml runs TESTS: 'bson:test bson-record-codec:test mongodb-crypt:test' (and the
kotlin modules' unit test tasks) with the flag set, but those classpaths never load the
extension — a silent diagnostics gap.

Workarounds:

  • Put the listener in a tiny shared test-diagnostics module added as testRuntimeOnly
    in the shared Gradle testing convention (avoids dragging all of driver-core's test
    output into bson).
  • Or explicitly document these modules as out of scope in the PR/Jira.

5. junit-platform.properties leaks autodetection to downstream modules

The testArtifacts jar bundles processed test resources, so
junit.jupiter.extensions.autodetection.enabled=true applies to driver-sync,
driver-legacy, driver-reactive-streams, driver-scala, and kotlin integrationTest.
Risks: any third-party extension shipped by a test dependency now auto-activates
everywhere; and a second junit-platform.properties added later would be resolved
non-deterministically (JUnit picks one, warns only).

Status: Partially mitigated by 8a9f055c — the extension itself is now inert unless
the system property is set. The global autodetection switch still leaks.

Fix: Move the switch into the Gradle test convention instead of a packaged resource:

// buildSrc/.../testing-base.gradle.kts, inside tasks.withType<Test>
systemProperty("junit.jupiter.extensions.autodetection.enabled", "true")

and delete junit-platform.properties. (Moot if #3's Platform-listener rewrite is taken.)
If keeping as-is, add a comment to the properties file documenting the propagation as intentional.

6. Other Evergreen scripts running the same suites weren't updated

.evergreen/run-socket-tests.sh and the three invocations in
.evergreen/run-load-balancer-tests.sh (historically hang-prone suites) don't set the flag.

Fix: Add -Dorg.mongodb.test.diagnostics.thread.dump.enabled=true to those scripts
(check with grep -l gradlew .evergreen/), or set it once in a common CI env-setup path.

The one-line takeaway if you're replying on the PR: the truncation fix (#1) is still outstanding and mechanical, and the Platform-listener rewrite (#3) would resolve #3 and #5 in a single change.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants