Skip to content

Commit 60c0f61

Browse files
os-warrenclaude
andauthored
fix(service-automation): re-seat the suspension map entry when the durable save fails (#16216)
* fix(service-automation): re-seat the suspension map entry when the durable save fails A concurrent per-id `loadSuspendedRunStrict` landing inside `persistSuspendedRun`'s save window evicts the live map entry (#16129's base window, which stays as pinned). Compounded with the save then FAILING, the run was left with neither a durable row nor a map entry: `hasSuspendedRun` answered `false` and `resume` answered `RUN_NOT_FOUND` — the run lost in-process, not merely un-durable — while the engine's own `error` record told the operator it was "kept in memory only" and that they had until the next restart to act. The catch now re-seats the map entry alongside the cache-only marking, so the marking qualifies something again. Option C of the card: the cache-only marking is not widened (that would weaken #13617's store authority), no lock is added, the save is not reordered, and the base window is untouched. The operator record is corrected in the same seam: it keeps its promise, and now names the two reads (`hasSuspendedRun()`, `listSuspendedRuns()`) that must answer for the run, so the promise can be falsified instead of trusted. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y * chore(changeset): the failed-save re-seat and the corrected operator record Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y * docs(service-automation): retire the stale "escapes those bounds" claim on evictConsumedSuspension The compound case that paragraph pointed at is closed by the re-seat in `persistSuspendedRun`'s catch, and the pin file now records the intended outcome rather than the measured loss. Comment-only. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent d770b3e commit 60c0f61

3 files changed

Lines changed: 164 additions & 41 deletions

File tree

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
1+
---
2+
"@objectstack/service-automation": patch
3+
---
4+
5+
A suspended run whose durable save fails is now kept resumable in this process even when a concurrent read landed mid-park — and the error record that reports the failure says how to check that.
6+
7+
`AutomationEngine.persistSuspendedRun` writes its map entry BEFORE it awaits `store.save()`, and marks the run cache-only only once that save settles. For the whole of that await the entry is live but unqualified, so a concurrent per-id `hasSuspendedRun` / `resume` reads a store that truthfully has no row yet, finds no qualifier, and evicts a run that is being parked right now. That window is bounded and stays as it was: the strict load is store-first, so once the save lands the run is resumable from the store, and only the cache-only listing under-reports.
8+
9+
Compounded with the save then **failing**, it was not bounded. The catch marked the run cache-only, but the map entry that marking qualifies had already been evicted, so the run had neither a durable row nor an in-memory copy: `hasSuspendedRun` answered `false` and `resume` answered `RUN_NOT_FOUND`. The run was lost **in this process**, not merely un-durable — for example a paused approval that no decision can ever advance. Reaching it needs a store that rejects the write while still answering reads with "no row" rather than throwing: a healthy read replica behind a broken write path, a missing `INSERT` grant, a full disk.
10+
11+
- **The failure path now re-seats the map entry** alongside the cache-only marking, so the marking qualifies something again and the documented degradation — a failed save costs cross-restart durability, not in-process resumability — holds in this interleaving too. The cache-only marking is not widened, no lock is added, and the save is not reordered, so a run is still never readable out of the map while the store is authoritative for it.
12+
- **The error record for a failed save is corrected.** It kept telling the operator the run was "kept in memory only" and that they had until the next restart to act, which in this interleaving pointed away from the loss: the run was already gone, and the restart would take the blame. It now names the two reads that must still answer for the run (`hasSuspendedRun()` and `listSuspendedRuns()`), so the promise can be checked rather than trusted. It still reports the same cause in the same structured slot, at the same `error` level.

packages/services/service-automation/src/engine.ts

Lines changed: 48 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -2049,7 +2049,14 @@ export class AutomationEngine implements IAutomationService {
20492049
// falls entirely on `listSuspendedRuns`, which merely OMITS the run --
20502050
// inside that listing's declared latitude. Do not widen the marking, add
20512051
// a lock, or move the save above this line without reading that pin's
2052-
// header: it also records the ONE compound case that escapes the bounds.
2052+
// header.
2053+
//
2054+
// [#16151] The ONE compound case that ESCAPED those bounds — an evicting
2055+
// read inside the window, and then the save FAILING, leaving the run
2056+
// with neither a durable row nor a map entry — is closed in the catch
2057+
// below, which re-seats this entry. The base window itself is
2058+
// deliberately unchanged: while the save is still in flight a per-id
2059+
// read still evicts, and bound 1 still carries it.
20532060
this.suspendedRuns.set(run.runId, run);
20542061
if (this.store) {
20552062
try {
@@ -2065,6 +2072,34 @@ export class AutomationEngine implements IAutomationService {
20652072
// what lets `loadSuspendedRunStrict` keep serving it from the
20662073
// map — the in-process resumability the message below promises.
20672074
this.cacheOnlySuspensions.add(run.runId);
2075+
// [#16151] RE-SEAT THE MAP ENTRY — the marking above qualifies
2076+
// an entry that may no longer be there. The map write at the
2077+
// top of this method is NOT yet qualified for the whole
2078+
// duration of the await, so a concurrent per-id
2079+
// `loadSuspendedRunStrict` reads a store that truthfully has no
2080+
// row, finds no qualifier, and evicts a run being parked right
2081+
// now. Compound that with THIS save failing and the run was
2082+
// left with neither a durable row nor a map entry:
2083+
// `hasSuspendedRun` answered `false` and `resume` answered
2084+
// `RUN_NOT_FOUND` — the run lost IN-PROCESS, while the record
2085+
// below told the operator it was "kept in memory only" and that
2086+
// they had until the next restart to act.
2087+
//
2088+
// Re-seating restores exactly this method's own write, on the
2089+
// one path where the store refused the row. It cannot resurrect
2090+
// a CONSUMED suspension: consumption goes through
2091+
// `forgetSuspendedRun`, which is reachable only once
2092+
// `loadSuspendedRunStrict` answers for this run, and for the
2093+
// whole of this await it answers `null` for the reason above.
2094+
// Nor can it clobber a NEWER entry: `persistSuspendedRun` is the
2095+
// only writer of this map, and a second park of the same run
2096+
// needs a resume that the same `null` refuses.
2097+
//
2098+
// ⛔ NOT a widening of the cache-only marking, which #16129
2099+
// forbids taking unilaterally because it would weaken #13617's
2100+
// store authority: the marking still happens only after the
2101+
// save has settled, and only when it settled as a FAILURE.
2102+
this.suspendedRuns.set(run.runId, run);
20682103
// #6499 — the cause is the datasource DRIVER's own text, so it
20692104
// goes to the logger's STRUCTURED slot, never spliced into the
20702105
// message; see `forgetSuspendedRun`'s catch below for the full
@@ -2078,8 +2113,10 @@ export class AutomationEngine implements IAutomationService {
20782113
// stays empty on purpose (#5575).
20792114
this.logger.error(
20802115
`[automation] failed to persist suspended run '${run.runId}' to the durable store — it is ` +
2081-
`kept in memory only and will NOT be resumable after a restart. Fix the store failure ` +
2082-
`in this record's meta.`,
2116+
`kept in memory only: this process keeps it resumable, and hasSuspendedRun() and ` +
2117+
`listSuspendedRuns() both still answer for it — if they do not, this run is already ` +
2118+
`gone and that is a defect in this engine, not in the store. It will NOT be resumable ` +
2119+
`after a restart. Fix the store failure in this record's meta.`,
20832120
undefined,
20842121
describeThrownForLog(err),
20852122
);
@@ -2242,8 +2279,14 @@ export class AutomationEngine implements IAutomationService {
22422279
* cache-only qualifier is not yet set. Evicting it is bounded -- the run
22432280
* stays resumable through the store-first strict load and only the
22442281
* cache-only listing under-reports -- and
2245-
* `suspended-run-mid-park-eviction-window.test.ts` pins both the window and
2246-
* the one compound case that escapes those bounds.
2282+
* `suspended-run-mid-park-eviction-window.test.ts` pins that window.
2283+
*
2284+
* [#16151] The one COMPOUND case that escaped those bounds -- an eviction
2285+
* here, and then that same save FAILING, leaving the run with neither a
2286+
* durable row nor a map entry -- no longer does: `persistSuspendedRun`'s
2287+
* catch re-seats the entry alongside the cache-only marking, so guard 2
2288+
* above has something to guard again. The same pin file carries it, now at
2289+
* the intended outcome rather than at the measured loss.
22472290
*
22482291
* A store read that THROWS must never reach here: an outage means the
22492292
* run's existence is UNKNOWN, not "gone". Every caller below is on a path

packages/services/service-automation/src/suspended-run-mid-park-eviction-window.test.ts

Lines changed: 104 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -59,22 +59,33 @@
5959
* a future change that alters the trade — in either direction — has to come
6060
* through here and say so.
6161
*
62-
* ## One measured case that does NOT stay inside those bounds
62+
* ## The one case that escaped those bounds — FIXED in #16151
6363
*
64-
* `FINDING` below. Bound 1 holds only because the save eventually LANDS. Let the
65-
* save FAIL after an evicting read has already run, and the compound outcome is
66-
* a run with no durable row and no map entry: unresumable, and the engine's own
67-
* `error` record for the failed save promises the opposite ("it is kept in
68-
* memory only"). It is narrower than the base window — it needs a store that
69-
* rejects the write while still answering reads with "no row" rather than
70-
* throwing (a healthy read replica behind a broken write path, a missing INSERT
71-
* grant, a full disk) — but it is not hypothetical, and it escapes the bound.
64+
* Bound 1 holds only because the save eventually LANDS. Let the save FAIL after
65+
* an evicting read has already run, and the compound outcome was a run with no
66+
* durable row and no map entry: unresumable in its own process, while the
67+
* engine's `error` record for that failed save promised the operator the
68+
* opposite ("it is kept in memory only ... after a restart"), which is the
69+
* direction that costs the most — an operator reading it looks for the run only
70+
* after the next restart, and blames the restart. It is narrower than the base
71+
* window — it needs a store that rejects the write while still answering reads
72+
* with "no row" rather than throwing (a healthy read replica behind a broken
73+
* write path, a missing INSERT grant, a full disk) — but it is not
74+
* hypothetical.
7275
*
73-
* ⛔ It is deliberately NOT fixed here. Widening the cache-only marking is
74-
* exactly the move this card forbids taking unilaterally, and the choice
75-
* between that, a lock, and reordering the save is a decision above it. The
76-
* case is pinned at its MEASURED behaviour so the cost is visible and so any
77-
* future fix has a red test to turn green.
76+
* ⭐ #16150 pinned it at its MEASURED behaviour, explicitly not as desired, so a
77+
* fix would have a red test to turn green. #16151 turned it green: the catch in
78+
* `persistSuspendedRun` now RE-SEATS the map entry alongside the cache-only
79+
* marking, so the marking qualifies something again. The two tests below are
80+
* that pin, rewritten to the INTENDED behaviour — the run stays resumable
81+
* in-process, and the `error` record's promise is asserted against the state it
82+
* describes rather than merely read.
83+
*
84+
* ⛔ The fix is option C of that card, and nothing wider: the cache-only marking
85+
* is NOT widened (it still happens only after the save settles, and only on
86+
* failure — widening it would weaken #13617's store authority and is reserved
87+
* to its own review), no lock is added, and the save is not reordered. The base
88+
* window above is untouched and its two tests are unchanged.
7889
*/
7990

8091
import { describe, it, expect } from 'vitest';
@@ -88,6 +99,17 @@ function silentLogger(): any {
8899
return { info() {}, warn() {}, error() {}, debug() {}, child() { return silentLogger(); } };
89100
}
90101

102+
/** A logger that keeps every `error` message, so a promise the engine MAKES can
103+
* be asserted against the state it describes. */
104+
function recordingLogger(errors: string[]): any {
105+
const log: any = {
106+
info() {}, warn() {}, debug() {},
107+
error(message: string) { errors.push(message); },
108+
child() { return log; },
109+
};
110+
return log;
111+
}
112+
91113
/** start -> lv1 -> lv2 -> end. Two levels, so a re-suspend has somewhere to go. */
92114
const APPROVAL_FLOW = {
93115
name: 'expense_approval',
@@ -106,8 +128,8 @@ const APPROVAL_FLOW = {
106128
],
107129
} as any;
108130

109-
function engineOver(store: SuspendedRunStore | undefined): AutomationEngine {
110-
const engine = new AutomationEngine(silentLogger(), store);
131+
function engineOver(store: SuspendedRunStore | undefined, logger: any = silentLogger()): AutomationEngine {
132+
const engine = new AutomationEngine(logger, store);
111133
engine.registerNodeExecutor({
112134
type: 'approval_level',
113135
descriptor: defineActionDescriptor({
@@ -252,43 +274,56 @@ describe('#16129 — the mid-park window between the map write and the durable s
252274
});
253275
});
254276

255-
// -- the one case that escapes the bounds, pinned at its measured behaviour ---
277+
// -- the one case that escaped the bounds, now pinned at the INTENDED outcome -
256278

257-
describe('#16129 — the window compounded with a FAILING save', () => {
258-
it('FINDING: an evicting read inside the window of a save that then fails leaves the run unresumable', async () => {
259-
// ⛔ Deliberately NOT fixed here — see this file's header. Pinned so the
260-
// cost is visible and so a future fix has a red test to turn green.
279+
describe('#16151 — the window compounded with a FAILING save', () => {
280+
it('an evicting read inside the window of a save that then FAILS leaves the run resumable in-process', async () => {
281+
// ⭐ This assertion set is #16150's `FINDING` pin, flipped. It recorded the
282+
// MEASURED loss (`hasSuspendedRun` false, `resume` → `RUN_NOT_FOUND`) and
283+
// said in its own header that it was pinned as measured and NOT as desired.
284+
// What follows is the desired behaviour, and it is what the engine's own
285+
// `error` record for a failed save has always promised.
261286
const inner = new InMemorySuspendedRunStore();
262287
const { store, entered, release } = gatedSaveStore(inner, { failSave: true });
263288
const engine = engineOver(store);
264289

265290
const parking = engine.execute('expense_approval');
266291
const runId = (await entered).runId;
267292

268-
// Same window, same evicting read.
293+
// The BASE window is unchanged by the fix — mid-park, the entry is still
294+
// unqualified, and the per-id read still evicts it. That half stays as
295+
// #16129 pinned it; only the compound outcome below moves.
269296
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual(['lv1']);
270297
expect(await engine.hasSuspendedRun(runId)).toBe(false);
271298
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual([]);
272299

273-
// The save now fails. `persistSuspendedRun` marks the run cache-only — but
274-
// the map entry it qualifies is already gone, so the qualifier qualifies
275-
// nothing and the strict loader has nothing left to serve.
300+
// The save now fails. `persistSuspendedRun` marks the run cache-only AND
301+
// re-seats the map entry that read evicted, so the marking qualifies
302+
// something again instead of qualifying nothing.
276303
release();
277304
expect((await parking).runId).toBe(runId);
278305

279-
// ESCAPES BOUND 1. The store never took the row and the cache no longer
280-
// holds it, so the run is unresumable — while the engine's `error` record
281-
// for the failed save says it "is kept in memory only".
306+
// The fix invents no durability: the store still never took the row, and
307+
// the cross-restart loss the record reports is real.
282308
expect(await inner.load(runId)).toBeNull();
283-
expect(await engine.hasSuspendedRun(runId)).toBe(false);
284-
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual([]);
285-
const resumed = await approve(engine, runId);
286-
expect(resumed.success).toBe(false);
287-
expect(resumed.code).toBe('RUN_NOT_FOUND');
288309

289-
// The control that isolates the window as the cause: WITHOUT the mid-park
290-
// read, the identical failing save is the documented degradation — the run
291-
// stays resumable in-process, which is exactly what the promise says.
310+
// BOUND 1, RESTORED. The run is resumable in THIS process — the documented
311+
// degradation (a failed save costs cross-restart durability, not in-process
312+
// resumability) now holds in the compound case too.
313+
expect(await engine.hasSuspendedRun(runId)).toBe(true);
314+
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual(['lv1']);
315+
expect(await engine.getSuspendedScreen(runId)).not.toBeUndefined();
316+
317+
// Resumable END TO END, not merely answering `true`: the run advances to
318+
// the next level (whose save fails the same way) and then completes.
319+
expect((await approve(engine, runId)).status).toBe('paused');
320+
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual(['lv2']);
321+
expect((await approve(engine, runId)).success).toBe(true);
322+
323+
// The CONTROL that isolated the mid-park read as the cause, kept as-is:
324+
// WITHOUT the read, the identical failing save is the documented
325+
// degradation. It was the half that already behaved; the two now agree,
326+
// which is the whole content of the fix.
292327
const solo = engineOver({
293328
async save() { throw new Error('sqlite: attempt to write a readonly database'); },
294329
async load() { return null; },
@@ -299,6 +334,39 @@ describe('#16129 — the window compounded with a FAILING save', () => {
299334
expect(await solo.hasSuspendedRun(soloRun)).toBe(true);
300335
expect(listedNodes(solo.listSuspendedRuns(), soloRun)).toEqual(['lv1']);
301336
});
337+
338+
it("the failed-save `error` record is TRUE in this interleaving: both reads it names answer for the run", async () => {
339+
// ⭐ The half of #16151 that is not about losing the run. The record told
340+
// the operator the run was "kept in memory only" and that they had until
341+
// the next restart to act; in this interleaving it was already gone, so the
342+
// message misdirected exactly the person who could still have acted. The
343+
// remedy is not to weaken the promise but to make it hold AND to make it
344+
// CHECKABLE: the message now names the two reads that must answer, so an
345+
// operator can falsify it instead of trusting it. This test asserts the
346+
// message against the state it describes — prose and behaviour cannot drift
347+
// apart without turning it red.
348+
const errors: string[] = [];
349+
const inner = new InMemorySuspendedRunStore();
350+
const { store, entered, release } = gatedSaveStore(inner, { failSave: true });
351+
const engine = engineOver(store, recordingLogger(errors));
352+
353+
const parking = engine.execute('expense_approval');
354+
const runId = (await entered).runId;
355+
expect(await engine.hasSuspendedRun(runId)).toBe(false); // the evicting read
356+
release();
357+
await parking;
358+
359+
const record = errors.find(m => m.includes('failed to persist suspended run'));
360+
expect(record).toBeDefined();
361+
// What it still says: in-memory survival now, no survival across a restart.
362+
expect(record).toContain('kept in memory only');
363+
expect(record).toContain('NOT be resumable after a restart');
364+
// What it now names — and each named read is asserted to actually answer.
365+
expect(record).toContain('hasSuspendedRun()');
366+
expect(await engine.hasSuspendedRun(runId)).toBe(true);
367+
expect(record).toContain('listSuspendedRuns()');
368+
expect(listedNodes(engine.listSuspendedRuns(), runId)).toEqual(['lv1']);
369+
});
302370
});
303371

304372
// -- controls: the shapes in which the window cannot bite ---------------------

0 commit comments

Comments
 (0)