diff --git a/.github/scripts/run-bounded.sh b/.github/scripts/run-bounded.sh new file mode 100755 index 000000000..05010ff83 --- /dev/null +++ b/.github/scripts/run-bounded.sh @@ -0,0 +1,48 @@ +#!/usr/bin/env bash +# Run a command under a wall-clock bound, and fail if it exceeds it. +# +# Usage: run-bounded.sh [args...] +# +# Why this exists rather than `timeout-minutes:` on the step. When a step exceeds its GitHub-side cap, the runner has to +# reap the step's process tree — and on windows-latest it could not. Observed on run 30697246865: the test step declared +# `timeout-minutes: 20` and ran 45m07s, the job then blew through its own 45-minute ceiling at 55m00s, and the runner was +# destroyed with both telemetry steps still pending. The one hang worth diagnosing produced no diagnostics at all, which +# is the exact failure #627 added the step cap to prevent. The cap did not hold. +# +# Why not `timeout(1)`. It is GNU coreutils, absent from macOS, which is two of the five arches in this matrix. Doing it +# in bash keeps one code path for every OS, which is the same reason the surrounding steps unified on `shell: bash`. +# +# On expiry we SIGKILL rather than SIGTERM: the process being bounded is a build that has already proven it is not +# responding, and a graceful signal it might ignore would put us back to waiting on a tree that will not die. + +set -uo pipefail + +if [ "$#" -lt 2 ]; then + echo "usage: run-bounded.sh [args...]" >&2 + exit 2 +fi + +limit_seconds="$1" +shift + +"$@" & +child_pid=$! + +waited=0 +poll_interval=5 +while kill -0 "$child_pid" 2>/dev/null; do + if [ "$waited" -ge "$limit_seconds" ]; then + # A GitHub workflow command, so this lands as an annotation on the job rather than only in the log. + echo "::error title=Timed out::'$*' exceeded ${limit_seconds}s and was killed" + kill -9 "$child_pid" 2>/dev/null || true + wait "$child_pid" 2>/dev/null || true + # 124 is what timeout(1) reports for this, so the number means the same thing here as everywhere else. + exit 124 + fi + sleep "$poll_interval" + waited=$(( waited + poll_interval )) +done + +# The loop only ends when the child is gone, so this reports its real exit status rather than blocking. +wait "$child_pid" +exit $? diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index 690820b60..46b178fb7 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -121,6 +121,8 @@ jobs: # Measured at 9m26s on master against ~3m30s of preceding steps, so 22 is >2x headroom and still # lands inside 30 with room for the upload. timeout-minutes: 22 + # No tag exclusions: this is the canonical full-suite gate, and the only place the platform linkers are + # exercised now that the native-image matrix skips them. run: ./bleep-cli.sh --dev test # Always, including on failure and step timeout — a run that went wrong is the one whose telemetry @@ -364,19 +366,26 @@ jobs: # `selftest` reaches the two FFM surfaces in the binary unconditionally (kernel32 for the terminal, SHGetKnownFolderPath for the user directories). # Both need `foreign` reachability metadata; without it the native image aborts at runtime and only a real Windows user finds out (#601). # - # Step cap, deliberately below the job's 45. Exceeding the *job* timeout tears the runner down with - # every remaining step, `if: always()` included — which is precisely what happened on windows-latest - # in this PR's own first run: the step hung for 36 minutes, the job was killed at its ceiling, and - # the two telemetry steps below never ran. The one arch the telemetry was written for produced - # nothing, for the one failure mode worth seeing. Failing the step instead keeps them. + # Bounded by `run-bounded.sh`, not by `timeout-minutes` alone. The step cap is a GitHub-side reap of the process + # tree, and on windows-latest that does not work: run 30697246865 declared 20 minutes here, ran 45m07s, blew the + # job's own 45-minute ceiling at 55m00s, and the runner was destroyed with both telemetry steps still pending. + # That is the same failure #627 added this cap to prevent, so the cap is evidently not sufficient on its own — + # and it fails in the worst way, destroying the diagnostics for the one hang worth reading. Killing the process + # ourselves fails the *step*, which keeps the `if: always()` collection below alive. # # Measured healthy durations for this step: 4m45s ubuntu-arm, 6m31s ubuntu, 10m13s macos-arm, - # 11m31s macos-intel, 12m52s windows. 20 is >1.5x the slowest, and clears the job budget on the - # slowest arch (macos-arm reaches this step at ~17m). - timeout-minutes: 20 + # 11m31s macos-intel, 12m52s-13m14s windows. 20m keeps the >1.5x-the-slowest margin this cap was originally + # sized for; only the enforcement was broken, so tightening the number too is not the fix. Runner variance is + # real and larger than it looks — macos-latest built the native image in 18m14s on one run and 24m28s on + # another, 34% apart — and a bound whose job is to catch a 45-minute hang loses nothing by clearing a slow + # healthy run comfortably. `selftest` is seconds, so 2m is generous. + # `timeout-minutes` stays as a backstop, now above our own bound rather than below it — 25 against the 22m our + # two bounds can add up to. It must also stay clear of the job's 45: macos-arm reaches this step at ~17m, so 25 + # lands at 42 and leaves the job cap as the last line rather than the first one to fire. + timeout-minutes: 25 run: | - ./${{ matrix.file_name }} --dev test --no-color jvm3 --exclude-tag slow - ./${{ matrix.file_name }} selftest + bash .github/scripts/run-bounded.sh 1200 ./${{ matrix.file_name }} --dev test --no-color jvm3 --exclude-tag slow + bash .github/scripts/run-bounded.sh 120 ./${{ matrix.file_name }} selftest # Same telemetry as the `build` job. This matrix is the only place Windows and macOS run, so without # it those arches were invisible: no metrics, no server log, nothing to read when a job hung or was diff --git a/bleep-bsp-tests/src/scala/bleep/MachineResourcesTest.scala b/bleep-bsp-tests/src/scala/bleep/MachineResourcesTest.scala index a6bc9a77f..8ec0ce900 100644 --- a/bleep-bsp-tests/src/scala/bleep/MachineResourcesTest.scala +++ b/bleep-bsp-tests/src/scala/bleep/MachineResourcesTest.scala @@ -332,7 +332,10 @@ class MachineResourcesTest extends AnyFunSuite with Matchers { val prog = for { // Fill memory, then shrink the budget under it so free memory is negative — exactly the state // the snapshot showed. - hold <- CountDownLatch[IO](1) + // Counts 8, once per fork. At 1 this returned as soon as the FIRST fork had reserved, so the retune below raced + // the other seven and the over-commit the test exists to construct only sometimes existed: at 8 forks free memory + // is -5480, but the test passes anywhere from 6 up, and CI caught it at 5 with `2200 was not less than 0`. + hold <- CountDownLatch[IO](8) release <- CountDownLatch[IO](1) forks <- (1 to 8).toList.parTraverse(i => m.reserve(TestFork, s"fork$i", cpu = 0, memoryMb = 2560).use(_ => hold.release *> release.await).start) _ <- hold.await diff --git a/bleep.yaml b/bleep.yaml index 11d989fad..78abee6cc 100644 --- a/bleep.yaml +++ b/bleep.yaml @@ -333,6 +333,32 @@ projects: # blocks the call outright — failing the suite. Scoped to this project rather than to every # forked test JVM bleep runs, because it is this suite's need, not a general one. jvmOptions: --enable-native-access=ALL-UNNAMED + # Suites that drive a real platform linker: Scala.js, Scala Native, Kotlin/JS, Kotlin/Native. Each one compiles a + # source and then links an artifact — for Scala Native that means NIR -> LLVM IR -> clang -> executable, at Debug, + # ReleaseFast and LTO — so the time is clang's and no build tool makes it cheaper. + # + # `slow`, the same tag bleep-tests puts on its `**IT` suites, because it means the same thing and is already wired + # where it is wanted: the native-image jobs pass `--exclude-tag slow`, and they exist to prove the produced binary + # runs rather than to re-exercise the test surface. Worth 7.7 of 18.3 minutes of suite time on windows. + # + # The `build` job stays the canonical full-suite gate and keeps running these, so every linker is still exercised + # once per CI run — just once instead of five times. Run them directly with + # `bleep test bleep-bsp-tests --only-tag slow`. + # + # Listed by name rather than by a glob. The cost is a property of what each suite does, not of what it is called: + # the cheap suites in the same packages also mention link types, and `ScalaNativeAdvancedTestIntegrationTest` is + # 132s from a single link call. A pattern would catch the wrong set in both directions. + testTags: + slow: + - bleep.analysis.ScalaNativeAdvancedIntegrationTest + - bleep.analysis.ScalaNativeAdvancedTestIntegrationTest + - bleep.analysis.ScalaNativeAdvancedLinkIntegrationTest + - bleep.analysis.KotlinNativeIntegrationTest + - bleep.analysis.KotlinNativeAdvancedIntegrationTest + - bleep.analysis.LinkExecutorIntegrationTest + - bleep.analysis.ScalaJsAdvancedIntegrationTest + - bleep.analysis.ScalaJsAdvancedLinkIntegrationTest + - bleep.analysis.KotlinJsAdvancedIntegrationTest bleep-tests: dependencies: org.scalatest::scalatest:3.2.19 dependsOn: