From 9adca15ec92ea388f103714c2e6c3b81c9567a0f Mon Sep 17 00:00:00 2001 From: Jack Zhuang <277994282+os-zhuang@users.noreply.github.com> Date: Fri, 31 Jul 2026 14:41:52 +0800 Subject: [PATCH] ci: Temporal Conformance's two test steps run under the stall guard (#4331) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both test steps in the Temporal Conformance (live PG + MySQL) job ran `pnpm test` bare, so a stall in either one had nothing to declare it: the job sat in_progress until its 30-minute timeout and ended as "The operation was canceled" — a red carrying no failing test, on PRs whose diff had nothing to do with the packages under test. #4331 recorded two such runs on one PR, both on the non-SQL step, ~4 and ~7× that job's normal 3-4 minute runtime. Both steps now wrap their pnpm invocation in run-with-stall-guard with the same `--stall-minutes 10` as Test Core (ci.yml:153/165), so silence past the limit becomes a labeled fast failure naming the last line seen. Each step keeps its TZ assertion ahead of the guard, unwrapped: the zone check must still abort the step before any test runs. The guard needed no new detector for the second shape #4331 saw — all five packages reporting Done and the process then never exiting. Verified against both shapes directly: a child that prints a completion summary and then never exits or emits is declared stalled at the limit and its process group killed (exit 75), and a child that exits while a silent grandchild still holds the stdio pipes open returns immediately rather than blocking the guard — `child.on('exit')`, not 'close'. Only the verdict text changed: it named just the mid-suite shape and sent readers hunting a hung test file that, in the post-Done shape, does not exist. Closes #4331 Co-Authored-By: Claude Opus 5 --- .../temporal-conformance-stall-guard.md | 4 +++ .github/workflows/ci.yml | 24 ++++++++++++++-- scripts/run-with-stall-guard.mjs | 28 ++++++++++++++----- 3 files changed, 47 insertions(+), 9 deletions(-) create mode 100644 .changeset/temporal-conformance-stall-guard.md diff --git a/.changeset/temporal-conformance-stall-guard.md b/.changeset/temporal-conformance-stall-guard.md new file mode 100644 index 0000000000..3194b0c9aa --- /dev/null +++ b/.changeset/temporal-conformance-stall-guard.md @@ -0,0 +1,4 @@ +--- +--- + +ci: the two Temporal Conformance test steps run under run-with-stall-guard, and the stall verdict names both stall shapes (#4331). CI-only — releases nothing. diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 9dbecfcd13..fdc2d5d78b 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -312,6 +312,17 @@ jobs: # The whole driver-sql suite runs under the skewed process zone — not # just the live-server files — so a TZ-sensitive assumption anywhere in # the driver's tests fails here before it can ship. + # + # run-with-stall-guard: same wiring and the same 10 minutes as Test Core + # (see the comment at that step). Both of this job's test steps ran bare + # until #4331, so a stall in either one sat in_progress for the full + # 30-minute job timeout and ended as "The operation was canceled" — a + # red with no failing test in it, on PRs whose diff had nothing to do + # with it. The occurrences #4331 recorded were all on the sibling + # non-SQL step; this step is guarded because it is the same job under + # the same timeout, not because it has been seen stalling. A healthy run + # of this job is 3–4 minutes end to end, so 10 minutes of dead air is + # not a slow suite. - name: Run driver-sql suite against both live servers env: TZ: America/New_York @@ -323,7 +334,8 @@ jobs: # everything still passes — the same vacuous-pass hole the live-server # suites close by asserting a non-UTC SERVER. node -e "const tz=Intl.DateTimeFormat().resolvedOptions().timeZone,off=new Date().getTimezoneOffset();if(!tz||tz==='UTC'||off===0){console.error('process zone is '+tz+' (offset '+off+') — this job must run skewed');process.exit(1)}console.log('process zone: '+tz+' (offset '+off+')')" - pnpm --filter @objectstack/driver-sql test + node scripts/run-with-stall-guard.mjs --log "$RUNNER_TEMP/temporal-driver-sql.log" --stall-minutes 10 -- \ + pnpm --filter @objectstack/driver-sql test # The non-SQL half of the same axis. `driver-sql` has run under a skewed # process zone since #3979, but the other backends the temporal @@ -350,6 +362,13 @@ jobs: --filter=@objectstack/formula... --concurrency=4 + # The leg #4331 actually caught stalling: twice on one PR whose diff + # touched none of these five packages, in both of the shapes the guard's + # silence watch covers — frozen partway through `core`'s kernel.test, + # and then, the next run, all five packages reporting Done and the + # process simply never exiting (a leaked handle, not a hung test). No + # output is no output, so one watchdog catches both; the last line it + # quotes is what tells them apart. - name: Run the non-SQL temporal backends under the skewed process zone env: TZ: America/New_York @@ -359,7 +378,8 @@ jobs: # everything still passes — the same vacuous-pass hole the live-server # suites close by asserting a non-UTC SERVER. node -e "const tz=Intl.DateTimeFormat().resolvedOptions().timeZone,off=new Date().getTimezoneOffset();if(!tz||tz==='UTC'||off===0){console.error('process zone is '+tz+' (offset '+off+') — this job must run skewed');process.exit(1)}console.log('process zone: '+tz+' (offset '+off+')')" - pnpm \ + node scripts/run-with-stall-guard.mjs --log "$RUNNER_TEMP/temporal-non-sql.log" --stall-minutes 10 -- \ + pnpm \ --filter @objectstack/core \ --filter @objectstack/formula \ --filter @objectstack/driver-memory \ diff --git a/scripts/run-with-stall-guard.mjs b/scripts/run-with-stall-guard.mjs index 6f83cecf65..faffb24e5f 100644 --- a/scripts/run-with-stall-guard.mjs +++ b/scripts/run-with-stall-guard.mjs @@ -16,6 +16,16 @@ // (EX_TEMPFAIL: the sanctioned response is a rerun -- every #4250 occurrence // passed on rerun of the same commit). // +// Silence is deliberately the ONLY signal, because it catches both observed +// shapes without having to tell them apart. #4331 hit Temporal Conformance in +// the second shape: every package printed `Done`, turbo printed its summary, +// and then the process never exited -- a leaked handle rather than a hung +// test. No output is no output, so the same watchdog fires; the quoted last +// line is what tells a reader which shape they got (a mid-test line vs. the +// run's own summary). Note the exit path is `child.on('exit')`, not 'close': +// the guard must not itself block waiting on stdio pipes a leaked grandchild +// is still holding open. +// // node scripts/run-with-stall-guard.mjs --log [--stall-minutes N] -- // // It also owns the log tee: combined stdout+stderr is forwarded to this @@ -118,14 +128,18 @@ ${'═'.repeat(72)} frozen since : ${new Date(lastOutputAt).toISOString()} last line : ${lastLine} - This is the #4250 failure mode -- the suite is STOPPED, not slow. A - healthy run prints continuously; only a hang goes silent this long. - Killing the test process group and failing the step now, instead of - sitting in_progress until the job timeout. + The run is STOPPED, not slow -- a healthy one prints continuously and + only a hang goes silent this long. Killing the test process group and + failing the step now, instead of sitting in_progress until the job + timeout. + + Read the last line above to place it: a mid-test line means the suite + hung partway (#4250); the run's own completion summary means every + package finished and the process then failed to exit (#4331). - Triage: every #4250 stall so far passed on a plain rerun of the same - commit -- rerun this job before suspecting the diff. If it stalls twice - at the same test file, add that occurrence to #4250. + Triage: every stall so far passed on a plain rerun of the same commit -- + rerun this job before suspecting the diff. If it stalls twice at the same + point, add that occurrence to #4250 (mid-suite) or #4331 (post-Done). ${'═'.repeat(72)} `; process.stdout.write(banner);