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);