From d8cd4cf657250fd8f051d461f06495956c9f794f Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 13:17:24 +0000 Subject: [PATCH 01/17] ci(backend): log test STARTED/PASSED so a hung test names itself `testLogging` only reported FAILED and STANDARD_ERROR, so the `:test` phase printed nothing between the first class's byte-buddy warning and BUILD SUCCESSFUL. A run that hangs and gets killed by the 15-minute timeout produced a log byte-for-byte the same shape as a green one, with no indication of where it stopped -- four such timeouts since June were undiagnosable for this reason. With STARTED and PASSED, the last STARTED without a matching PASSED is the test that hung. Costs ~1160 extra log lines for ~580 tests. Co-Authored-By: Claude Opus 5 (1M context) --- backend/build.gradle | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/backend/build.gradle b/backend/build.gradle index 0ff1f8937a..a3356d2765 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -125,7 +125,13 @@ tasks.named('test') { useJUnitPlatform() jvmArgs '--enable-native-access=ALL-UNNAMED' testLogging { - events TestLogEvent.FAILED, TestLogEvent.STANDARD_ERROR + // STARTED + PASSED so an in-flight test is visible: on a hang, the last STARTED with no + // matching PASSED names the culprit. Without them the whole :test phase prints nothing, + // making a hung log indistinguishable from a green one. + events TestLogEvent.STARTED, + TestLogEvent.PASSED, + TestLogEvent.FAILED, + TestLogEvent.STANDARD_ERROR exceptionFormat = TestExceptionFormat.FULL showExceptions = true } From 7657ff88229ac5e3301c86e00a3d28ab48bba2f7 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 13:17:51 +0000 Subject: [PATCH 02/17] ci(backend): keep the JUnit XML when tests time out The job archived nothing, so `backend/build/test-results/test/*.xml` -- which carries per-class start times and the captured stdout that `testLogging` discards -- died with the runner on every failure. An `if: always()` upload alone would not have fixed that: `timeout-minutes` sat at *job* level, and a job timeout cancels the job, skipping all remaining steps. So move the 15-minute limit onto the `Run tests` step and give the job a larger cap; a step timeout fails only that step and lets the upload run. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/backend-tests.yml | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 4411eff0a3..881bd4a495 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -14,7 +14,10 @@ concurrency: jobs: test: runs-on: ubuntu-latest - timeout-minutes: 15 + # Deliberately larger than the `Run tests` step timeout below: a *job* timeout cancels the job, + # which skips every remaining step, so the diagnostics upload would never run. The step timeout + # fails just that step and lets `if: always()` steps continue. + timeout-minutes: 20 env: RUN_EXTRA_TESTS: ${{ github.event_name == 'push' && github.ref == 'refs/heads/main' && 'true' || 'false' }} steps: @@ -33,8 +36,21 @@ jobs: - name: Setup Gradle uses: gradle/actions/setup-gradle@v6 - name: Run tests + timeout-minutes: 15 run: ./gradlew test working-directory: ./backend + # Gradle already writes these; without an upload they die with the runner. The JUnit XML + # carries per-class start times and captured stdout, which is what localises a hang. + - name: Upload test results + if: always() + uses: actions/upload-artifact@v7 + with: + name: backend-test-results + path: | + backend/build/test-results/test/**/*.xml + backend/build/reports/tests/** + if-no-files-found: warn + retention-days: 14 lint: runs-on: ubuntu-latest From 9d07d60182a050591f371db87f51bf0e1ebc7701 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 13:18:41 +0000 Subject: [PATCH 03/17] ci(backend): thread-dump the test JVMs before the step timeout Knowing *which* test hung (previous commits) still leaves the question of where inside it. A step timeout kills the JVM without a stack, so run a watchdog that `jcmd Thread.print`s every live JVM at 11 and 13 minutes -- before the 15-minute deadline -- and ship the dumps with the test-results artifact. Two dumps a couple of minutes apart distinguish a genuinely stuck thread from a slow one. The watchdog is killed as soon as Gradle returns, so it costs nothing on the ~99.3% of runs that finish normally. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/backend-tests.yml | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 881bd4a495..65a2986ca9 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -37,8 +37,23 @@ jobs: uses: gradle/actions/setup-gradle@v6 - name: Run tests timeout-minutes: 15 - run: ./gradlew test working-directory: ./backend + run: | + # The step timeout kills the JVM without a stack trace, so snapshot every live JVM + # shortly before that deadline. Two dumps, a couple of minutes apart, so a thread that + # is genuinely stuck can be told apart from one that is merely slow. + mkdir -p build/diagnostics + dump() { + for pid in $(jcmd -l 2>/dev/null | grep -v 'sun.tools.jcmd' | awk '{print $1}'); do + jcmd "$pid" Thread.print > "build/diagnostics/threaddump-$1-$pid.txt" 2>&1 || true + done + } + ( sleep 660; dump at11min; sleep 120; dump at13min ) >/dev/null 2>&1 & + watchdog=$! + rc=0 + ./gradlew test || rc=$? + kill "$watchdog" 2>/dev/null || true + exit $rc # Gradle already writes these; without an upload they die with the runner. The JUnit XML # carries per-class start times and captured stdout, which is what localises a hang. - name: Upload test results @@ -49,6 +64,7 @@ jobs: path: | backend/build/test-results/test/**/*.xml backend/build/reports/tests/** + backend/build/diagnostics/** if-no-files-found: warn retention-days: 14 From eec6df3557d973dc4fcac941b7192343cf7dfda1 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:28:07 +0200 Subject: [PATCH 04/17] Apply suggestions from code review Co-authored-by: Cornelius Roemer --- .github/workflows/backend-tests.yml | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 65a2986ca9..c8acbd2d70 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -39,9 +39,7 @@ jobs: timeout-minutes: 15 working-directory: ./backend run: | - # The step timeout kills the JVM without a stack trace, so snapshot every live JVM - # shortly before that deadline. Two dumps, a couple of minutes apart, so a thread that - # is genuinely stuck can be told apart from one that is merely slow. + # Threaddump collected to help debug test hangs mkdir -p build/diagnostics dump() { for pid in $(jcmd -l 2>/dev/null | grep -v 'sun.tools.jcmd' | awk '{print $1}'); do @@ -54,8 +52,6 @@ jobs: ./gradlew test || rc=$? kill "$watchdog" 2>/dev/null || true exit $rc - # Gradle already writes these; without an upload they die with the runner. The JUnit XML - # carries per-class start times and captured stdout, which is what localises a hang. - name: Upload test results if: always() uses: actions/upload-artifact@v7 From ec0d28429d335a2ea7aeb208060ba7579530ad35 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:28:31 +0200 Subject: [PATCH 05/17] Apply suggestion from @corneliusroemer --- .github/workflows/backend-tests.yml | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index c8acbd2d70..5d05443475 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -14,9 +14,7 @@ concurrency: jobs: test: runs-on: ubuntu-latest - # Deliberately larger than the `Run tests` step timeout below: a *job* timeout cancels the job, - # which skips every remaining step, so the diagnostics upload would never run. The step timeout - # fails just that step and lets `if: always()` steps continue. + # larger than individual steps so logs can be collected timeout-minutes: 20 env: RUN_EXTRA_TESTS: ${{ github.event_name == 'push' && github.ref == 'refs/heads/main' && 'true' || 'false' }} From 5c5525378d318f87736171c1b822c4cbc6cd1402 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:29:09 +0200 Subject: [PATCH 06/17] Apply suggestion from @corneliusroemer --- backend/build.gradle | 3 --- 1 file changed, 3 deletions(-) diff --git a/backend/build.gradle b/backend/build.gradle index a3356d2765..4df83dbdfc 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -125,9 +125,6 @@ tasks.named('test') { useJUnitPlatform() jvmArgs '--enable-native-access=ALL-UNNAMED' testLogging { - // STARTED + PASSED so an in-flight test is visible: on a hang, the last STARTED with no - // matching PASSED names the culprit. Without them the whole :test phase prints nothing, - // making a hung log indistinguishable from a green one. events TestLogEvent.STARTED, TestLogEvent.PASSED, TestLogEvent.FAILED, From 84cec1abc470d3e7df8912c1afc2b509d1153595 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 13:31:55 +0000 Subject: [PATCH 07/17] ci(backend): upload the binary test results, not just the XML The earlier `**/*.xml` glob uploads nothing in the case it was written for. Gradle converts the binary results to JUnit XML and HTML only when the `test` task completes, so a killed run leaves neither. Measured by SIGKILLing a local run: 0 XML files and no HTML report even though all 580 tests had executed -- only build/test-results/test/binary survived. So upload that directory too, and add a `recoverTestReport` task that rebuilds a report from it, run on failure. Its limits are measured rather than assumed: recovery is complete when the tests finished and the kill hit report generation, but yields an empty report when the run is killed genuinely mid-flight -- 73 tests had passed across ~10 classes and none appeared, because the binary store is not committed incrementally. For a hang the STARTED/PASSED log and the thread dumps stay the usable evidence. Also drop `retention-days: 14`, an arbitrary number that inherited the very problem it was meant to solve; the repo default applies instead. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/backend-tests.yml | 9 +++++++-- backend/build.gradle | 6 ++++++ 2 files changed, 13 insertions(+), 2 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 5d05443475..10c6efd2b9 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -50,17 +50,22 @@ jobs: ./gradlew test || rc=$? kill "$watchdog" 2>/dev/null || true exit $rc + # A killed run leaves no XML or HTML report, only test-results/test/binary + - name: Recover test report + if: failure() + run: ./gradlew recoverTestReport || true + working-directory: ./backend - name: Upload test results if: always() uses: actions/upload-artifact@v7 with: name: backend-test-results path: | - backend/build/test-results/test/**/*.xml + backend/build/test-results/test/** backend/build/reports/tests/** + backend/build/reports/recovered/** backend/build/diagnostics/** if-no-files-found: warn - retention-days: 14 lint: runs-on: ubuntu-latest diff --git a/backend/build.gradle b/backend/build.gradle index 4df83dbdfc..e43c1177bf 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -163,3 +163,9 @@ task downloadDependencies { } } } + +// Gradle only writes XML/HTML when `test` completes, so rebuild from the binary results +tasks.register('recoverTestReport', TestReport) { + testResults.from(layout.buildDirectory.dir('test-results/test/binary')) + destinationDirectory = layout.buildDirectory.dir('reports/recovered') +} From 96259bcfc2b8962d98798b12c16581d85baeefdf Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:37:36 +0200 Subject: [PATCH 08/17] Apply suggestion from @corneliusroemer --- .github/workflows/backend-tests.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 10c6efd2b9..ce540012da 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -50,7 +50,6 @@ jobs: ./gradlew test || rc=$? kill "$watchdog" 2>/dev/null || true exit $rc - # A killed run leaves no XML or HTML report, only test-results/test/binary - name: Recover test report if: failure() run: ./gradlew recoverTestReport || true From 16bd0ce497648b892284464e61d5c1e33ead6a75 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 13:45:37 +0000 Subject: [PATCH 09/17] ci(backend): archive diagnostics only on failure, without duplicates Inspecting the artifact from a green run showed 60 MB carrying the same information three times: the JUnit XML (18 MB, and the only part that pays -- per-class timings plus the stdout logging Gradle discards from the console), `binary/output-events.bin` (19 MB, that same stdout in Gradle's internal format), and the HTML report (23 MB, a rendering of the XML). Nobody debugs a passing run, so upload on failure only. Drop the HTML, which is regenerable from the XML and absent on a kill anyway. Keep the binary results only when Gradle produced no XML, which is exactly when it was killed and they are the sole survivor; otherwise they duplicate the XML. Reverses the `always()` upload added earlier: the "green baseline to diff a hang against" it was justified by does not hold up -- that would want per-class timings, not 60 MB of HTML. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/backend-tests.yml | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index ce540012da..061c744c6b 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -50,18 +50,22 @@ jobs: ./gradlew test || rc=$? kill "$watchdog" 2>/dev/null || true exit $rc - - name: Recover test report + - name: Collect diagnostics if: failure() - run: ./gradlew recoverTestReport || true working-directory: ./backend + run: | + if ls build/test-results/test/*.xml >/dev/null 2>&1; then + rm -rf build/test-results/test/binary + else + ./gradlew recoverTestReport || true + fi - name: Upload test results - if: always() + if: failure() uses: actions/upload-artifact@v7 with: name: backend-test-results path: | backend/build/test-results/test/** - backend/build/reports/tests/** backend/build/reports/recovered/** backend/build/diagnostics/** if-no-files-found: warn From 8b5c91d8565c1afc8f80fc4855d9d4b5e7f18438 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 14:20:58 +0000 Subject: [PATCH 10/17] test(backend): stop SubmitLargeBatchTest writing a 127 MB results XML Its 100k inserts were logged individually by Exposed at debug, so the JUnit XML for that one class was 127 MB of the main-path artifact's 146 MB -- 123 MB of it from Slf4jSqlDebugLogger. Compressed that is only ~6 MB, but it makes the artifact unpleasant to download and expand. Set the level through `logging.level.Exposed=WARN` on the test's Spring context rather than manipulating the logger directly: a @BeforeAll that set the logback level was measured to have no effect, because Spring Boot re-applies logging configuration when the context starts, after @BeforeAll has run. Batch test XML 127.37 MB -> 1.28 MB, whole test-results directory 146 MB -> 41 MB. Checked that the level does not leak: logback levels are JVM-global, so this could have silenced SQL logging for every later class. It doesn't -- the DB-touching classes that run after this one still log Exposed at debug (the ones that don't are unit tests that never touch the database). Co-Authored-By: Claude Opus 5 (1M context) --- .../backend/controller/submission/SubmitLargeBatchTest.kt | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt index 771c061043..4b720461be 100644 --- a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt +++ b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt @@ -10,7 +10,8 @@ import org.springframework.beans.factory.annotation.Autowired import org.springframework.mock.web.MockMultipartFile import org.springframework.test.web.servlet.result.MockMvcResultMatchers.status -@EndpointTest +// Logging 100k inserts at debug made the test-results XML 127 MB +@EndpointTest(properties = ["logging.level.Exposed=WARN"]) @EnabledIfEnvironmentVariable(named = "RUN_EXTRA_TESTS", matches = "true") class SubmitLargeBatchTest( @Autowired val submissionControllerClient: SubmissionControllerClient, From b4c894cba7db9b2906101db2a68258005423a5d0 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:04:44 +0000 Subject: [PATCH 11/17] ci(backend): bound the diagnostics step so the upload always gets to run The Gradle daemon survives the runner killing the test step's process tree, so recoverTestReport can block on the project lock instead of failing, and `|| true` does not help against a block. With a 15-minute test step inside a 20-minute job there is only about three minutes left, so a block there would hit the job timeout, which cancels the job and skips the upload - losing the thread dumps this workflow exists to capture. --- .github/workflows/backend-tests.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 061c744c6b..146b020168 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -52,6 +52,8 @@ jobs: exit $rc - name: Collect diagnostics if: failure() + # bounded so a blocked Gradle lock can't eat the budget the upload needs + timeout-minutes: 2 working-directory: ./backend run: | if ls build/test-results/test/*.xml >/dev/null 2>&1; then From 9b3a6cb9986de5acbf0f1f1b53adb67319063a61 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:26:26 +0000 Subject: [PATCH 12/17] test(backend): write per-test progress to a file, not the console Streaming STARTED/PASSED to the console made every run's log unreadable for the sake of the rare hang that needs it. The progress is still what identifies a hung test, so it now goes to build/diagnostics/test-progress.log, which the existing artifact upload already picks up. Each line is appended and flushed as it happens, so a killed run keeps everything up to the moment it died. The lines are timestamped, which the console version could not be, so the log also gives per-test durations and shows exactly when progress stopped. Uses addTestListener rather than the beforeTest/afterTest closures: Gradle 9.7 deprecates those and removes them in 10, and they would have made the build report as Gradle 10 incompatible. On failure the diagnostics step prints just the tests that started and never finished, so the one line worth having in the job log is still there without the other 1159. --- .github/workflows/backend-tests.yml | 16 ++++++++++++++++ backend/build.gradle | 28 ++++++++++++++++++++++++---- 2 files changed, 40 insertions(+), 4 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 146b020168..1469cdb8b2 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -56,6 +56,22 @@ jobs: timeout-minutes: 2 working-directory: ./backend run: | + # the only progress signal worth putting in the log: what never finished + progress=build/diagnostics/test-progress.log + if [ ! -f "$progress" ]; then + echo "No $progress, so the test task never got as far as running a test." + else + unfinished=$(awk '{ ts = $1; ev = $2; sub(/^[^ ]+ [^ ]+ /, "") + if (ev == "STARTED") started[$0] = ts; else delete started[$0] } + END { for (t in started) print started[t], t }' "$progress") + echo "Tests started: $(grep -c ' STARTED ' "$progress")" + if [ -n "$unfinished" ]; then + echo "Tests that started but never finished:" + echo "$unfinished" + else + echo "Every test that started also finished." + fi + fi if ls build/test-results/test/*.xml >/dev/null 2>&1; then rm -rf build/test-results/test/binary else diff --git a/backend/build.gradle b/backend/build.gradle index e43c1177bf..131ce54125 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -1,3 +1,6 @@ +import org.gradle.api.tasks.testing.TestDescriptor +import org.gradle.api.tasks.testing.TestListener +import org.gradle.api.tasks.testing.TestResult import org.gradle.api.tasks.testing.logging.TestExceptionFormat import org.gradle.api.tasks.testing.logging.TestLogEvent @@ -125,13 +128,30 @@ tasks.named('test') { useJUnitPlatform() jvmArgs '--enable-native-access=ALL-UNNAMED' testLogging { - events TestLogEvent.STARTED, - TestLogEvent.PASSED, - TestLogEvent.FAILED, - TestLogEvent.STANDARD_ERROR + events TestLogEvent.FAILED, TestLogEvent.STANDARD_ERROR exceptionFormat = TestExceptionFormat.FULL showExceptions = true } + // per-test progress goes to a file, not the console, so a killed run still names the test it was in + def progressLog = layout.buildDirectory.file('diagnostics/test-progress.log') + doFirst { + def file = progressLog.get().asFile + file.parentFile.mkdirs() + file.text = '' + } + addTestListener(new TestListener() { + void beforeSuite(TestDescriptor suite) {} + + void afterSuite(TestDescriptor suite, TestResult result) {} + + void beforeTest(TestDescriptor descriptor) { + progressLog.get().asFile << "${java.time.Instant.now()} STARTED ${descriptor.className}.${descriptor.name}\n" + } + + void afterTest(TestDescriptor descriptor, TestResult result) { + progressLog.get().asFile << "${java.time.Instant.now()} ${result.resultType} ${descriptor.className}.${descriptor.name}\n" + } + }) } tasks.named('bootBuildImage') { From 52c37457a222d0b19562c89941ac63c7cf54b86a Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 15:35:40 +0000 Subject: [PATCH 13/17] ci(backend): put back the test report root page Anything logged from a plan-level hook has no test to be attributed to, so Gradle files it as root output of the whole test run, which exists only in build/reports/tests/test/index.html. That is where a failure to start the test environment reports its real cause. Measured on a forced startup failure: 74 per-class XMLs were written and the underlying pg_ctl error appeared in none of them and in no console line, only in that one file. This restores something earlier in this branch. 16bd0ce49 dropped reports/tests/** as a duplicate of the XML, which is true for a green or ordinarily-failing run and false for a startup failure, where the root page is the only durable copy of the cause. Rather than putting the whole report back, this takes just the root page: 57 KB against 9.4 MB, so the deduplication still holds for the per-class pages it was aimed at. The general lesson, since the same reasoning will come up again: when pruning archived diagnostics, judge each copy by what it holds on the worst run, not the typical one. --- .github/workflows/backend-tests.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 1469cdb8b2..1596b1b7e4 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -82,10 +82,12 @@ jobs: uses: actions/upload-artifact@v7 with: name: backend-test-results + # index.html is the only place output from outside a test lands, e.g. a failed test env start path: | backend/build/test-results/test/** backend/build/reports/recovered/** backend/build/diagnostics/** + backend/build/reports/tests/test/index.html if-no-files-found: warn lint: From 1952550830135222300ae865973e81694ef84a57 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 16:13:40 +0000 Subject: [PATCH 14/17] ci(backend): explain the test-progress listener The listener exists to make a hang name the test it was stuck in, without putting per-test output in the log of every normal run. Say that, and say why it is a TestListener rather than the shorter deprecated closures. Also say where the 127 MB came from, since the level alone doesn't show it. Co-Authored-By: Claude Opus 5 (1M context) --- backend/build.gradle | 4 +++- .../backend/controller/submission/SubmitLargeBatchTest.kt | 2 +- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/backend/build.gradle b/backend/build.gradle index 131ce54125..f5923407d5 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -132,13 +132,15 @@ tasks.named('test') { exceptionFormat = TestExceptionFormat.FULL showExceptions = true } - // per-test progress goes to a file, not the console, so a killed run still names the test it was in + // Records each test's start and finish so a hung run names the test it was stuck in. + // It goes to a file rather than the console, which would flood the log of every normal run. def progressLog = layout.buildDirectory.file('diagnostics/test-progress.log') doFirst { def file = progressLog.get().asFile file.parentFile.mkdirs() file.text = '' } + // TestListener rather than the shorter beforeTest/afterTest closures, which Gradle 9 deprecated addTestListener(new TestListener() { void beforeSuite(TestDescriptor suite) {} diff --git a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt index 4b720461be..3a3c622b4f 100644 --- a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt +++ b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt @@ -10,7 +10,7 @@ import org.springframework.beans.factory.annotation.Autowired import org.springframework.mock.web.MockMultipartFile import org.springframework.test.web.servlet.result.MockMvcResultMatchers.status -// Logging 100k inserts at debug made the test-results XML 127 MB +// logback-test.xml puts Exposed at debug, which made this test's 100k inserts a 127 MB test-results XML @EndpointTest(properties = ["logging.level.Exposed=WARN"]) @EnabledIfEnvironmentVariable(named = "RUN_EXTRA_TESTS", matches = "true") class SubmitLargeBatchTest( From 9c4aa3f984ae116d4582c1dd35167bc7f7b5741d Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 16:37:18 +0000 Subject: [PATCH 15/17] ci(backend): cut the diagnostics down to what a hang needs Three simplifications and one reversal, all of which shrink the workflow: `jcmd ` matches every JVM whose main class contains the substring, so `jcmd Gradle Thread.print` dumps the daemon and the test executor in one call, replacing the pid loop. It no longer covers the Kotlin compile daemon, but a wedge there shows up as the Gradle daemon waiting on it. The suite runs one test at a time (no maxParallelForks, no forkEvery, no junit-platform.properties), so the last line of the progress log is the test a hang was stuck in and a tail replaces the started-but-never-finished set. recoverTestReport is gone, along with the binary result store it read from. Recovery is empty when a run is killed while tests are still running, which is every hang we have, so it only paid off in the narrow window of a kill during the report write. Exposed logging stays at debug for the large-batch test: the 127 MB XML only appears when that main-only test fails, and there is no level that keeps a shorter trail, since Exposed inlines every parameter value into the statement it logs. Co-Authored-By: Claude Opus 5 (1M context) --- .github/workflows/backend-tests.yml | 42 ++++--------------- backend/build.gradle | 6 --- .../submission/SubmitLargeBatchTest.kt | 4 +- 3 files changed, 10 insertions(+), 42 deletions(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 1596b1b7e4..84bf9bb92c 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -37,46 +37,21 @@ jobs: timeout-minutes: 15 working-directory: ./backend run: | - # Threaddump collected to help debug test hangs mkdir -p build/diagnostics - dump() { - for pid in $(jcmd -l 2>/dev/null | grep -v 'sun.tools.jcmd' | awk '{print $1}'); do - jcmd "$pid" Thread.print > "build/diagnostics/threaddump-$1-$pid.txt" 2>&1 || true - done - } - ( sleep 660; dump at11min; sleep 120; dump at13min ) >/dev/null 2>&1 & + # Thread dumps before the step cap, so a hang shows where it is stuck. + # `jcmd Gradle` matches every JVM whose main class contains "Gradle": the daemon and the test executor. + ( sleep 660; jcmd Gradle Thread.print; sleep 120; jcmd Gradle Thread.print ) \ + > build/diagnostics/threaddumps.txt 2>&1 & watchdog=$! rc=0 ./gradlew test || rc=$? kill "$watchdog" 2>/dev/null || true exit $rc - - name: Collect diagnostics + - name: Show where the test run stopped if: failure() - # bounded so a blocked Gradle lock can't eat the budget the upload needs - timeout-minutes: 2 working-directory: ./backend - run: | - # the only progress signal worth putting in the log: what never finished - progress=build/diagnostics/test-progress.log - if [ ! -f "$progress" ]; then - echo "No $progress, so the test task never got as far as running a test." - else - unfinished=$(awk '{ ts = $1; ev = $2; sub(/^[^ ]+ [^ ]+ /, "") - if (ev == "STARTED") started[$0] = ts; else delete started[$0] } - END { for (t in started) print started[t], t }' "$progress") - echo "Tests started: $(grep -c ' STARTED ' "$progress")" - if [ -n "$unfinished" ]; then - echo "Tests that started but never finished:" - echo "$unfinished" - else - echo "Every test that started also finished." - fi - fi - if ls build/test-results/test/*.xml >/dev/null 2>&1; then - rm -rf build/test-results/test/binary - else - ./gradlew recoverTestReport || true - fi + # the suite runs one test at a time, so the last line is the test a hang was stuck in + run: tail -n 5 build/diagnostics/test-progress.log || echo "No progress log, so no test ever started." - name: Upload test results if: failure() uses: actions/upload-artifact@v7 @@ -84,8 +59,7 @@ jobs: name: backend-test-results # index.html is the only place output from outside a test lands, e.g. a failed test env start path: | - backend/build/test-results/test/** - backend/build/reports/recovered/** + backend/build/test-results/test/*.xml backend/build/diagnostics/** backend/build/reports/tests/test/index.html if-no-files-found: warn diff --git a/backend/build.gradle b/backend/build.gradle index f5923407d5..717f1b9752 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -185,9 +185,3 @@ task downloadDependencies { } } } - -// Gradle only writes XML/HTML when `test` completes, so rebuild from the binary results -tasks.register('recoverTestReport', TestReport) { - testResults.from(layout.buildDirectory.dir('test-results/test/binary')) - destinationDirectory = layout.buildDirectory.dir('reports/recovered') -} diff --git a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt index 3a3c622b4f..c33a25df79 100644 --- a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt +++ b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt @@ -10,8 +10,8 @@ import org.springframework.beans.factory.annotation.Autowired import org.springframework.mock.web.MockMultipartFile import org.springframework.test.web.servlet.result.MockMvcResultMatchers.status -// logback-test.xml puts Exposed at debug, which made this test's 100k inserts a 127 MB test-results XML -@EndpointTest(properties = ["logging.level.Exposed=WARN"]) +// logback-test.xml puts Exposed at debug, so this test's 100k inserts make its test-results XML ~127 MB +@EndpointTest @EnabledIfEnvironmentVariable(named = "RUN_EXTRA_TESTS", matches = "true") class SubmitLargeBatchTest( @Autowired val submissionControllerClient: SubmissionControllerClient, From 967762530e9d9c9e9e0e17392466bcec7ee0bad6 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 18:43:58 +0200 Subject: [PATCH 16/17] Apply suggestions from code review Co-authored-by: Cornelius Roemer --- backend/build.gradle | 2 -- .../backend/controller/submission/SubmitLargeBatchTest.kt | 1 - 2 files changed, 3 deletions(-) diff --git a/backend/build.gradle b/backend/build.gradle index 717f1b9752..1194324cf9 100644 --- a/backend/build.gradle +++ b/backend/build.gradle @@ -133,14 +133,12 @@ tasks.named('test') { showExceptions = true } // Records each test's start and finish so a hung run names the test it was stuck in. - // It goes to a file rather than the console, which would flood the log of every normal run. def progressLog = layout.buildDirectory.file('diagnostics/test-progress.log') doFirst { def file = progressLog.get().asFile file.parentFile.mkdirs() file.text = '' } - // TestListener rather than the shorter beforeTest/afterTest closures, which Gradle 9 deprecated addTestListener(new TestListener() { void beforeSuite(TestDescriptor suite) {} diff --git a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt index c33a25df79..771c061043 100644 --- a/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt +++ b/backend/src/test/kotlin/org/loculus/backend/controller/submission/SubmitLargeBatchTest.kt @@ -10,7 +10,6 @@ import org.springframework.beans.factory.annotation.Autowired import org.springframework.mock.web.MockMultipartFile import org.springframework.test.web.servlet.result.MockMvcResultMatchers.status -// logback-test.xml puts Exposed at debug, so this test's 100k inserts make its test-results XML ~127 MB @EndpointTest @EnabledIfEnvironmentVariable(named = "RUN_EXTRA_TESTS", matches = "true") class SubmitLargeBatchTest( From 91b5b8a2707ee7b4516d699d66fee1d0ae98ecc7 Mon Sep 17 00:00:00 2001 From: Cornelius Roemer Date: Tue, 25 Aug 2026 18:45:55 +0200 Subject: [PATCH 17/17] Apply suggestion from @corneliusroemer --- .github/workflows/backend-tests.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/.github/workflows/backend-tests.yml b/.github/workflows/backend-tests.yml index 84bf9bb92c..5895b78a1b 100644 --- a/.github/workflows/backend-tests.yml +++ b/.github/workflows/backend-tests.yml @@ -57,7 +57,6 @@ jobs: uses: actions/upload-artifact@v7 with: name: backend-test-results - # index.html is the only place output from outside a test lands, e.g. a failed test env start path: | backend/build/test-results/test/*.xml backend/build/diagnostics/**