From d144b47b841add2925dc86b8dc679d78fcc82e7e Mon Sep 17 00:00:00 2001 From: Pascal Garber Date: Fri, 11 Sep 2026 21:44:38 +0200 Subject: [PATCH] feat: name a sweep that no longer fits its job MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Ported from #15, which measured the case and is now closed: everything else it carried arrived via #16 and #17. A sweep killed by `timeout-minutes` reports that the RUNNER exceeded its maximum execution time, which names neither the package it was on nor how far it got. Give the publisher its own budget, under the job's, so the message a human reads is the publisher's. Put elapsed and ETA on every progress line for the same reason: the run-level `updatedAt` GitHub exposes does not advance while a job streams logs, so from the API a sweep that is working looks exactly like one that is wedged. Reading it that way is what got the 4.8.0 sweep cancelled at 38% while it was publishing normally. Both decisions are pure functions in publish-plan.ts so they can be held to cases that go both ways โ€” zero disables the deadline rather than expiring instantly, which a plain `now > start` would get wrong. Claude-Session: https://claude.ai/code/session_012KM53BXFvEdP4PLgcojKCS --- .github/release-script/src/index.ts | 34 +++++++++++++++++-- .../release-script/src/publish-plan.test.ts | 20 +++++++++++ .github/release-script/src/publish-plan.ts | 25 ++++++++++++++ 3 files changed, 77 insertions(+), 2 deletions(-) diff --git a/.github/release-script/src/index.ts b/.github/release-script/src/index.ts index 5ba73042d2..e278c57dbf 100644 --- a/.github/release-script/src/index.ts +++ b/.github/release-script/src/index.ts @@ -8,11 +8,13 @@ import { type ClosureGap, closureGaps, classifyGap, + formatDuration, describeGap, planPublishOrder, type PublishGroup, type RegistryView, runtimeDependencies, + sweepDeadlineExceeded, takeIndependentRun, } from "./publish-plan.ts"; @@ -985,6 +987,13 @@ class LiveRegistry implements RegistryView { * two hours sitting in this loop over 76 gaps that were all lag: 19.2 s per package against the * 10.7 s of the release before it. */ +/** + * Wall-clock budget for the whole sweep. Keep it UNDER release.yml's `timeout-minutes`, so a run + * that stops fitting says which package it was on instead of leaving the runner to report that it + * exceeded its maximum execution time. Zero disables it. + */ +const DEADLINE_MIN = Math.max(0, getEnvInt("NPM_DEADLINE_MIN", 300)); + const CLOSURE_LAG_BUDGET_MS = Math.max(0, getEnvInt("NPM_CLOSURE_LAG_MS", 15_000)); const CLOSURE_LAG_STEP_MS = Math.max(250, getEnvInt("NPM_CLOSURE_LAG_STEP_MS", 5_000)); @@ -1083,6 +1092,7 @@ async function publishPendingPackages( console.log(`๐Ÿš€ Phase 2: Publishing ${pendingCount} packages in plan order (batch size: ${BATCH_SIZE})...\n`); + const startedAt = Date.now(); let processed = 0; // A failed PUBLISH and a closure not yet readable are different facts with different // remedies. One counter for both is what printed "76 of 792 package(s) failed to publish" @@ -1091,6 +1101,17 @@ async function publishPendingPackages( const published: Package[] = []; for (let i = 0; i < pendingGroups.length; ) { + // Checked between groups, never mid-flight: a publish already in the air is finished and + // counted. `--continue-on-error` governs a failing PACKAGE, not a run that no longer fits. + if (sweepDeadlineExceeded(startedAt, Date.now(), DEADLINE_MIN)) { + const left = pendingGroups.slice(i).reduce((n, group) => n + group.members.length, 0); + throw new Error( + `sweep deadline of ${DEADLINE_MIN} min reached with ${left} of ${pendingCount} package(s) ` + + `unpublished (published: ${processed}, failed: ${publishErrors}). ` + + "Raise NPM_DEADLINE_MIN, or find why the registry got slow.", + ); + } + const run = takeIndependentRun(pendingGroups, i, BATCH_SIZE); const members = run.flatMap((group) => group.members); i += run.length; @@ -1149,8 +1170,17 @@ async function publishPendingPackages( } } - const progress = (((processed + publishErrors) / pendingCount) * 100).toFixed(1); - console.log(`โœ… ${progress}% - Processed: ${processed}, Errors: ${publishErrors}\n`); + // Elapsed and ETA on every line, because the run-level `updatedAt` GitHub exposes does NOT + // advance while a job streams logs โ€” from the API a sweep that is working looks exactly like + // one that is wedged. Reading it that way is what got the 4.8.0 sweep cancelled at 38%. + const done = processed + publishErrors; + const progress = ((done / pendingCount) * 100).toFixed(1); + const elapsedS = (Date.now() - startedAt) / 1000; + const etaS = done > 0 ? (elapsedS / done) * (pendingCount - done) : 0; + console.log( + `โœ… ${progress}% - Processed: ${processed}, Errors: ${publishErrors}` + + ` - elapsed ${formatDuration(elapsedS)}, ETA ${formatDuration(etaS)}\n`, + ); if (i < pendingGroups.length && BATCH_DELAY_MS > 0) { await sleep(BATCH_DELAY_MS); diff --git a/.github/release-script/src/publish-plan.test.ts b/.github/release-script/src/publish-plan.test.ts index dfd542052a..92a4dd866f 100644 --- a/.github/release-script/src/publish-plan.test.ts +++ b/.github/release-script/src/publish-plan.test.ts @@ -28,6 +28,7 @@ import { satisfies } from "semver"; import { closureGaps, classifyGap, + formatDuration, describeGap, type PlannablePackage, planPublishOrder, @@ -35,6 +36,7 @@ import { type RegistryView, runtimeDependencies, stronglyConnectedComponents, + sweepDeadlineExceeded, takeIndependentRun, } from "./publish-plan.ts"; @@ -352,3 +354,21 @@ test("the three verdicts are distinguishable โ€” the same gap, three plans", () ]; assert.deepEqual(verdicts, ["lag", "ordering-defect", "not-in-release"]); }); + + +// --- the sweep's own clock ---------------------------------------------------------------- + +test("the deadline fires only after the budget, and zero disables it", () => { + const start = 1_000_000; + assert.equal(sweepDeadlineExceeded(start, start + 299 * 60_000, 300), false); + assert.equal(sweepDeadlineExceeded(start, start + 301 * 60_000, 300), true); + // Zero is off, not "expire immediately" โ€” which is what a plain `now > start + 0` would do. + assert.equal(sweepDeadlineExceeded(start, start + 10 * 60 * 60_000, 0), false); +}); + +test("durations read at a glance across the three scales", () => { + assert.deepEqual( + [0, 93, 432, 8040].map(formatDuration), + ["0s", "1m33s", "7m12s", "2h14m"], + ); +}); diff --git a/.github/release-script/src/publish-plan.ts b/.github/release-script/src/publish-plan.ts index 0071ff03a5..51efddbbe8 100644 --- a/.github/release-script/src/publish-plan.ts +++ b/.github/release-script/src/publish-plan.ts @@ -370,3 +370,28 @@ export function classifyGap( if (plannedAt === undefined) return "not-in-release"; return plannedAt > publishedAtGroup ? "ordering-defect" : "lag"; } + + +/** + * A sweep that no longer fits in its job, named by the publisher rather than by the runner. + * + * `timeout-minutes` is the only other bound, and a job killed by it says "The job running on + * runner โ€ฆ has exceeded the maximum execution time" โ€” which names the runner, not the package + * the sweep was on. Keep the budget UNDER the job's own, so this is the message a human reads. + * + * Zero disables it. Measured for scale: v4.9.0 published 716 packages at 10.7 s each over 2.14 h, + * v5.0.0 at 19.2 s over 2.7 h. + */ +export function sweepDeadlineExceeded(startedAt: number, now: number, budgetMin: number): boolean { + if (budgetMin <= 0) return false; + return now - startedAt > budgetMin * 60_000; +} + +/** `93s` ยท `7m12s` ยท `2h14m` โ€” a duration a human reads at a glance in a 700-line log. */ +export function formatDuration(seconds: number): string { + const s = Math.max(0, Math.round(seconds)); + if (s < 60) return `${s}s`; + const m = Math.floor(s / 60); + if (m < 60) return `${m}m${String(s % 60).padStart(2, "0")}s`; + return `${Math.floor(m / 60)}h${String(m % 60).padStart(2, "0")}m`; +}