Skip to content

HADOOP-19964. Restore TimedOutTestsListener thread dumps on test timeout. - #8682

Open
joseluisll wants to merge 1 commit into
apache:trunkfrom
joseluisll:HADOOP-19964
Open

HADOOP-19964. Restore TimedOutTestsListener thread dumps on test timeout.#8682
joseluisll wants to merge 1 commit into
apache:trunkfrom
joseluisll:HADOOP-19964

Conversation

@joseluisll

Copy link
Copy Markdown
Contributor

Description of PR

JIRA: HADOOP-19964

A test that fails on timeout now produces exactly one full JVM thread dump,
with deadlock analysis, taken while the threads are still hung — in every
module, with no per-pom wiring. That is the diagnostic you actually want for
a hang, and today you get either nothing or two copies of it.

Two things had to change to get there. TimedOutTestsListener, which prints
the dump, has been dead code since February 2025 and is rewritten here as a
JUnit Platform listener. And GenericTestUtils.waitFor — at 650 call sites
the most common timeout in the suite — used to inline its own 16 KB dump into
every TimeoutException message; it now routes through that same listener,
so the message drops to one line and the dump joins the others on stderr.

Scope of the change: 12 files, +336/-86, of which 54 deleted lines are dead
pom configuration.

This diagnostic has been silently dead since February 2025. HADOOP-19415
Part 4 moved Surefire onto the JUnit Platform provider, and
TimedOutTestsListener was a JUnit 4 RunListener registered through the
Surefire listener provider property — which that provider ignores. Eight
poms have been carrying the property ever since, registering nothing, and a
timed-out test has reported only its exception. The failure mode is invisible:
a missing dump looks exactly like a test that never hung.

What changed

  • TimedOutTestsListener is now a JUnit Platform TestExecutionListener,
    registered through
    META-INF/services/org.junit.platform.launcher.TestExecutionListener in the
    hadoop-common test resources. Because it rides in the hadoop-common
    test-jar, it activates anywhere that artifact is on the test classpath.
    That is a wider net than the old wiring ever cast, even when it worked:
    coverage no longer depends on each module remembering to paste a property.
    It detects JUnit 5 @Timeout, the JUnit 4 vintage runner's
    TestTimedOutException (by class name, so no vintage dependency), and any
    failure whose message says it timed out.
  • Two controls the 2012 original never had: -Dhadoop.test.timedout.dump=false
    disables the dump entirely, and -Dhadoop.test.timedout.dump.limit
    (default 5) caps the dumps one JVM prints, with a single elision notice at
    the cap.
  • One dump per timeout, in one place. GenericTestUtils.waitFor built a full
    thread dump into every TimeoutException it threw — some 16 KB per failure,
    at 650 call sites across 258 files. It now prints that dump through
    TimedOutTestsListener.dumpForTimeout and its message shrinks to one line
    saying where the dump went; the listener matches that marker and stays
    quiet. The two properties above now cover waitFor as well, which the
    inlined dump obeyed neither of.
  • The dead listener property is gone from all eight poms (hadoop-common,
    hadoop-kms, hadoop-hdfs, hadoop-hdfs-httpfs,
    hadoop-mapreduce-client-nativetask, hadoop-mapreduce-client,
    hadoop-mapreduce-project, hadoop-yarn); no pom in the tree references it
    any more. Where removal left an empty <configuration/>, that element is
    dropped but the plugin declaration is kept, so no module's surefire
    activation or version resolution changes.

Why waitFor still takes its own dump rather than deferring to the
listener: a TestExecutionListener is only notified at executionFinished,
which fires once the test method and its teardown have unwound. For a hang,
the threads you need to see are usually gone by then — a MiniDFSCluster has
been shut down in @AfterEach. Dumping inside waitFor keeps the capture at
the instant the wait expired, exactly where it was before this patch. The
listener remains the only option for @Timeout, which gives no earlier hook.
Both paths share the enable switch and the per-JVM budget.

Scope and limits (verified against Surefire 3.5.3): the listener fires for
timeouts that fail through JUnit (@Timeout and friends). It cannot cover a
fork killed by Surefire at forkedProcessTimeoutInSeconds
ForkClient#tryToTimeout sends the fork Shutdown.KILL regardless of the
configured shutdown strategy, and the fork executes Runtime.halt(), which
bypasses listeners and shutdown hooks alike. That case is handled by
HADOOP-19950 (Surefire dumpstream capture and CI upload). The two are
complementary: this listener writes to System.err, so its dump lands in
surefire-reports/*-output.txt, already inside the globs HADOOP-19950
uploads in CI.

Note for downstream consumers: the same ServiceLoader registration that
removes the per-pom wiring also means projects consuming the hadoop-common
test artifact (HBase, Ozone, Hive, Tez, …) pick the listener up without
asking for it, and waitFor's exception message changes shape for them too —
the dump moves out of the message and onto stderr. Nothing in the Hadoop tree
asserted on that message, but downstream code that did will need adjusting.
-Dhadoop.test.timedout.dump=false opts out of the dumps entirely. A release
note is attached to the JIRA.

This patch was developed with AI assistance. Contains content generated by
Claude Code.

How was this patch tested?

  • End-to-end through the real ServiceLoader path, under a plain mvn test: a
    scratch test (not part of this PR) pairing a hanging @Timeout(3) method
    with a GenericTestUtils.waitFor timeout. Each produced exactly one dump
    in surefire-reports/*-output.txt, labelled Test: testHangOnJunitTimeout()
    and Timed out in: GenericTestUtils.waitFor respectively, and the
    @Timeout case was confirmed in both SAME_THREAD and SEPARATE_THREAD
    modes. The waitFor message dropped from ~16 KB to a single line, taking
    its report file from 18,223 to 1,642 bytes; it now reads in full:
    TimeoutException: Timed out waiting for condition. Thread dump printed to stderr.
    The dump is moved, not discarded — it lands in -output.txt with the
    others, so total bytes are about the same. The win is that the failure you
    read first is legible.
  • TestTimedOutTestsListener (5 tests): thread-dump content and deadlock
    detection (6-thread monitor + synchronizer deadlock), timeout-failure
    detection, the hadoop.test.timedout.dump=false kill switch, the per-JVM
    dump limit and its single elision notice, and both halves of the waitFor
    change — that it prints its own dump with the right label and that its
    message is now one line, plus that the off switch reaches it. The waitFor
    tests drive the real helper, so they fail if either side changes. All pass,
    as does TestGenericTestUtils unchanged (13 tests together):
    mvn -B test -pl hadoop-common-project/hadoop-common -Dtest='TestTimedOutTestsListener,TestGenericTestUtils'
  • Registration verified to ship: the services file is copied into
    hadoop-common/target/test-classes/META-INF/services/, i.e. into the
    test-jar, alongside Hadoop's existing service registrations. The same run
    logs Using auto detected provider org.apache.maven.surefire.junitplatform.JUnitPlatformProvider — which is
    why the old JUnit 4 listener property registered nothing.
  • mvn test-compile passes on all eight modules whose poms changed. Because
    the GenericTestUtils change ships inside the hadoop-common test-jar,
    hadoop-registry — a consumer of that artifact — was also test-compiled
    against it: BUILD SUCCESS, so test-jar consumers are unaffected at compile
    time.
  • Checkstyle: TimedOutTestsListener.java and TestTimedOutTestsListener.java
    are both clean. The test file carried two violations inherited from the 2012
    original — a package-private field in the Monitor helper and a brace-less
    if — which this PR fixes in passing, since it rewrites that file anyway.
    GenericTestUtils.java has pre-existing violations, none on any line this
    PR touches.

For code changes:

  • Does the title of this PR start with the corresponding JIRA issue id
    (e.g. 'HADOOP-17799. Your PR title ...')?
  • Object storage: Have the integration tests been executed and the endpoint
    declared according to the connector-specific documentation? N/A
  • If adding new dependencies to the code, are these dependencies licensed
    in a way that is compatible for inclusion under
    ASF 2.0?
    N/A — no new dependencies
  • If applicable, have you updated the LICENSE, LICENSE-binary,
    NOTICE-binary files? N/A

AI Tooling

If an AI tool was used:

@joseluisll

Copy link
Copy Markdown
Contributor Author

Cross-reference: this pairs with #8659 (HDFS-17957), which sets a default
junit.jupiter.execution.timeout.default on the hdfs modules.
The two cover different halves of the same problem. This PR restores the thread
dump for tests that fail through JUnit, and explicitly cannot cover a fork
killed at forkedProcessTimeoutInSeconds: Surefire sends the fork
Shutdown.KILL, the fork executes Runtime.halt(), and that bypasses
listeners and shutdown hooks alike. #8659 is what moves hung hdfs tests off
that path — with a default @Timeout they fail through JUnit instead, at which
point this listener produces the dump. Neither PR alone yields a usable
diagnostic for a hung HDFS test.
The two touch one file in common, hadoop-hdfs-project/hadoop-hdfs/pom.xml:
#8659 adds inside <systemPropertyVariables>, this one removes the dead
<properties> listener block just after it. I trial-merged the two heads and
the result is clean, with both changes intact, in either order — no rebase
needed whichever lands first.

…out.

A test that fails on timeout prints a full thread dump again, in every
module rather than the eight that opted in. TimedOutTestsListener
(HADOOP-8755, 2012) did this until the JUnit 5 migration (HADOOP-19415
Part4) left it implementing no listener interface; the Surefire
"listener" property that 8 poms still carried registered nothing.

- Reimplement it as a JUnit Platform TestExecutionListener,
  auto-registered via META-INF/services in the hadoop-common test
  artifact, so no per-pom wiring is needed and coverage no longer
  depends on each module remembering to paste a property.
- Remove the dead "listener" property from the 8 poms. Where that left
  an empty <configuration/>, the element is dropped but the plugin
  declaration is kept, so no module's surefire activation or version
  resolution changes. hadoop-registry keeps its hadoop-common test-jar
  dependency: still required, and it now carries the services entry.
- Stop GenericTestUtils.waitFor inlining a thread dump into every
  TimeoutException it throws. At 650 call sites across 258 files it is
  the most common timeout in the suite, and each failure carried some
  16KB of dump inside the exception message. It now prints that dump
  through TimedOutTestsListener.dumpForTimeout at the moment the wait
  expires, while the threads are still hung, and its message shrinks to
  one line saying where the dump went. The listener matches that marker
  and stays quiet, so a timeout yields exactly one dump, in one place.
  -Dhadoop.test.timedout.dump=false and the per-JVM limit now cover
  waitFor too; the inlined dump obeyed neither.
- -Dhadoop.test.timedout.dump=false turns dumps off;
  -Dhadoop.test.timedout.dump.limit (default 5) caps them per JVM, with
  a single elision notice at the limit. Both entry points obey the
  switch and draw on the one budget, which the javadoc spells out: a JVM
  that spends it on waitFor timeouts will not dump for a later @timeout.
- Fix the two checkstyle violations the 2012 test file carried, a
  package-private field in the Monitor helper and a brace-less if,
  since this rewrites that file anyway. Both listener files are now
  checkstyle-clean.

The listener necessarily dumps at executionFinished, after the test
method and its teardown have unwound. That is why waitFor keeps its own
capture point rather than deferring to it: for a hang, the threads you
want to see are usually gone by teardown.

Covers timeouts that fail through JUnit. Does not cover Surefire's fork
kill at forkedProcessTimeoutInSeconds: verified against Surefire 3.5.3,
ForkClient#tryToTimeout sends Shutdown.KILL regardless of the configured
shutdown strategy and the fork executes Runtime.halt(), bypassing
listeners and shutdown hooks alike. Complements HADOOP-19950, whose CI
upload globs already capture the report files these dumps land in.

The listener activates for every module and downstream consumer of the
hadoop-common test artifact (HBase, Ozone, Hive, Tez), and waitFor's
exception message changes shape for all of them: needs a release note.

Verified: TestTimedOutTestsListener covers detection, the off switch,
the dump limit, and both halves of the waitFor change, the last by
driving the real waitFor so the checks fail if either side changes.
TestGenericTestUtils passes unchanged. End-to-end, a hung @timeout(3)
test dumps through the real ServiceLoader path in both timeout thread
modes, while a waitFor timeout in the same run dumps once at its own
deadline; the failure report fell from 18,223 to 1,642 bytes and both
dumps now land in the same -output.txt.

Contains content generated by Claude Code.
Generated-by: Claude Code (Opus 5)
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant