diff --git a/src/orchestrator/factory.test.ts b/src/orchestrator/factory.test.ts index 884a069e..cfbf7337 100644 --- a/src/orchestrator/factory.test.ts +++ b/src/orchestrator/factory.test.ts @@ -31583,3 +31583,296 @@ describe('changeEventPath (resource-less event tolerance)', () => { expect(changeEventPath({ resource: { path: 123 } } as unknown as ChangeEvent)).toBeUndefined() }) }) + +/** + * The release retry loop (#379). + * + * Production on 0.1.76 logged the same three `no pid available to terminate + * ... during completion` lines over and over inside one evidence payload. The + * missing PID is a co-symptom, not the cause: `#terminationRoots` returning + * `unresolved` only logs, and never reaches `failed[]`. What repeated was the + * whole completion release, once a second, indefinitely, because + * `#finishDurableRelease` returns `false` on a failed release and re-arms + * itself at `DISPATCH_LIFECYCLE_RETRY_MS` — through the RESOLVED path, which + * is why no `.catch()` in either scheduler ever bounded it. + * + * Each pass costs a `#terminationRoots` process scan per agent in the release + * and another per agent in `#writeInFlightRegistry`, plus a durable read and + * write. That is the same serialized-store spin #303 already measured once, at + * 1477 state GETs in 111 s. + */ +class CompletionReleaseFailingFleetClient extends FakeFleetClient { + readonly releaseAttempts: Array<{ name: string; reason?: string }> = [] + failReleases = true + /** + * Fail exactly this many completion releases and then succeed. Set instead of + * flipping `failReleases` from the test body, so the transient case does not + * race the retry cadence it is running under. + */ + remainingFailures?: number + + override async release(name: string, reason?: string): Promise { + this.releaseAttempts.push({ name, reason }) + if (reason === 'issue-done') { + if (this.remainingFailures !== undefined) { + if (this.remainingFailures > 0) { + this.remainingFailures -= 1 + throw new Error(`control plane unavailable for ${name}`) + } + } else if (this.failReleases) { + throw new Error(`control plane unavailable for ${name}`) + } + } + await super.release(name, reason) + } + + /** Reproduces the production shape: no PID resolves for any agent. */ + async resolveAgentPid(_name: string): Promise<{ status: 'unresolved' }> { + return { status: 'unresolved' } + } +} + +/** + * The same failure on the DURABLE lifecycle, which is what production runs. + * + * `#usesDurableDispatchLifecycle()` is `durableOwnership ?? placementLocality + * === 'remote'`, so a local-placement fake exercises `#scheduleReleaseRetry`'s + * own timer and never touches `#driveDispatchLifecycle`. The deployed Factory + * places remotely. The first version of this suite tested only the local path + * and therefore proved nothing about the loop in the report (#379 review, P1). + */ +class DurableCompletionReleaseFailingFleetClient extends RemoteLifecycleFleetClient { + readonly releaseAttempts: Array<{ name: string; reason?: string }> = [] + failReleases = true + remainingFailures?: number + + override async release(name: string, reason?: string): Promise { + this.releaseAttempts.push({ name, reason }) + if (reason === 'issue-done') { + if (this.remainingFailures !== undefined) { + if (this.remainingFailures > 0) { + this.remainingFailures -= 1 + throw new Error(`control plane unavailable for ${name}`) + } + } else if (this.failReleases) { + throw new Error(`control plane unavailable for ${name}`) + } + } + await super.release(name, reason) + } +} + +describe('completion release retry budget (#379)', () => { + const completionReleases = ( + fleet: CompletionReleaseFailingFleetClient | DurableCompletionReleaseFailingFleetClient, + ) => fleet.releaseAttempts.filter((attempt) => attempt.reason === 'issue-done') + + // The production floor is 1 s, so exhausting the budget honestly would cost + // ten real seconds per case. The cadence is a test-only port override for the + // same reason `babysitterWakeUnreachableRetryMs` is: this suite already + // carries flakes (#342, #373) and a slower file is how a fourth is bought. + // The BUDGET under test is the real one; only the delay between attempts moves. + const RETRY_MS = 5 + + it('stops re-arming a completion release that never succeeds, instead of spinning at 1 Hz forever', async () => { + const mount = new FakeMountClient({ [issuePath(70)]: issueFile(70) }) + const fleet = new CompletionReleaseFailingFleetClient() + const errors: unknown[][] = [] + const factory = createFactory(config(), { + mount, + fleet, + triage: new StaticTriage(), + dispatchLifecycleRetryMs: RETRY_MS, + logger: { warn: () => undefined, error: (...args: unknown[]) => errors.push(args) }, + }) + + await factory.runOnce() + fleet.emitAgentExit('ar-70-impl-pear', 'issue-done') + + // Against `origin/main` this never arrives: the loop re-arms for as long as + // the process lives, so the wait can only end in its own deadline. That is + // the fail-first, and it is a property of the loop rather than of any + // number chosen here. + await vi.waitFor( + () => expect(factory.status().counters.dispatchLifecycleReleaseAbandoned).toBe(1), + { timeout: 10_000, interval: 5 }, + ) + expect(errors.map(([message]) => message)).toContain( + '[factory] release retries exhausted; abandoning cleanup for this work unit', + ) + + // Time is what the unbounded loop turns into work, so the decisive + // assertion is that MORE time buys no further attempts — here, 100 further + // re-arm windows' worth. + const bounded = completionReleases(fleet).length + await new Promise((resolve) => setTimeout(resolve, RETRY_MS * 100)) + expect(completionReleases(fleet).length).toBe(bounded) + }, 20_000) + + /** + * The trivially wrong way to stop a retry loop is to stop retrying. A + * release that succeeds must still complete the work unit, and must not + * leave the dead-letter counter set. + */ + it('does not bound a completion release that succeeds', async () => { + const mount = new FakeMountClient({ [issuePath(71)]: issueFile(71) }) + const fleet = new CompletionReleaseFailingFleetClient() + fleet.failReleases = false + const factory = createFactory(config(), { + mount, + fleet, + triage: new StaticTriage(), + dispatchLifecycleRetryMs: RETRY_MS, + logger: {}, + }) + + await factory.runOnce() + fleet.emitAgentExit('ar-71-impl-pear', 'issue-done') + await vi.waitFor(() => expect(factory.status().inFlight).toEqual([]), { timeout: 10_000, interval: 5 }) + + expect(factory.status().counters.dispatchLifecycleReleaseAbandoned).toBeUndefined() + // Each agent released exactly once: no retry, and no duplicate release. + const names = completionReleases(fleet).map((attempt) => attempt.name) + expect(names.length).toBe(new Set(names).size) + expect(names).toEqual(['ar-71-impl-pear', 'ar-71-review']) + }, 30_000) + + /** + * A transient failure is what the retry exists for and must still be + * recovered from: the budget bounds CONSECUTIVE failures, not the lifetime + * of a work unit that gets there in the end. + */ + it('still completes a release that fails a few times and then succeeds', async () => { + const mount = new FakeMountClient({ [issuePath(72)]: issueFile(72) }) + const fleet = new CompletionReleaseFailingFleetClient() + const factory = createFactory(config(), { + mount, + fleet, + triage: new StaticTriage(), + dispatchLifecycleRetryMs: RETRY_MS, + logger: {}, + }) + + // Three failures, then success — well inside the ten-attempt budget. + fleet.remainingFailures = 3 + + await factory.runOnce() + fleet.emitAgentExit('ar-72-impl-pear', 'issue-done') + await vi.waitFor(() => expect(factory.status().inFlight).toEqual([]), { timeout: 10_000, interval: 5 }) + + // It genuinely retried rather than succeeding first time... + expect(completionReleases(fleet).length).toBeGreaterThan(2) + // ...and the budget never tripped. + expect(factory.status().counters.dispatchLifecycleReleaseAbandoned).toBeUndefined() + }, 20_000) + + /** + * THE PRODUCTION SHAPE, and the case the first version of this suite missed. + * + * On the durable lifecycle the retry does not go through + * `#scheduleReleaseRetry`'s own timer. It goes: + * + * #finishDurableRelease -> release fails -> returns FALSE (never throws) + * -> #scheduleReleaseRetry -> #scheduleDispatchLifecycleRetry + * -> timer -> #driveDispatchLifecycle -> phase 'releasing' + * -> #finishDurableRelease -> fails -> re-arms -> RESOLVES NORMALLY + * + * `#driveDispatchLifecycle` discards `#finishDurableRelease`'s boolean + * (factory.ts, the `phase === 'releasing'` branch), so the drive resolves on + * a failed release and the scheduler's success handler runs. Any budget + * cleared there is cleared on every pass, and the counter can never climb. + * + * This test therefore asserts on the counter surviving ACROSS re-arms, not + * merely on a dead-letter being reachable by some path. + */ + it('exhausts the budget on the durable lifecycle, where the failed release resolves instead of throwing', async () => { + const mount = new FakeMountClient({ [issuePath(73)]: issueFile(73) }) + const fleet = new DurableCompletionReleaseFailingFleetClient() + const stateStore = new InMemoryStateStore({ batchSize: 2 }) + const errors: unknown[][] = [] + const factory = createFactory(config(), { + mount, + fleet, + stateStore, + triage: new StaticTriage(), + dispatchLifecycleRetryMs: RETRY_MS, + logger: { warn: () => undefined, error: (...args: unknown[]) => errors.push(args) }, + }) + + await factory.runOnce() + fleet.emitAgentExit('ar-73-impl-pear', 'issue-done') + + await vi.waitFor( + () => expect(factory.status().counters.dispatchLifecycleReleaseAbandoned).toBe(1), + { timeout: 10_000, interval: 5 }, + ) + expect(errors.map(([message]) => message)).toContain( + '[factory] release retries exhausted; abandoning cleanup for this work unit', + ) + + // The re-arm loop is genuinely stopped, not merely counted once. + const bounded = completionReleases(fleet).length + await new Promise((resolve) => setTimeout(resolve, RETRY_MS * 100)) + expect(completionReleases(fleet).length).toBe(bounded) + }, 20_000) + + /** + * A dead-letter must not silently eat capacity. Trading a visible 1 Hz spin + * for an in-flight record nobody will ever complete is not a win: the slot is + * gone until someone restarts the process (#379 review, P1). + */ + it('releases the slot when the budget is exhausted rather than leaking the work unit', async () => { + const mount = new FakeMountClient({ [issuePath(74)]: issueFile(74) }) + const fleet = new CompletionReleaseFailingFleetClient() + const factory = createFactory(config(), { + mount, + fleet, + triage: new StaticTriage(), + dispatchLifecycleRetryMs: RETRY_MS, + logger: {}, + }) + + await factory.runOnce() + expect(factory.status().inFlight.map((issue) => issue.key)).toEqual(['AR-74']) + fleet.emitAgentExit('ar-74-impl-pear', 'issue-done') + + await vi.waitFor( + () => expect(factory.status().counters.dispatchLifecycleReleaseAbandoned).toBe(1), + { timeout: 10_000, interval: 5 }, + ) + + // The slot is what capacity is computed from. Abandoning cleanup must not + // also abandon the accounting. + await vi.waitFor(() => expect(factory.status().inFlight).toEqual([]), { timeout: 10_000, interval: 5 }) + }, 20_000) + + /** + * The narrowing that answers #379 review P1 (wrong budget charged) is + * STRUCTURAL, and this test states the structure rather than pretending to + * exercise it. + * + * The generic arm of `#driveDispatchLifecycle`'s `.catch()` re-arms for + * dispatch, publishing and recovery failures as well as releases, so it must + * not charge. Charging is now confined to `#scheduleReleaseRetry`. I could + * not reach that generic arm from a realistic fixture — forcing durable state + * reads to throw makes the agent-exit handler fail before any lifecycle retry + * is scheduled, so a test built that way passes whether or not the narrowing + * is present, which is worth nothing. Rather than ship that, the guarantee is + * pinned by auditing the call sites, which is what actually makes it true. + */ + it('charges the release budget from the release scheduler only', () => { + const source = readFileSync(new URL('./factory.ts', import.meta.url), 'utf8') + + // Two call sites, both inside `#scheduleReleaseRetry` — its durable branch + // and its local branch. Every caller of that method is a failed release: + // the three inside `#finishDurableRelease`, and `#completeIssue`'s catch + // once `releaseReasonForRetry` is set. + const callSites = [...source.matchAll(/!this\.#chargeReleaseAttempt\(/gu)] + expect(callSites).toHaveLength(2) + + // The generic lifecycle re-arm — dispatch, publishing, recovery — passes no + // release charge, so it cannot dead-letter a unit that never released. + expect(source).toContain('this.#scheduleDispatchLifecycleRetry(record, nextDelayMs)\n') + expect(source).not.toContain('releaseAttempt = true') + }) +}) diff --git a/src/orchestrator/factory.ts b/src/orchestrator/factory.ts index 3c2b1f34..197ba89e 100644 --- a/src/orchestrator/factory.ts +++ b/src/orchestrator/factory.ts @@ -466,6 +466,31 @@ const DISPATCH_LIFECYCLE_RETRY_MS = 1_000 * multi-hour run holds the slot honestly), so what is bounded is the *rate*. */ const DISPATCH_LIFECYCLE_RETRY_MAX_MS = 30_000 +/** + * How many times a work unit's RELEASE may fail before it is dead-lettered. + * + * #303 bounded the rate of the capacity-wait re-arm and deliberately left its + * count unbounded, because waiting for capacity is legitimate: the slot will + * free eventually and abandoning the wait would drop real work. Release is the + * opposite shape. It is the last step of a work unit that is already finished + * — the issue is closed, the writeback is acknowledged, the batch slot is + * gone — so a release that has failed ten times is not waiting for anything. + * It is failing, and re-arming it at 1 Hz forever buys nothing. + * + * What that costs when it happens: `#finishDurableRelease` does not throw on a + * failed release, it returns `false` and re-arms itself, so the loop runs + * through the *success* path of every `.catch()` that might otherwise have + * bounded it. Each pass calls `#terminationRoots` once per agent, and + * `#writeInFlightRegistry` calls it once per agent again — each one a process + * table scan — plus a durable read and write. Three agents is order ten scans + * and several state operations per second, indefinitely, which is the same + * serialized-store spin #303 measured at 1477 GETs in 111 s. + * + * Ten attempts at the 1 Hz floor is ~10 s of genuine retry, which covers the + * transient failures release retries exist for (a brief control-plane blip, a + * lease handover) without covering a permanent one. + */ +const DISPATCH_LIFECYCLE_MAX_RELEASE_ATTEMPTS = 10 /** Rate limit for the capacity-wait warning once the backoff has capped. */ const DISPATCH_LIFECYCLE_CAPACITY_WAIT_LOG_MS = 60_000 const DISPATCH_WRITEBACK_MAX_ATTEMPTS = 3 @@ -751,6 +776,7 @@ export class FactoryLoop implements Factory { readonly #babysitterWakeUnreachableEscalateMs: number readonly #babysitterWakeUnreachableRetryMs: number readonly #startupAgentExitDrainTimeoutMs: number + readonly #dispatchLifecycleRetryMs: number readonly #state: StateStore readonly #workspaceId: string readonly #relayflows?: FactoryPorts['relayflows'] @@ -827,6 +853,16 @@ export class FactoryLoop implements Factory { readonly #dispatchTerminalWaiters = new Map>() readonly #dispatchLifecycleRetryTimers = new Map>() readonly #dispatchLifecycleDrives = new Set>() + /** + * Failed release attempts per work unit, and the units that ran out. + * + * Keyed by `dispatchLifecycleKey`, so it follows the work unit rather than + * any one agent, surface or dispatcher — the same identity rule the AR-448 + * duplicate established for claims. Counted only for release re-arms; a + * capacity or ownership wait is not a failure and must not spend the budget. + */ + readonly #dispatchLifecycleReleaseAttempts = new Map() + readonly #dispatchLifecycleReleaseAbandoned = new Set() readonly #abandonedDispatchReasons = new Map() /** * Live batch-capacity waits, keyed by issue (#303). @@ -1224,6 +1260,7 @@ export class FactoryLoop implements Factory { this.#babysitterWakeUnreachableEscalateMs = ports.babysitterWakeUnreachableEscalateMs ?? BABYSITTER_WAKE_UNREACHABLE_ESCALATE_MS this.#babysitterWakeUnreachableRetryMs = ports.babysitterWakeUnreachableRetryMs ?? BABYSITTER_WAKE_UNREACHABLE_RETRY_MS this.#startupAgentExitDrainTimeoutMs = ports.startupAgentExitDrainTimeoutMs ?? STARTUP_AGENT_EXIT_DRAIN_TIMEOUT_MS + this.#dispatchLifecycleRetryMs = ports.dispatchLifecycleRetryMs ?? DISPATCH_LIFECYCLE_RETRY_MS this.#workspaceId = config.workspaceId ?? 'default' this.#relayflows = ports.relayflows this.#worktrees = ports.worktrees @@ -6251,8 +6288,23 @@ export class FactoryLoop implements Factory { consecutiveFailures, failureThreshold: READINESS_RECONCILE_FAILURE_THRESHOLD, intervalMs: this.#readinessReconcileIntervalMs, + // The two bounds that can actually preempt this pass, published beside + // the cadence that cannot. Omitting them made the stanza unreadable in + // the one situation it exists for: `intervalMs` next to a climbing + // `inFlightMs` looks exactly like an unbounded hang, and has twice been + // reported as one. `timeoutMs` ends the wait, `sweepBudgetMs` unwinds + // the sweep and hands the lease back — so the second is the one that + // answers "when does this recover". + timeoutMs: this.#readinessReconcileTimeoutMs, + sweepBudgetMs: this.#discoverySweepBudgetMs, ...(Number.isFinite(inFlightSinceMs) ? { inFlightSinceMs } : {}), ...(inFlightMs !== undefined ? { inFlightMs } : {}), + // Derived here rather than left to each reader. The public projection + // already computed it (#295/#300); the heartbeat stanza did not, so the + // surface an operator actually opens first was the one missing it. + ...(inFlightMs !== undefined && this.#readinessReconcileIntervalMs > 0 + ? { missedPasses: Math.floor(inFlightMs / this.#readinessReconcileIntervalMs) } + : {}), ...(this.#readinessReconcileLastDurationMs !== undefined ? { lastDurationMs: this.#readinessReconcileLastDurationMs } : {}), @@ -7647,18 +7699,115 @@ export class FactoryLoop implements Factory { this.#increment('dispatchCapacityBackoffResets') } - #scheduleDispatchLifecycleRetry(record: InFlightIssue, delayMs = DISPATCH_LIFECYCLE_RETRY_MS): void { + /** + * Charge one failed release against a work unit's budget. + * + * Returns `false` once the budget is spent, and the caller must NOT re-arm. + * Failing closed here is deliberate and is the opposite of a dispatch gate: + * an unrecordable dispatch claim must abort the dispatch, but an unbounded + * release must abort the RETRY — the work is already done either way, and + * the only thing still running is the spin. + */ + #chargeReleaseAttempt(record: InFlightIssue, key: string, context: string): boolean { + if (this.#dispatchLifecycleReleaseAbandoned.has(key)) return false + const attempts = (this.#dispatchLifecycleReleaseAttempts.get(key) ?? 0) + 1 + this.#dispatchLifecycleReleaseAttempts.set(key, attempts) + if (attempts <= DISPATCH_LIFECYCLE_MAX_RELEASE_ATTEMPTS) return true + this.#dispatchLifecycleReleaseAbandoned.add(key) + this.#dispatchLifecycleReleaseAttempts.delete(key) + this.#increment('dispatchLifecycleReleaseAbandoned') + const durableLifecycleRetained = this.#usesDurableDispatchLifecycle() + // `error`, not `warn`. Every previous layer of this failure was invisible + // until somebody read stderr by hand; a work unit whose cleanup this + // process has permanently given up on is exactly the event that must not + // be inferable only from the absence of further log lines. + this.#logger.error?.('[factory] release retries exhausted; abandoning cleanup for this work unit', { + issue: record.issue.key, + attempts: attempts - 1, + maxAttempts: DISPATCH_LIFECYCLE_MAX_RELEASE_ATTEMPTS, + context, + // The durable lifecycle is retained on purpose: a takeover or a restart + // re-drives it from the persisted phase. This bounds THIS process's + // spin, it does not declare the work unit clean. + durableLifecycleRetained, + }) + const drive = this.#releaseDeadLetteredSlot(record, key) + .catch((error) => { + this.#logger.warn?.('[factory] dead-lettered release could not free its batch slot', { + issue: record.issue.key, + error: describeError(error).errorMessage, + }) + }) + .finally(() => this.#dispatchLifecycleDrives.delete(drive)) + this.#dispatchLifecycleDrives.add(drive) + return false + } + + /** + * Hand back the batch slot of a work unit whose release was dead-lettered. + * + * Without this the bound trades an unbounded 1 Hz spin for a permanently + * leaked slot, which is not obviously the better failure (#379 review, P1): + * a spin is loud and self-describing, whereas an in-flight record nobody will + * ever complete silently reduces dispatch capacity until the process is + * restarted. The slot is process-local accounting and is always freed here. + * + * What is NOT declared clean is the work itself. On a durable lifecycle the + * persisted `releasing` phase is deliberately left in place, so a successor + * or a restart re-drives the same cleanup with a fresh budget; freeing the + * local slot does not write a terminal phase. On a local lifecycle there is + * no durable record to retain, so the batch record is all there is and + * completing it is what keeps capacity honest. + */ + async #releaseDeadLetteredSlot(record: InFlightIssue, key: string): Promise { + const batch = await this.#batch() + const next = batch.complete(record.issue) + this.#uncompensatedDispatchClaims.delete(key) + await this.#writeInFlightRegistry() + // A freed slot that nothing is admitted into is only half the repair. + if (next && !this.#stopping) await this.dispatch(next.decision, { dryRun: next.dryRun }) + } + + /** Clears a work unit's release budget once cleanup actually succeeds. */ + #clearReleaseAttempts(key: string): void { + this.#dispatchLifecycleReleaseAttempts.delete(key) + this.#dispatchLifecycleReleaseAbandoned.delete(key) + } + + #scheduleDispatchLifecycleRetry( + record: InFlightIssue, + delayMs = this.#dispatchLifecycleRetryMs, + opts: { releaseAttempt?: boolean } = {}, + ): void { const key = dispatchLifecycleKey(record.issue) if (this.#stopping || this.#dispatchLifecycleRetryTimers.has(key)) return + // Only a release re-arm spends the budget. A capacity or ownership wait is + // a legitimate wait for someone else to finish (#303) and is bounded by + // its rate, not its count — spending the budget on one would abandon work + // that was never failing. + if (opts.releaseAttempt === true && !this.#chargeReleaseAttempt(record, key, 'durable-lifecycle')) return const timer = setTimeout(() => { this.#dispatchLifecycleRetryTimers.delete(key) const drive = this.#driveDispatchLifecycle(key) .then(() => { this.#dispatchLifecycleCapacityWaits.delete(key) this.#dispatchLifecycleOwnershipWaitLogged.delete(key) + // DELIBERATELY NOT `#clearReleaseAttempts` (#379 review, P1). + // + // A FAILED release reaches here. `#finishDurableRelease` returns + // `false` rather than throwing, and `#driveDispatchLifecycle` + // discards that boolean in its `phase === 'releasing'` branch, so + // the drive RESOLVES on a failed release and this handler runs on + // every re-arm. Clearing the budget here zeroed it once per pass and + // the counter could never reach the cap — the same never-fires this + // bound exists to avoid, moved from the `.catch()` to the `.then()`. + // + // The budget is refunded where success is actually known: + // `#finishDurableRelease` clears it on real per-agent progress and + // again when the work unit completes. }) .catch((error) => { - let nextDelayMs = DISPATCH_LIFECYCLE_RETRY_MS + let nextDelayMs = this.#dispatchLifecycleRetryMs if (error instanceof DispatchLifecycleCapacityError) { this.#dispatchLifecycleOwnershipWaitLogged.delete(key) nextDelayMs = this.#recordDispatchCapacityWait(record, key) @@ -7672,7 +7821,7 @@ export class FactoryLoop implements Factory { leaseRemainingMs: error.leaseUntilMs === undefined ? undefined : Math.max(0, error.leaseUntilMs - this.#clock.now()), - retryMs: DISPATCH_LIFECYCLE_RETRY_MS, + retryMs: this.#dispatchLifecycleRetryMs, }) } } else { @@ -7683,6 +7832,20 @@ export class FactoryLoop implements Factory { error: describeError(error).errorMessage, }) } + // Deliberately UNCHARGED (#379 review, P1). This arm re-arms for + // dispatch, publishing and recovery failures as well as releases, and + // charging all of them would dead-letter a work unit that was never + // stuck in a release loop. Charging is confined to + // `#scheduleReleaseRetry`, whose every caller is a release failure: + // the three inside `#finishDurableRelease` and `#completeIssue`'s + // catch once `releaseReasonForRetry` is set. + // + // The gap this leaves, stated plainly: a release failure that THREW + // out of `#finishDurableRelease` instead of returning `false` would + // reach here and re-arm unbounded. Every failure path in that method + // returns `false` and schedules its own retry, so this is not a + // reachable shape today — and if one appears it degrades to the + // pre-existing unbounded behaviour rather than to a wrong dead-letter. this.#scheduleDispatchLifecycleRetry(record, nextDelayMs) }) .finally(() => this.#dispatchLifecycleDrives.delete(drive)) @@ -7693,11 +7856,17 @@ export class FactoryLoop implements Factory { #scheduleReleaseRetry(record: InFlightIssue, reason: string): void { if (this.#usesDurableDispatchLifecycle()) { - this.#scheduleDispatchLifecycleRetry(record) + this.#scheduleDispatchLifecycleRetry(record, this.#dispatchLifecycleRetryMs, { releaseAttempt: true }) return } const key = dispatchLifecycleKey(record.issue) if (this.#stopping || this.#dispatchLifecycleRetryTimers.has(key)) return + // Charged here rather than in the `.catch()` below, because the loop this + // bounds does not go through the `.catch()`: `#finishDurableRelease` + // returns `false` on a failed release and re-arms itself, so every re-arm + // arrives on the resolved path. A bound on the rejection handler alone + // would have been a fix that never fired. + if (!this.#chargeReleaseAttempt(record, key, 'local-completion')) return const timer = setTimeout(() => { this.#dispatchLifecycleRetryTimers.delete(key) const drive = this.#finishDurableRelease(record, reason) @@ -7711,7 +7880,7 @@ export class FactoryLoop implements Factory { }) .finally(() => this.#dispatchLifecycleDrives.delete(drive)) this.#dispatchLifecycleDrives.add(drive) - }, DISPATCH_LIFECYCLE_RETRY_MS) + }, this.#dispatchLifecycleRetryMs) timer.unref?.() this.#dispatchLifecycleRetryTimers.set(key, timer) } @@ -7935,6 +8104,9 @@ export class FactoryLoop implements Factory { return } if (lifecycle.phase === 'releasing') { + // The boolean is discarded here, as it always was — and that is exactly + // why the scheduler's success handler must not refund the release budget + // (#379 review, P1). A failed release resolves through this line. await this.#finishDurableRelease(record, lifecycle.releaseReason) } } @@ -8158,6 +8330,7 @@ export class FactoryLoop implements Factory { .filter((agent) => agent.releasedAtMs !== undefined) .map((agent) => agent.name) ?? this.#localReleaseCheckpoints.get(releaseKey) ?? []) const failed: string[] = [] + const releasedOnEntry = released.size for (const agent of record.agents) { if (released.has(agent[0])) continue const releaseFailed = await this.#releaseAndTerminateAgents([agent], reason, 'completion') @@ -8176,6 +8349,12 @@ export class FactoryLoop implements Factory { await this.#writeInFlightRegistry() if (failed.length > 0) { this.#increment('dispatchLifecycleReleaseRetries') + // Real progress refunds the budget, so the ten attempts bound CONSECUTIVE + // no-progress passes rather than capping a slow multi-agent release. This + // terminates because an agent released once is checkpointed and skipped + // on the next pass, so the remaining set strictly shrinks — a refund can + // only be earned a finite number of times. + if (released.size > releasedOnEntry) this.#clearReleaseAttempts(releaseKey) this.#scheduleReleaseRetry(record, reason) return false } @@ -8193,6 +8372,10 @@ export class FactoryLoop implements Factory { } const next = this.#usesDurableDispatchLifecycle() ? undefined : batch.complete(record.issue) this.#localReleaseCheckpoints.delete(releaseKey) + // Every agent is released. Nothing is left to retry, so the budget goes + // back — including the abandoned marker, so a reopened work unit that + // reuses this key starts with a full budget rather than a spent one. + this.#clearReleaseAttempts(releaseKey) if (next) await this.dispatch(next.decision, { dryRun: next.dryRun }) // Terminal lifecycle saves intentionally relinquish the owner epoch. Clear // the babysitter's durable ownership/wake/critical state while that epoch diff --git a/src/orchestrator/public-health.test.ts b/src/orchestrator/public-health.test.ts index 86cb48a8..39a9a211 100644 --- a/src/orchestrator/public-health.test.ts +++ b/src/orchestrator/public-health.test.ts @@ -741,6 +741,69 @@ describe('publicHealthFromHeartbeat (#295)', () => { // A duration is genuinely fractional; only the count is not. expect(health?.readinessReconcile?.inFlightMs).toBe(90_000) }) + + /** + * The stanza published `intervalMs` — a scheduler tick that cannot preempt + * anything — and neither of the two deadlines that can. A reader watching + * `inFlightMs` climb 1:1 with wall clock beside it had no field that could + * distinguish "bounded, but the bound is 90 minutes away" from "nothing will + * ever stop this", and the second reading has now been reported twice off + * this exact stanza. Publishing the bounds is what makes them falsifiable. + */ + it('publishes the deadlines that can preempt a sweep, not just the cadence that cannot', () => { + const health = publicHealthFromHeartbeat(heartbeat({ + readinessReconcile: { + state: 'healthy', + consecutiveFailures: 0, + failureThreshold: 3, + intervalMs: 60_000, + timeoutMs: 5_400_000, + sweepBudgetMs: 5_400_000, + lastStartedAtMs: BOOT_MS - 268_232, + inFlightSinceMs: BOOT_MS - 268_232, + }, + }), { nowMs: BOOT_MS }) + + expect(health.readinessReconcile?.timeoutMs).toBe(5_400_000) + expect(health.readinessReconcile?.sweepBudgetMs).toBe(5_400_000) + // The production reading that produced the misdiagnosis: a pass 268s old on + // a 60s cadence. `missedPasses` says how far in, the budget says how far to + // go, and the two together are what `intervalMs` alone could not say. + expect(health.readinessReconcile?.missedPasses).toBe(4) + }) + + /** + * The trivially wrong version of the change above publishes a zero for a + * daemon that recorded no bound, which reads as an instant deadline rather + * than an unknown one. Absent and zero are different facts here for the same + * reason they are for `candidates` (#355). + */ + it('omits an unset or non-positive bound instead of publishing it as zero', () => { + const health = normalizePublicHealth({ + schemaVersion: 1, + ok: true, + status: 'ok', + stale: false, + loopStatus: 'running', + degradedSubsystems: [], + readinessReconcile: { + state: 'healthy', + consecutiveFailures: 0, + failureThreshold: 3, + intervalMs: 60_000, + timeoutMs: 0, + sweepBudgetMs: -1, + }, + }) + + expect(health?.readinessReconcile?.timeoutMs).toBeUndefined() + expect(health?.readinessReconcile?.sweepBudgetMs).toBeUndefined() + // And an instance that predates the fields at all still projects cleanly. + const legacy = publicHealthFromHeartbeat(heartbeat(), { nowMs: BOOT_MS }) + expect(legacy.readinessReconcile?.timeoutMs).toBeUndefined() + expect(legacy.readinessReconcile?.sweepBudgetMs).toBeUndefined() + expect(legacy.readinessReconcile?.state).toBe('healthy') + }) }) diff --git a/src/orchestrator/public-health.ts b/src/orchestrator/public-health.ts index 6b56bcdd..79fe9707 100644 --- a/src/orchestrator/public-health.ts +++ b/src/orchestrator/public-health.ts @@ -507,6 +507,11 @@ function readinessReconcileHealth( consecutiveFailures: counter(status.consecutiveFailures), failureThreshold: counter(status.failureThreshold), ...(intervalMs !== undefined ? { intervalMs } : {}), + // Republished only when positive, for the same reason `intervalMs` is: a + // recorded `0` means "no bound configured", and echoing it as though it + // were a real deadline would read as an instant one. + ...optionalPositive('timeoutMs', status.timeoutMs), + ...optionalPositive('sweepBudgetMs', status.sweepBudgetMs), ...(finiteNumber(status.lastDurationMs) !== undefined ? { lastDurationMs: finiteNumber(status.lastDurationMs) } : {}), @@ -879,6 +884,8 @@ export function normalizePublicHealth(value: unknown): FactoryPublicHealth | und consecutiveFailures: counter(readiness.consecutiveFailures), failureThreshold: counter(readiness.failureThreshold), ...optionalPositive('intervalMs', readiness.intervalMs), + ...optionalPositive('timeoutMs', readiness.timeoutMs), + ...optionalPositive('sweepBudgetMs', readiness.sweepBudgetMs), ...optionalDuration('lastDurationMs', readiness.lastDurationMs), ...optionalTimestamp('lastStartedAtMs', readiness.lastStartedAtMs), ...optionalTimestamp('lastCompletedAtMs', readiness.lastCompletedAtMs), diff --git a/src/types.ts b/src/types.ts index b36b7e7d..cc5c60cc 100644 --- a/src/types.ts +++ b/src/types.ts @@ -62,6 +62,12 @@ export interface FactoryPorts { * active in the background. Test-only override of the built-in default. */ startupAgentExitDrainTimeoutMs?: number + /** + * Re-arm delay for the dispatch-lifecycle and completion-release retries. + * Test-only override of the built-in 1 s floor, so a suite can exercise the + * release retry budget without spending ten real seconds waiting for it. + */ + dispatchLifecycleRetryMs?: number relayflows?: FactoryRelayflowDispatchPort /** Local CLI checkout isolation. Remote fleet nodes own their own checkout lifecycle. */ worktrees?: AgentWorktreeManager @@ -233,6 +239,29 @@ export interface FactoryReadinessReconcileStatus { failureThreshold: number /** Sweep cadence — the denominator that turns `inFlightMs` into missed passes. */ intervalMs?: number + /** + * The deadline on the *caller's wait* for one sweep (#296). + * + * Published because its absence was read as its non-existence. An operator + * looking at a climbing `inFlightMs` beside `intervalMs: 60000` and nothing + * else has no way to tell "this is bounded, the bound is just far away" from + * "nothing will ever preempt this" — and the second reading has now been + * reached twice from the same stanza. `intervalMs` is a scheduler tick and + * cannot preempt anything; these two are the numbers that can. + */ + timeoutMs?: number + /** + * The aggregate budget for one sweep (#372/#374) — the bound that UNWINDS. + * + * Distinct from `timeoutMs` on purpose. `timeoutMs` ends the wait and leaves + * `runOnce()` running for later cycles to coalesce onto; this one expires + * from inside the sweep, so the lease goes back and the next cycle starts + * clean. When a reader wants to know "how long until this recovers", this is + * the field, and `missedPasses` is how far through it the current pass is. + */ + sweepBudgetMs?: number + /** `inFlightMs` expressed in sweeps that should have run and did not. */ + missedPasses?: number lastDurationMs?: number lastStartedAtMs?: number /** @@ -349,6 +378,10 @@ export interface FactoryPublicReadinessReconcileHealth { consecutiveFailures: number failureThreshold: number intervalMs?: number + /** The deadline on the caller's wait. See the same field on the status record. */ + timeoutMs?: number + /** The aggregate per-sweep budget — the bound that unwinds and frees the lease. */ + sweepBudgetMs?: number lastDurationMs?: number lastStartedAtMs?: number lastCompletedAtMs?: number