fix(automation): stop logging the degraded "child run is gone" warning on the healthy subflow up-bubble

[claude]

Fixes #14392

What was wrong

Every successful subflow completion logged this, at warn:

[automation] run 'R' is paused at subflow node 'N' but child run 'C' is gone — continuing without child output

Both halves are false on that path. The child had not gone anywhere — it had
completed, the normal outcome — and the parent was continuing with the
child's output, not without it: the very signal the engine held when it wrote
the line already carried it.

The mechanism (verified against origin/main, not assumed)

A parent parked at a subflow node correlates to its child as
subflow:CHILDID. On resume, resumeInternal calls
loadSuspendedRun(CHILDID) — which finds only SUSPENDED runs. A child that
finished has no suspension to find, so 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. That is
why the fix is not a second run lookup — that would move the same confusion
one call over.

The fix

Branch on the fact the message is actually about: does the incoming signal
already carry the child's output.

• carries it ⇒ the normal up-bubble — a debug line naming the carried output;
• no child run and no carried output ⇒ genuinely degraded — existing
  sentence, existing level, untouched.

The engine-built marker is load-bearing, 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 symbol, and there are
exactly two mint sites in the package (buildSubflowResumeSignal, and the map
handoff — which parks under a distinct map: correlation and never reaches this
branch).

Before / after of the log call site

The else is byte-identical to before — the entire engine diff is additive.
Every added non-comment line in engine.ts:

function carriesSubflowChildOutput(signal: ResumeSignal): boolean {
    if ((signal as Record<symbol, unknown>)[ENGINE_BUILT_SIGNAL] !== true) return false;
    const output = signal.output;
    return typeof output === 'object' && output !== null && 'output' in output;
}
                } else if (carriesSubflowChildOutput(signal)) {
                    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).`,
                    );

Removed lines in engine.ts: zero. The degraded warn, its text and its
level are untouched, and both branches fall through to exactly the same
continuation code — no early return, no state change.

The level fence, measured

Every this.logger.* call site in engine.ts, base vs head:

level	base	head
warn	40	40
error	6	6
info	15	15
debug	3	4

Diffing the call-site text with line numbers stripped yields exactly one line:
> this.logger.debug(. No existing call site changed level — the only
movement is one added debug, which is the option the ruling offers for the
healthy path.

The pin can fail — ablation

Pinned on the branch, not on the sentence. The test uses a recordingLogger
(the pre-existing silentLogger discards, so absence cannot be asserted against
it) and asserts the degraded sentence is absent on the engine-built
up-bubble, plus a positive control that it still fires when no child run and no
carried output exist.

Ablating the predicate to always return false restores the old always-log
behaviour:

run	result
baseline	Test Files 1 passed (1) · Tests 10 passed (10)
ablated	Test Files 1 failed (1) · Tests 1 failed | 9 passed (10)
restored	Test Files 1 passed (1) · Tests 10 passed (10)

The ablated failure is the original bug, reproduced verbatim:

AssertionError: expected [ { level: 'warn', …(1) } ] to deeply equal []

Mutation confirmed on disk (not by a // comment — esbuild strips those):
anchor line count 1 → 0, injected globalThis marker count 0 → 1, and blob
hash 9f7ef89f5… → 059f24835…. Restore proven by blob equality back to the
HEAD blob 9f7ef89f5…, marker count back to 0, an empty git diff HEAD and
a clean git status.

No rebuild is in the ablation loop, and that is a measured claim rather than an
assumption: the test imports ../engine.js — a same-package relative
import, which vitest resolves to src/engine.ts, never through exports to
dist/. The red/green flip is itself the proof, since a mutation the runner did
not read would have stayed green.

Verification

All at af8d0e7eb.

• Affected package, full suite: pnpm --filter @objectstack/service-automation exec vitest run --maxWorkers=2 — Test Files 101 passed (101) · Tests 1203 passed (1203)
• Typecheck: tsc --noEmit -p tsconfig.json over the package reports 3 errors, none in either edited file — all three are TS2341 in src/nested-region-parity.test.ts at 95/151/180, which is exactly the entry recorded in check-type-check-coverage.mjs (errors: 3, "code-tier 3 (TS2341 x3), all in src/nested-region-parity.test.ts at 95/151/180"). The debt number moves by zero. --listFiles confirms both edited files are genuinely in the checked set (443 files), so this is a measurement and not a vacuous pass.
• Gates: re-derived with node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack at the final commit — 36 commands, identical to the pre-changeset derivation. 33 pass. The 3 remaining exit 3 and say so themselves — check-test-completeness ("Nothing was measured… ⛔ It is NOT a finding"), check:dual-build-cjs-loads ("PREREQUISITE NOT MET… ⛔ This is NOT a pass"), check:type-check-debt ("⛔ This is NOT a pass and NOT a finding"). All three need a full-repo build, which CI performs. Exit codes captured by redirect-then-read, never across a pipe.

A patch changeset is included: this is a bug fix in a released package
(@objectstack/service-automation@17.2.0).

Scope

Log text and one branch. No new exported symbol, no payload key, no accept/reject
change, no behaviour change. Adjacent but deliberately not folded in: #14379
remains open and is not addressed here.

🤖 Generated with Claude Code

https://claude.ai/code/session_01AUF1NoViznQK32gqpK8wS8

---

Generated by Claude Code

[github-actions]

📓 Docs Drift Check

2 anchor(s) derived from 1 changed package(s); no hand-written page names any of them, so this run has nothing to list — not a clean bill of health. This check sees only pages that NAME a derived anchor: one that documents this change in prose, or enumerates it in an authoring dialect, names none and stays invisible to it on every run.

What this run could not see

• the SDK route bridge reached 47 of 219 client-bound route-ledger rows — the other 172 have no registrar path: tail to select them, so pages documenting THEIR client methods cannot appear above, on this or any run. Of those 172: 14 are remediable by widening that discovery convention (an in-repo file declares the path; the convention did not scan it); 56 are structural — on a ledger where NOT ONE row is declared in-repo, so no discovery change reaches them at any price; 102 are undecided (no in-repo declaration, on a ledger that has other in-repo registrars — absence and an unreadable spelling are not distinguishable here). The rows themselves: node scripts/docs-audit/affected-docs.mjs --bridge-coverage
• a page that states a rule by its inputs shares no identifier with the emitter that implements the rule, so an emitter-only diff cannot list it — not on this run and not on any run. Measured on fix(driver-sql): emit varchar(maxLength) for a text field a declared index keys on #11430: content/docs/protocol/objectql/types.mdx documents the text-family column mapping by the ObjectQL type names it maps FROM (text / textarea / html) while the diff changed createColumn; it went unlisted, and it was the page that diff falsified, in four places. No shared token exists to detect this on, so a rule your change carries has to be re-read by hand in the pages that restate it.

Coarse fallback — 5 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json 6665c5c916caf6d95022734328ae82154e1a5f10 → packageMentionDocs.

Which tree this was computed on

This run read content/docs from a27799b89384c7bdb78da66a9a3b2e4c6929e7d5 — the merge of head f6c6cb94abd21c949098571e4e37be9546e3b0e5 into base 6665c5c916caf6d95022734328ae82154e1a5f10, which is what actions/checkout gives a pull_request run. Not the PR head.

A worktree cut from an older main holds a different content/docs, so re-deriving there can legitimately return a different list — that is a different tree, not a wrong row. To answer on the same tree:

# while this PR is open — GitHub drops the merge commit once it closes
git fetch origin a27799b89384c7bdb78da66a9a3b2e4c6929e7d5 && git checkout a27799b89384c7bdb78da66a9a3b2e4c6929e7d5
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin 6665c5c916caf6d95022734328ae82154e1a5f10 f6c6cb94abd21c949098571e4e37be9546e3b0e5 && git checkout -B drift-repro 6665c5c916caf6d95022734328ae82154e1a5f10 && git merge --no-ff f6c6cb94abd21c949098571e4e37be9546e3b0e5

node scripts/docs-audit/affected-docs.mjs --json 6665c5c916caf6d95022734328ae82154e1a5f10

⚠️ That checkout carried uncommitted changes, so the commit above does not fully identify what was read.

[claude]

Test Core (1/6) red on af8d0e7eb — not this PR's, and the fix that was supposed to cover it was already active

domain:services seat. Standing down on this failure, with the reason measured rather than asserted.

What failed — run 33714881551:

FAIL  integration  test/run-dev-unbuilt-workspace.e2e.test.ts
  > the mirror direction: a reader that is never coming back
  > gives up and exits instead of waiting forever
AssertionError: the harness SIGKILLed the child — it was still alive at the ceiling.
  cap 180000 ms (RUN_TIMEOUT_MS); this child ran 180097 ms;
  case 1 measured the same child at 8199 ms on this runner minutes earlier
Tests  1 failed | 2734 passed (2735)

Why it is not this PR's, on three counts:

1. Different package. The failing test is packages/cli. This PR touches packages/services/service-automation only — engine.ts (+54, zero removed lines), one test file, and a changeset. There is no path from this diff to that test.
2. It is the known repo-wide signature, aggregated on Queue-flake anchor: test/run-dev-unbuilt-workspace.e2e.test.ts #14648 — 18–19 PRs across ~9–10 independent speculation stacks in 24 h.
3. The failure is a stall, not a margin. 8199 ms → 180097 ms on the same runner minutes apart, ~22×. check-test-completeness passed on the same run (2735 test(s) declared and all accounted for), so nothing was skipped or lost.

And the part worth stating plainly: the fix for it was already in force here. #14715 merged as accb9231c and the message above reports cap 180000 ms (RUN_TIMEOUT_MS) at :418 — the post-fix shape. A pull_request run builds head merged into the current base tip, which carries it. ⇒ There is nothing left to port into this PR; the existing fix is present and insufficient. I have posted the measurement to #14648, whose owning seat (domain:cli) decides the disposition.

⚠️ I first mis-read this as a stale base ("merge main in and it goes away") because the recorded merge-base 5a5336b39 still carries UNREAD_HARD_CAP_MS = 40_000. That is not the tree CI built. Correcting it here rather than acting on it: merging main would have changed nothing and I would have claimed a fix that was not one.

Action taken: one re-run of the failed job — the single re-run this PR is entitled to, spent to confirm rather than to hope. ⛔ I am not skipping, disabling or quarantining the test, and ⛔ not pushing an empty commit. If it fails again on this signature, the failure is real for queue purposes and this PR waits on #14648 rather than on anything I can do in this diff.

---

Generated by Claude Code

[claude]

CI red diagnosed as not this PR's — the fix is already on main, and the base has been brought in

This PR was PM-ACCEPTed at 04:29:36Z and then sat draft and unarmed for 17 hours. Recording why, and what I did, so the gap is not silent.

The failing check

Test Core (1/6) — completed/failure. Test Core is the aggregator and is red only because it re-reports the shard; there is one real failure, and 235 test files / 2734 tests pass alongside it.

packages/cli/test/run-dev-unbuilt-workspace.e2e.test.ts:418
[integration] the mirror direction: a reader that is never coming back
  > gives up and exits instead of waiting forever
AssertionError: the harness SIGKILLed the child — it was still alive at the ceiling.
cap 180000 ms (RUN_TIMEOUT_MS, constant and load-independent by design);
this child ran 180104 ms; case 1 measured the same child at 7887 ms on this runner minutes earlier

Why it is not this PR's

• The failure is in packages/cli. This PR changes service-automation logging on the subflow up-bubble path. The diff does not touch the failing subsystem.
• The signature is an already-adjudicated defect: os dev in an unbuilt workspace sometimes HANGS instead of exiting 2 when its reader goes away — measured at 180103 ms against a 7046 ms calibration on the same runner #14832, "os dev in an unbuilt workspace sometimes HANGS instead of exiting 2 when its reader goes away — measured at 180103 ms against a 7046 ms calibration on the same runner." This run measured 180104 ms against a 7887 ms calibration — the same defect, same shape.
• It has a standing queue-flake anchor in domain:cli: Queue-flake anchor: test/run-dev-unbuilt-workspace.e2e.test.ts #14822.

The fix exists and this PR predates it

ref	packages/cli/bin/stderr-nonblocking.mjs
origin/main	present (with test/fixtures/stderr-nonblocking-probe.mjs and test/run-dev-stderr-nonblocking.e2e.test.ts)
this PR's head af8d0e7eb	absent — 0 hits

Control for the absence read: packages/cli/bin/run-dev.js = 1 hit at the same ref, so the query resolves.

#14875 (bin/stderr-nonblocking.mjs re-asserts O_NONBLOCK on fd 2 per write, installed above run() in bin/run-dev.js) landed on main at 11:34:02Z. This PR's head was pushed at 04:43Z — about seven hours earlier. Its CI therefore ran the test in the exact window where the hang reproduces, against a base that did not yet carry the repair.

Action taken

⛔ No re-run, and ⛔ nothing skipped, disabled, or quarantined. I have updated this branch from main, which brings #14875 in and re-runs CI against a base that carries the fix. If the shard goes green, this PR is undrafted and armed; if it fails again on the updated base, the failure is this PR's and I root-cause it here.

---

Generated by Claude Code