JMR-dev/LibreMediaConverter
1
0
Fork 0
Code Issues 16 Pull Requests Actions Packages Projects Releases Wiki Activity

Bound the JVM suite's hangs so a deadlock ends in minutes with a stack #127

Merged
JMR-dev merged 4 commits from test/bound-the-hangs into main 2026-08-26 05:21:48 +00:00
Conversation 1 Commits 4 Files Changed 3
+218
3 changed files with 218 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files
CLAUDE.md
+9
View File
@@ -246,3 +246,12 @@ Because versions float, a build can change without a commit. `./gradlew :app:dep
`@OptIn`. Android lint's `UnsafeOptInUsageError` catches a missed one.
- **Release builds ship both ABIs.** `-PabiFilters` is a test-run override only; `build.yml`
verifies the released APK carries every ABI and that all native libraries are 16 KB aligned.
- **A JUnit `Timeout` — rule or `@Test(timeout=)` — cannot be used in the JVM suite.** Both run the
test body on a separate thread, and every Compose test here goes through Robolectric's paused
main looper: `UnsupportedOperationException: main looper can only be controlled from main
thread`, from `ShadowPausedLooper` under `RobolectricIdlingStrategy.runUntilIdle`. The identical
tests pass with the timeout removed, so it is the mechanism, not the test. What bounds a hung
run instead is `timeout` on the `Test` tasks plus the jstack watchdog beside it in
`app/build.gradle.kts`, neither of which moves a thread. `HangBoundTest` guards both numbers,
and **a timed-out run writes no XML for the class that hung** — the dump is its only
attribution, so do not delete the watchdog as stray config.
app/build.gradle.kts
+111
View File
@@ -1,5 +1,7 @@
import org.gradle.api.tasks.PathSensitivity
import org.gradle.testing.jacoco.tasks.JacocoReport
import java.io.File
import java.time.Duration
plugins {
// Applied by id: these two come from the root buildscript classpath, which is what
@@ -217,6 +219,115 @@ tasks.withType<Test>().configureEach {
.withPropertyName("releaseWorkflow")
.withPathSensitivity(PathSensitivity.RELATIVE)
// Same reasoning, same trap: HangBoundTest reads the two numbers below out of this file, and
// they are the one part of the change that does not compile. Without this the task stays
// UP-TO-DATE when the build script changes, so the guard would go stale on exactly the edit
// it exists to catch.
inputs.file(project.file("build.gradle.kts"))
.withPropertyName("moduleBuildScript")
.withPathSensitivity(PathSensitivity.RELATIVE)
// --- Bounding a hung run (#125) -----------------------------------------------------------
//
// This suite had no timeout of any kind, so a hang ran until something outside it gave up.
// #125 is a real Java-level deadlock -- a lock-order inversion between Room's
// TransactionExecutor and WorkManager's SerialExecutorImpl, reached through the WorkInfo flow
// -- and one local run sat in it for 47 minutes. On CI it would burn the Unit tests job's
// 30-minute cap and report as a job timeout with no cause at all.
//
// WHY NOT A JUnit `Timeout` RULE, which is the obvious answer: it runs the test body on a
// separate thread, and this suite is thread-affine. Measured here, `@Rule Timeout` and
// `@Test(timeout = ...)` against a `createComposeRule()` Robolectric test both give:
//
// java.lang.UnsupportedOperationException: main looper can only be controlled from main
// at org.robolectric.shadows.ShadowPausedLooper.executeOnLooper
// at androidx.compose.ui.test.RobolectricIdlingStrategy.runUntilIdle
//
// The same two tests with the timeout removed pass, so that is the mechanism and not the
// probe. Nothing that moves a test off its own thread can be used here.
//
// `Task.timeout` moves nothing -- it stops the forked test JVM from outside. Its weakness is
// that it kills without a thread dump, and the jstack is the only reason #125 could be named
// at all; the watchdog below is what answers that, and it only dumps.
//
// THE NUMBER, against the slowest observed *pass* rather than the typical one. Eight CI runs
// sampled 2026-08-26, whole `./gradlew :app:testDebugUnitTest` invocation with compilation in
// it and this task a subset: 62, 76, 77, 79, 81, 84, 86 and 90 seconds. Locally the task
// itself is ~11 s over 454 tests. Ten minutes is ~6.7x the slowest of those and a third of
// the job's 30-minute cap, so a fired timeout still has room to be reported and uploaded. It
// is deliberately nowhere near the observed duration: a timeout that fires on a healthy slow
// runner turns a real signal into noise and teaches people to re-run reflexively.
timeout.set(Duration.ofMinutes(10))
// The dump, two minutes before the kill. jstack is what turned #125 from "CI timed out" into
// a named lock-order inversion, and `Task.timeout` on its own would have thrown it away.
//
// It is deliberately incapable of failing a build: it reads a live process and writes a file.
// Nothing here kills, interrupts or signals anything, so the worst a misfire can do is leave a
// stack trace nobody needed. It has one, and it is the ordinary CI shape rather than an exotic
// case: the worker is found by scanning this daemon's descendants for GradleWorkerMain, which
// cannot tell one invocation's worker from the next, and the Unit tests job runs
// testDebugUnitTest and jacocoTestReport back to back against the same daemon. If this task's
// own worker lived and died inside a single poll, the watchdog can adopt the following one.
//
// Everything it needs is read here, at configuration time, and captured by value. Reaching
// back through the task or the project from inside the action would not survive the
// configuration cache, which `gradle.properties` turns on for every build.
val threadDump = layout.buildDirectory.file("reports/hang/$name-threads.txt").get().asFile
val taskPath = path
val dumpAfterNanos = Duration.ofMinutes(8).toNanos()
val captureWindowNanos = Duration.ofMinutes(1).toNanos()
val pollMillis = 1_000L
doFirst {
val watchdog = Thread {
val startedAt = System.nanoTime()
var worker: ProcessHandle? = null
while (true) {
Thread.sleep(pollMillis)
val elapsed = System.nanoTime() - startedAt
val watched = worker
if (watched == null) {
// Gradle forks the worker moments after this task starts. If none has shown
// up by the end of the capture window there is nothing to watch, and going on
// polling would only risk adopting some other build's.
if (elapsed > captureWindowNanos) return@Thread
worker = ProcessHandle.current().descendants()
.filter { it.info().commandLine().orElse("").contains("GradleWorkerMain") }
.findFirst().orElse(null)
} else if (!watched.isAlive) {
return@Thread // the run finished; this is the healthy exit
} else if (elapsed >= dumpAfterNanos) {
val jstack = File(File(System.getProperty("java.home"), "bin"), "jstack")
threadDump.parentFile.mkdirs()
if (jstack.canExecute()) {
ProcessBuilder(jstack.absolutePath, "-l", watched.pid().toString())
.redirectErrorStream(true)
.redirectOutput(threadDump)
.start()
.waitFor()
} else {
threadDump.writeText("no jstack at ${jstack.absolutePath}\n")
}
// To stdout as well as to the file, and that is the half that matters on CI:
// the Unit tests job uploads app/build/reports/tests/ and nothing else, so a
// dump that only ever existed under reports/hang/ would be unreachable from a
// red run -- which is the "timed out with no cause" this exists to end. The
// step log always survives, and needs no workflow edit to say so.
println(
"$taskPath is still running after ${Duration.ofNanos(elapsed).toMinutes()} " +
"minutes and is about to be timed out. Thread dump of pid " +
"${watched.pid()}, also written to $threadDump -- look for 'Found one " +
"Java-level deadlock' (that is #125).\n" + threadDump.readText(),
)
return@Thread
}
}
}
watchdog.isDaemon = true
watchdog.name = "hang-watchdog"
watchdog.start()
}
extensions.configure<JacocoTaskExtension> {
isIncludeNoLocationClasses = true
excludes = listOf("jdk.internal.*")
app/src/test/java/org/libremediaconverter/ci/HangBoundTest.kt
+98
View File
@@ -0,0 +1,98 @@
package org.libremediaconverter.ci
import org.junit.Assert.assertTrue
import org.junit.Test
import java.io.File
/**
* That a hung unit-test run still ends by itself, and still says why.
*
* `:app:testDebugUnitTest` had no timeout of any kind until #125 was filed. That ticket is a real
* Java-level deadlock between Room's `TransactionExecutor` and WorkManager's `SerialExecutorImpl`,
* reached through the WorkInfo flow the ViewModel collects, and one local run sat in it for 47
* minutes. Nothing inside the suite could break it: the deadlock is monitor contention, which is
* not interruptible, so it runs until something outside the JVM gives up.
*
* Two numbers in `app/build.gradle.kts` are what bound it now, and neither compiles, so nothing
* else would notice their removal:
*
* - `timeout.set(...)` on every `Test` task, which stops the forked test JVM.
* - the watchdog's `dumpAfterNanos`, which jstacks that JVM *before* the timeout kills it.
*
* The second is the one worth guarding hardest, and the one that most looks like stray config.
* Gradle's timeout kills without a thread dump, and the jstack -- with its "Found one Java-level
* deadlock" section naming both monitors -- is the only reason #125 could be described at all.
* The ordering between the two numbers is what makes it work: dump first, kill second. Reverse
* them, or delete the watchdog, and the suite still stops hanging but every hang from then on
* reports as a bare "Timeout has been exceeded" with nothing to read. Measured against a probe
* that hung one test: no test XML was written for the class that hung, so the hanging test itself
* gets no attribution from the report at all.
*
* The range on the timeout is not decoration either, and it is the half a future edit is most
* likely to get wrong. Below it, a healthy-but-slow runner trips the bound and a real signal
* becomes noise people learn to re-run through; above it, CI's 30-minute job cap fires first and
* the bound never gets to say anything.
*
* `ReleasePermissionTest` is the precedent and its caveat applies here too. This asserts the two
* numbers are present, sanely sized and correctly ordered. It cannot assert that the timeout
* fires -- that needs a hang, which is what the whole change exists to prevent. Refs #125.
*/
class HangBoundTest {
@Test
fun `every Test task is bounded, and bounded between the slow runner and the job cap`() {
assertTrue(
"app/build.gradle.kts sets its Test task timeout to ${timeoutMinutes}m, which is " +
"outside $SANE_MINUTES. Under that range a slow CI runner trips a bound meant for " +
"deadlocks -- the slowest observed passing run of the whole invocation was 90s. " +
"Over it, the Unit tests job's own 30-minute cap kills the job first and the " +
"timeout never reports. `null` means the line is gone or the block was rewritten, " +
"and without it #125's deadlock has nothing to stop it: monitor contention breaks " +
"no interrupt, so it runs until CI gives up and reports a timeout with no cause.",
timeoutMinutes in SANE_MINUTES,
)
}
@Test
fun `the thread dump is taken before the timeout kills the JVM it would dump`() {
assertTrue(
"app/build.gradle.kts takes its hang thread dump after ${dumpAfterMinutes}m but times " +
"the task out at ${timeoutMinutes}m, so the JVM is already dead when jstack runs " +
"and every future hang reports as a bare `Timeout has been exceeded`. The dump " +
"has to come first -- it is the only attribution a hanging test gets, since the " +
"test XML never names it.",
(dumpAfterMinutes ?: 0) < (timeoutMinutes ?: 0),
)
}
/** Minutes given to a whole `Test` task before Gradle stops the forked JVM. */
private val timeoutMinutes: Int?
get() = minutesIn("""timeout\.set\(Duration\.ofMinutes\((\d+)\)\)""")
/** Minutes the watchdog waits before jstacking the forked JVM. */
private val dumpAfterMinutes: Int?
get() = minutesIn("""val dumpAfterNanos = Duration\.ofMinutes\((\d+)\)""")
/**
* Read out of the build script rather than from a model: the numbers live in a Kotlin DSL block
* that no unit test can instantiate, and a scan that reports `null` when the shape changes is a
* better trade than not checking them at all.
*/
private fun minutesIn(pattern: String): Int? =
Regex(pattern).find(buildScript.readText())?.groupValues?.get(1)?.toInt()
/**
* Found by walking up rather than by a fixed relative path: Gradle's working directory for the
* unit tests is the module, but that is a default rather than a promise.
*/
private val buildScript: File
get() = generateSequence(File(".").absoluteFile) { it.parentFile }
.map { File(it, "app/build.gradle.kts") }
.firstOrNull { it.isFile }
?: error("could not find app/build.gradle.kts above ${File(".").absolutePath}")
private companion object {
/** Above the slowest observed passing run, below the Unit tests job's `timeout-minutes`. */
val SANE_MINUTES = 3..29
}
}