Skip to content

Commit 0cf0867

Browse files
os-warrenclaude
andauthored
fix(automation): keep the stranded verdict when post-journal bookkeeping throws — a repairable strand must not report repairable: false (#15949)
* test(automation): reproduce #15555 — a throw between the journal and the stranded stamp loses the verdict Pins written against the CORRECT behaviour so that running them at HEAD is the reproduction: today resume() throws the secondary failure and reports no run-state discriminator at all, while restoreConsumedSuspension on that same run succeeds — a false negative on a repair instruction. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y * fix(automation): keep the strand verdict when post-journal bookkeeping throws Once journalConsumedSuspension has written the repair snapshot, the run IS repairable, and the status: 'stranded' stamp is the only thing that tells a consumer so. Two statements between them could throw out of the whole arm -- recordLog's run-summary line and a store whose recordTerminal throws synchronously -- and a throw there made the approvals door report repairable: false about a run restoreConsumedSuspension puts back. A false negative on a repair instruction stops an operator from fixing a run that is fixable, so the window is now guarded: the bookkeeping may fail, loudly at error with the run and its repair verb named, and the verdict still ships. The guard opens AFTER the journal, so only a run that demonstrably has a snapshot can reach the stamp; every exit above the consumption point still carries no status, and cascade-failed ancestors are untouched. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y * changeset(automation): the strand verdict survives a post-journal bookkeeping throw Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y * changeset(automation): name the pre-existing phantom this guard makes visible The changeset is what reaches release notes, and the operator-facing consequence was only in the PR body. It now says that a run that COMPLETED is journalled and reported stranded when its completed history row throws, that repairing such a run re-runs the flow, that the phantom and its double run were measurable before this change rather than created by it, and that it is filed as #15944. Text only. engine.ts is byte-identical at blob e6fa6ff, and no pin, ablation leg or source line moves. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01XpTx2tbq3pZRYAdoGt6E6Y --------- Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
1 parent cc00df2 commit 0cf0867

4 files changed

Lines changed: 478 additions & 20 deletions

File tree

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,17 @@
1+
---
2+
'@objectstack/service-automation': patch
3+
---
4+
5+
Keep a resume's `status: 'stranded'` verdict when the bookkeeping after the repair journal throws.
6+
7+
`resumeInternal`'s catch arm journals the consumed suspension — the snapshot `restoreConsumedSuspension` puts back — and only then stamps `status: 'stranded'`. Two statements sat between them and could throw out of the whole arm: `recordLog`'s terminal run-summary line, and a store whose `recordTerminal` throws synchronously (the `void write.catch(...)` beneath that call only ever sees a returned promise's rejection). `failAncestors` follows them.
8+
9+
A throw in that window left the run genuinely repairable while the verdict never shipped, and every consumer derives repairability from the verdict — `plugin-approvals` computes its operator-facing `repairable` as `status === 'stranded'` — so the approvals decision door reported `repairable: false` about a run that `restoreConsumedSuspension` answers `restored: true` for. That is a false negative on a repair instruction: it tells an operator not to attempt a repair that works.
10+
11+
The window is now guarded. The bookkeeping may still fail — and says so loudly, at `error`, naming the run, what did not land, and the verb that repairs the strand — while the verdict still ships. Measured: with a store whose terminal write throws, `resume` now returns `{ success: false, status: 'stranded' }` instead of throwing, the door reports `repairable: true`, and the repair verb succeeds on that same run.
12+
13+
The guard opens **after** the journal, so only a run that demonstrably has a snapshot can reach the stamp: a throw from the journal itself still propagates, every exit above the consumption point still carries no status at all, and cascade-failed ancestors — which journal nothing — are untouched and still correctly non-repairable.
14+
15+
⚠️ This change also makes a pre-existing fault **visible** rather than creating it. The completion path's history write sits inside the same `try` as the node-failure arm, so a run that **completed** — every node succeeded — is journalled and reported `stranded` when its `completed` history row throws, and repairing such a run **re-runs the flow**. That phantom, its repair snapshot and the double run were all measurable before this change; what changes here is only that more store failures now report the verdict instead of throwing over it, so an operator can now be told to repair a completed run. Filed as #15944, with the measurement on both trees.
16+
17+
⚠️ `repairable` remains a point-in-time fact, and this change does not make it durable: the run in the case above has no terminal history row (that write is what failed), so the repair rides on the in-memory journal and a restart loses it. The verdict reports what an operator can do now, which is exactly what was being denied.

packages/plugins/plugin-approvals/src/decision-strand-envelope.test.ts

Lines changed: 70 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -39,10 +39,35 @@
3939
* 3. `'stranded'` observed AT THE DOOR, not dropped — with its reverse
4040
* control, a resume failure the engine does NOT call stranded, which must
4141
* report `repairable: false` rather than inheriting a default.
42+
*
43+
* ## The fourth pin (#15555) — the false NEGATIVE
44+
*
45+
* PIN 3's reverse control holds that the ABSENCE of the stamp must not be read
46+
* as repairable. #15555 is the other half of the same reading: the stamp could
47+
* go missing on a run that IS repairable, because the engine journalled the
48+
* repair snapshot and then threw before stamping. The door then answered
49+
* `repairable: false` — correctly from its own point of view, and wrong about
50+
* the world — telling an operator not to attempt a repair that succeeds.
51+
* PIN 4 drives that window through this same door and asserts the fix at the
52+
* only place it matters: what the operator is told.
4253
*/
4354

4455
import { describe, it, expect, beforeEach } from 'vitest';
4556
import { AutomationEngine, InMemorySuspendedRunStore } from '@objectstack/service-automation';
57+
58+
/**
59+
* [#15555] A durable run-history store whose terminal write throws
60+
* SYNCHRONOUSLY — the statement that sits between the engine's repair journal
61+
* and its `status: 'stranded'` stamp. The engine's own `void write.catch(...)`
62+
* beneath that call only ever sees a returned promise's rejection, so a
63+
* synchronous throw escapes the whole catch arm.
64+
*/
65+
const TERMINAL_WRITE_FAILURE = 'run-history driver refused the terminal row';
66+
class SyncThrowTerminalStore extends InMemorySuspendedRunStore {
67+
override recordTerminal(): Promise<void> {
68+
throw new Error(TERMINAL_WRITE_FAILURE);
69+
}
70+
}
4671
// [#4550] The engine doubles below route their write verbs through ObjectQL's
4772
// OWN dispatch predicates rather than a hand-mirrored copy — a double looser
4873
// than the engine it stands in for is how #4434 shipped a dead REST route with
@@ -141,8 +166,8 @@ describe('#13807 — a stranded decision publishes its facts, and keeps its stat
141166
let rejectBranchThrows: string | undefined;
142167

143168
/** One live process: real engine, real approval node, real approvals service. */
144-
function boot() {
145-
const automation = new AutomationEngine(noopLogger as any, new InMemorySuspendedRunStore());
169+
function boot(store?: InMemorySuspendedRunStore) {
170+
const automation = new AutomationEngine(noopLogger as any, store ?? new InMemorySuspendedRunStore());
146171
registerApprovalNode(automation, service, noopLogger as any);
147172
automation.registerNodeExecutor({
148173
type: 'mark',
@@ -308,4 +333,47 @@ describe('#13807 — a stranded decision publishes its facts, and keeps its stat
308333
expect(lostDetails?.runId, 'and it still names the run an operator must look at')
309334
.toBe(lostReq.flow_run_id);
310335
});
336+
337+
it('PIN 4 — #15555: a strand whose own bookkeeping throws is STILL reported repairable', async () => {
338+
// The false NEGATIVE, driven end to end through the public door. The
339+
// engine consumes the pause, journals the repair snapshot, and then the
340+
// durable run-history write throws out of the arm before the
341+
// `status: 'stranded'` stamp is reached. Before the engine-side guard the
342+
// door received a raw throw carrying no run-state discriminator at all,
343+
// so `repairable = status === 'stranded'` answered FALSE — about a run the
344+
// repair verb puts back successfully, asserted below on the same run.
345+
rejectBranchThrows = 'the node blew up';
346+
const automation = boot(new SyncThrowTerminalStore());
347+
const req = await park(automation);
348+
const runId = req.flow_run_id;
349+
350+
const err = await service
351+
.decide(req.id, { decision: 'reject', actorId: 'u1' }, SYSTEM_CTX)
352+
.then(() => null, (e: Error) => e);
353+
354+
// The door still throws and the decision still stands — this card moves
355+
// neither. ⛔ The status code and the `finalized` fact are the #13807
356+
// ruling's and are untouched.
357+
const details = strandedDecisionDetails(err);
358+
expect(details?.finalized).toBe(true);
359+
expect(details?.decision).toBe('reject');
360+
expect(details?.runId).toBe(runId);
361+
// ⭐ The card: the operator must be told the repair is worth attempting.
362+
expect(details?.repairable, 'a journalled strand is repairable even when its bookkeeping failed').toBe(true);
363+
364+
// The two assertions that make the old `false` a FALSE NEGATIVE rather
365+
// than a conservative default: the run really is stranded, and the verb
366+
// the operator was told not to bother with really does put it back.
367+
expect(await automation.hasSuspendedRun(runId)).toBe(false);
368+
const restored = await automation.restoreConsumedSuspension(runId, { requestedBy: 'ops' });
369+
expect(restored.restored, 'the repair the caller was told not to attempt').toBe(true);
370+
expect(await automation.hasSuspendedRun(runId)).toBe(true);
371+
372+
// And the prose names the run's OWN failure, not the history driver's:
373+
// the secondary failure is an operator fact and belongs in the engine's
374+
// log, never in the sentence that explains why the flow stopped.
375+
expect(err?.message).toMatch(/^RESUME_FAILED/);
376+
expect(err?.message).toContain(rejectBranchThrows);
377+
expect(err?.message).not.toContain(TERMINAL_WRITE_FAILURE);
378+
});
311379
});

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

Lines changed: 89 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -5515,23 +5515,90 @@ export class AutomationEngine implements IAutomationService {
55155515
// ordering above is untouched. It is the evidence a repair
55165516
// needs, written at the only moment it still exists.
55175517
const consumed = this.journalConsumedSuspension(run, stepCountAtPause, errorMessage);
5518-
const logged = this.recordLog({
5519-
id: runId,
5520-
flowName: run.flowName,
5521-
flowVersion: run.flowVersion,
5522-
status: 'failed',
5523-
startedAt: run.startedAt,
5524-
completedAt: new Date().toISOString(),
5525-
durationMs,
5526-
trigger: buildRunTrigger(context),
5527-
steps,
5528-
error: errorMessage,
5529-
}, context, consumed.run);
5530-
// Subflow chain: a child failing terminally fails every
5531-
// ancestor awaiting it — they can never be resumed otherwise.
5532-
// The delegation path handles its own level (skipBubble).
5533-
if (!skipBubble) {
5534-
await this.failAncestors(run.context, errorMessage);
5518+
// [#15555] From the line above, "this run is repairable" is a
5519+
// FACT: a snapshot exists and `restoreConsumedSuspension` puts
5520+
// it back. Everything from here to the `status: 'stranded'`
5521+
// stamp below is BOOKKEEPING ABOUT that fact — and none of it
5522+
// may be allowed to delete the fact by throwing.
5523+
//
5524+
// It could, and the direction is the dangerous one. The stamp
5525+
// is the ONLY thing that tells a consumer the run is
5526+
// repairable (`plugin-approvals` derives its operator-facing
5527+
// `repairable` from it verbatim: `status === 'stranded'`), and
5528+
// two statements in here throw out of the whole arm. Both live
5529+
// in `recordLog`'s terminal path: the run-summary line
5530+
// (`logger.info`, on by default) and `store.recordTerminal`,
5531+
// whose SYNCHRONOUS throw escapes — the `void write.catch(...)`
5532+
// beneath that call only ever sees a returned promise's
5533+
// rejection. Then `failAncestors` awaits a walk that can throw.
5534+
// A throw anywhere in that window replaced a truthful
5535+
// `repairable: true` with `false`, which does not merely lose
5536+
// information: it tells an operator NOT to attempt a repair
5537+
// that succeeds. A false negative on a repair instruction is
5538+
// worse than silence, and it is the opposite of the direction
5539+
// everybody checks for.
5540+
//
5541+
// ⛔ This is NOT "assume repairable when the failure is
5542+
// unknown" — that would invert the honest default and promise
5543+
// a repair for a lost run. The guard opens AFTER the journal,
5544+
// so only a run that demonstrably HAS a snapshot can reach the
5545+
// stamp: a throw from `journalConsumedSuspension` itself still
5546+
// propagates, and every exit above the consumption point is
5547+
// untouched and still carries no status at all.
5548+
//
5549+
// ⛔ And the journal is NOT moved down to sit beside the stamp
5550+
// instead. `recordLog` is what carries the snapshot into the
5551+
// durable row, so journalling after it would leave a
5552+
// `recordLog` failure with NO snapshot anywhere — converting
5553+
// this false negative into a TRUE one by destroying the repair
5554+
// rather than by reporting it.
5555+
let logged: ExecutionLogEntry | undefined;
5556+
try {
5557+
logged = this.recordLog({
5558+
id: runId,
5559+
flowName: run.flowName,
5560+
flowVersion: run.flowVersion,
5561+
status: 'failed',
5562+
startedAt: run.startedAt,
5563+
completedAt: new Date().toISOString(),
5564+
durationMs,
5565+
trigger: buildRunTrigger(context),
5566+
steps,
5567+
error: errorMessage,
5568+
}, context, consumed.run);
5569+
// Subflow chain: a child failing terminally fails every
5570+
// ancestor awaiting it — they can never be resumed otherwise.
5571+
// The delegation path handles its own level (skipBubble).
5572+
if (!skipBubble) {
5573+
await this.failAncestors(run.context, errorMessage);
5574+
}
5575+
} catch (bookkeeping) {
5576+
// #4632 verdict: DURABILITY, so `error` — the caller is
5577+
// told a truthful, actionable thing (the run stranded, and
5578+
// it is repairable), which is exactly what makes the rest
5579+
// invisible from the outside: the terminal history row
5580+
// never landed and/or the ancestor cascade stopped
5581+
// part-way, nothing retries either, and no envelope
5582+
// carries a word about it. Consequence and fix in the
5583+
// first line, per AGENTS.md. Said ONCE per stranded run,
5584+
// not once per failed write.
5585+
//
5586+
// THIRD argument per `error(message, error?, meta?)`; the
5587+
// `Error` slot stays empty on purpose (#5575), and the
5588+
// thrown text goes to the structured slot rather than into
5589+
// the message (#6499).
5590+
this.logger.error(
5591+
`[Automation] run '${runId}' of flow '${run.flowName}' is STRANDED and its ` +
5592+
`post-strand bookkeeping threw, so its terminal history row never landed ` +
5593+
`and/or its subflow ancestors were not failed — nothing retries either, and ` +
5594+
`the run reads healthy to the Runs surfaces and the approvals sweeps. The ` +
5595+
`strand itself IS reported and repairable right now: restore it with ` +
5596+
`restoreConsumedSuspension('${runId}') before this process restarts, which ` +
5597+
`drops the in-memory journal this repair rides on. Fix the failure in this ` +
5598+
`record's meta.`,
5599+
undefined,
5600+
describeThrownForLog(bookkeeping),
5601+
);
55355602
}
55365603
// Surface the flow's friendly error message (the raw error stays
55375604
// in `error` for logs/diagnostics).
@@ -5569,7 +5636,11 @@ export class AutomationEngine implements IAutomationService {
55695636
// worse) condition, which this stamp must not claim.
55705637
status: 'stranded',
55715638
errorMessage: flow.errorMessage,
5572-
summary: logged.summary,
5639+
// [#15555] Recomputed when the guard above had to abandon
5640+
// `recordLog`: the same pure function of the same steps
5641+
// that `recordLog`'s own first statement runs, so the two
5642+
// spellings cannot disagree.
5643+
summary: logged?.summary ?? summarizeRun(steps),
55735644
};
55745645
}
55755646
} finally {

0 commit comments

Comments
 (0)