From 9ed13210b9f2108341eae21df0d28af705775b4e Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 3 Sep 2026 03:46:27 +0000 Subject: [PATCH 1/2] =?UTF-8?q?wip(#14392):=20pin=20the=20up-bubble=20log?= =?UTF-8?q?=20branch=20=E2=80=94=20carried=20over=20a=20container=20restar?= =?UTF-8?q?t?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01AUF1NoViznQK32gqpK8wS8 --- .../builtin/screen-resume-signal-less.test.ts | 75 ++++++++++++++++++- .../services/service-automation/src/engine.ts | 54 +++++++++++++ 2 files changed, 128 insertions(+), 1 deletion(-) diff --git a/packages/services/service-automation/src/builtin/screen-resume-signal-less.test.ts b/packages/services/service-automation/src/builtin/screen-resume-signal-less.test.ts index 7a83f17207..18829d779c 100644 --- a/packages/services/service-automation/src/builtin/screen-resume-signal-less.test.ts +++ b/packages/services/service-automation/src/builtin/screen-resume-signal-less.test.ts @@ -30,6 +30,28 @@ import { installBuiltinNodes } from './index.js'; function silentLogger() { return { info() {}, warn() {}, error() {}, debug() {}, child() { return silentLogger(); } } as any; } + +/** + * A logger that RECORDS what it was told, level included — the engine's own + * sink for the tests that pin a log branch. `silentLogger` discards, so a + * branch can only be pinned on absence against something that keeps the calls + * (#14392). + */ +function recordingLogger(sink: Array<{ level: string; message: string }>) { + const rec = (level: string) => (message: unknown) => { sink.push({ level, message: String(message) }); }; + const self: any = { + info: rec('info'), warn: rec('warn'), error: rec('error'), debug: rec('debug'), + child() { return self; }, + }; + return self; +} + +/** + * The degraded up-bubble sentence, verbatim (#14392). Asserted by CONTENT and + * not by "some warn fired": the card is that this exact sentence described the + * healthy path. + */ +const DEGRADED_SENTENCE = 'is gone — continuing without child output'; function ctx() { return { logger: silentLogger(), getService() { return undefined; } } as any; } @@ -165,9 +187,12 @@ describe('signal-less resume of a pause that declares no contract proceeds (#136 describe("engine-built continuation stays exempt — the flag is the ONLY exemption (#13648 negative control)", () => { let engine: AutomationEngine; let captured: unknown[]; + /** #14392 — the engine's log records, so the up-bubble branch is pinnable. */ + let records: Array<{ level: string; message: string }>; beforeEach(() => { - engine = new AutomationEngine(silentLogger()); + records = []; + engine = new AutomationEngine(recordingLogger(records)); installBuiltinNodes(engine, ctx()); captured = []; // Copies the screen-collected `kind` into the child's declared output. @@ -241,6 +266,54 @@ describe("engine-built continuation stays exempt — the flag is the ONLY exempt expect(childRes.status).toBeUndefined(); expect(captured).toEqual([{ result: 'escalate' }]); expect(engine.listSuspendedRuns()).toHaveLength(0); + + // [#14392] Pinned on the BRANCH, not on the sentence. This IS the + // engine-built up-bubble: `captured` one line up is the child's output + // arriving in the parent, so the parent continued *with* it. The + // degraded line claims the opposite and must be absent — it used to + // fire here on every healthy subflow completion, because the parent's + // `subflow:` correlation is looked up with `loadSuspendedRun` and a + // COMPLETED child has no suspension to find. + expect(records.filter((r) => r.message.includes(DEGRADED_SENTENCE))).toEqual([]); + // Not silent by accident either: the healthy continuation says what it + // is, once, at `debug` — never `warn`. + const bubbled = records.filter((r) => r.message.includes('engine-built up-bubble signal')); + expect(bubbled).toHaveLength(1); + expect(bubbled[0].level).toBe('debug'); + expect(bubbled[0].message).toContain(child.runId); + }); + + it('[#14392 positive control] the degraded line still fires when the child run is gone AND nothing carries its output', async () => { + const started = await engine.execute('parent', {} as any); + const parentRunId = started.runId!; + const child = engine.listSuspendedRuns().find((r) => r.flowName === 'child')!; + + // Make the child GENUINELY gone without bubbling anything up: + // `cancelRun` consumes the child's continuation only, leaving this + // parent parked on a `subflow:` correlation that now dangles. + expect(await engine.cancelRun(child.runId, 'abandoned')).toBe(true); + records.length = 0; + + // A CALLER's signal this time — not the engine's — so nothing carries + // the child's output. `kind` satisfies the child's screen, which the + // parent surfaces as its own. + const res = await engine.resume(parentRunId, { variables: { kind: 'escalate' } }); + + const degraded = records.filter((r) => r.message.includes(DEGRADED_SENTENCE)); + expect(degraded).toHaveLength(1); + // The level does NOT move (#13398-class): this branch keeps `warn`. + expect(degraded[0].level).toBe('warn'); + expect(degraded[0].message).toContain(child.runId); + expect(degraded[0].message).toContain(parentRunId); + // ...and no debug up-bubble line, since there was no up-bubble. + expect(records.filter((r) => r.message.includes('engine-built up-bubble signal'))).toEqual([]); + + // Behaviour unchanged: the branch still CONTINUES the parent, which is + // the whole point of the `else` — downstream ran, with no subflow + // output to map into `subResult`. + expect(res.success).toBe(true); + expect(captured).toEqual([undefined]); + expect(await engine.hasSuspendedRun(parentRunId)).toBe(false); }); it("a signal-less resume of the CHILD is still refused — the flag exempts the engine's signal, not the run", async () => { diff --git a/packages/services/service-automation/src/engine.ts b/packages/services/service-automation/src/engine.ts index cc6fbf5a8b..9f7ef89f55 100644 --- a/packages/services/service-automation/src/engine.ts +++ b/packages/services/service-automation/src/engine.ts @@ -1011,6 +1011,31 @@ function engineBuilt(signal: ResumeSignal): ResumeSignal { return Object.assign(signal, { [ENGINE_BUILT_SIGNAL]: true }); } +/** + * Whether an incoming resume signal ALREADY carries a completed subflow + * child's output — the engine-built up-bubble, i.e. the signal + * `bubbleToParent` builds with `buildSubflowResumeSignal` when a delegated + * child finishes and continues its parent. + * + * The discriminator for the up-bubble's log branch, and deliberately NOT "is + * the child run still there". On the up-bubble the child has COMPLETED, so its + * suspension is already consumed and the `loadSuspendedRun` miss on the + * parent's `subflow:` correlation says nothing about whether the parent + * continues with the child's output — it only says the child is not SUSPENDED. + * Branching on a second run lookup would move that same confusion one call + * over; this asks the fact the message is actually about. + * + * The engine-built marker is load-bearing, not decoration: `output` is a + * caller-writable field, and on this node the caller's signal is delegated + * DOWN to the child, so shape alone would let a caller's own bag silence the + * genuine degraded warning. Only the engine can mint the symbol. + */ +function carriesSubflowChildOutput(signal: ResumeSignal): boolean { + if ((signal as Record)[ENGINE_BUILT_SIGNAL] !== true) return false; + const output = signal.output; + return typeof output === 'object' && output !== null && 'output' in output; +} + /** * Variable names the flow engine owns: `$runId`, `$flowName`, `$flowLabel`, * `$record`, `$error`, `$parentRunId`, `$parentMapNode`, `$parentOutputVariable`, @@ -5089,7 +5114,36 @@ export class AutomationEngine implements IAutomationService { // #4354 — down-delegation is the other way a child's work // lands under a parent step written at suspend time. this.creditChildRun(run.steps, run.nodeId, childRes.summary); + } else if (carriesSubflowChildOutput(signal)) { + // The engine-built UP-BUBBLE — the HEALTHY path, and the + // one this `else` used to describe as a degradation. The + // child COMPLETED and `bubbleToParent` resumed this run + // with the child's mapped output, so the miss above is the + // SUSPENSION lookup missing (a completed run has no + // suspension), not the child having disappeared, and the + // parent continues *with* the child's output — which is + // what the old sentence denied outright. + // + // `debug`, for the same reason as the lost-advance-claim + // record further down: an ordinary outcome logged at `warn` + // on every healthy subflow completion is the cry-wolf + // shape — the operator who reads "child run is gone" on + // each one stops reading the line, and the one time it + // means what it says is the time it is ignored. Nothing + // else moves: this branch continues the parent exactly as + // before, and the degraded branch below keeps its text and + // its level. + this.logger.debug( + `[automation] run '${runId}' continues from subflow node '${run.nodeId}' with the output of ` + + `completed child run '${childRunId}' — carried on the engine-built up-bubble signal ` + + `(the child's suspension is consumed, which is why it is not loadable here).`, + ); } else { + // The genuinely degraded case, and the only one the + // sentence below was ever true of: nothing suspended under + // the child id AND no carried output, so this run really + // does continue without the child's output. #4632 verdict: + // FUNCTIONAL — stays `warn`. this.logger.warn( `[automation] run '${runId}' is paused at subflow node '${run.nodeId}' but child run '${childRunId}' ` + `is gone — continuing without child output`, From af8d0e7eb7b42f6d1c6c0d79aa537cc5d9299a2e Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 3 Sep 2026 04:08:39 +0000 Subject: [PATCH 2/2] chore(changeset): patch for the subflow up-bubble logging correction Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01AUF1NoViznQK32gqpK8wS8 --- .../subflow-upbubble-degraded-warning.md | 42 +++++++++++++++++++ 1 file changed, 42 insertions(+) create mode 100644 .changeset/subflow-upbubble-degraded-warning.md diff --git a/.changeset/subflow-upbubble-degraded-warning.md b/.changeset/subflow-upbubble-degraded-warning.md new file mode 100644 index 0000000000..61fd6e5e01 --- /dev/null +++ b/.changeset/subflow-upbubble-degraded-warning.md @@ -0,0 +1,42 @@ +--- +"@objectstack/service-automation": patch +--- + +fix(automation): the healthy subflow up-bubble no longer logs the degraded "child run is gone" warning + +Every successful subflow completion logged, at `warn`: + +``` +[automation] run 'R' is paused at subflow node 'N' but child run 'C' is gone — continuing without child output +``` + +Both halves of that sentence were false on this path. The child had not gone +anywhere — it had *completed*, which is the normal outcome — and the parent was +continuing **with** the child's output, not without it: the very signal the +engine was holding when it wrote the line already carried it. + +The cause is that the branch keyed off a suspension lookup. A parent parked at a +`subflow` node correlates to its child as `subflow:CHILDID`, and on resume the +engine calls `loadSuspendedRun(CHILDID)`. That finds only **SUSPENDED** runs, so +a child that finished has no suspension to find, and the miss fell through to an +`else` written for the genuinely degraded case. The lookup answers "is the child +still parked", which on the up-bubble is a question about nothing: the child is +supposed to be finished there. + +The branch now asks the fact the message is actually about — whether the incoming +resume signal already carries the child's output, which is what the engine's own +`buildSubflowResumeSignal` mints when a completed child bubbles into its parent. +When it does, the run continues from the subflow node with a `debug` line naming +the carried output. When there is no child run **and** no carried output, the +degraded case is real and keeps its existing sentence at its existing level. + +The engine-built marker is part of the test, not decoration: `output` is a +caller-writable field and on this node a caller's signal is delegated down to the +child, so matching on shape alone would let a caller's own bag silence a genuine +degraded warning. Only the engine can mint that marker. + +No behaviour changes: both branches continue the parent exactly as before, no log +call site changes level, and the degraded sentence is untouched. This is a +logging correctness fix — an ordinary outcome had been reported as a fault on +every healthy subflow completion, which is the cry-wolf shape that trains an +operator to skip the line on the one occasion it means what it says.