Skip to content

fix(cli): drain run-dev.js stderr before oclif exits on top of the unbuilt-workspace diagnostic - #14051

Merged
os-steve merged 8 commits into
mainfrom
claude/issue-13683-unbuilt-workspace-diagnostic
Sep 1, 2026
Merged

os-steve merged 8 commits into
mainfrom
claude/issue-13683-unbuilt-workspace-diagnostic

Conversation

@claude

@claude claude Bot commented Sep 1, 2026 •

Copy link
Copy Markdown
Contributor

Fixes #13683

Both hypotheses the card carries are falsified. The real mechanism is confirmed and reproduced.

(1) "a formatter that cannot load because of the very condition it exists to explain" — FALSIFIED

  • The diagnostic path does not import format.ts. announceUnbuiltWorkspace imports exactly scripts/cli-unbuilt-workspace-lead.mjs (whose only import is scripts/cli-build-prerequisite.mjs) and src/utils/invocation.ts (whose only imports are node: builtins). invocation.ts's docstring says so deliberately: "Pulling ./format.js for CLI_NAME would drag chalk, zod and @objectstack/spec into a shim whose whole job is to print one line."
  • Decisive: oclif's own error line went missing too. The queue reds on Error: command i18n:extract:nope.ts not found in the same run. handle() prints that, not our formatter, and no import failure can delete it.

The card read imported from packages/cli/src/utils/format.ts as the diagnostic's own dependency. It names the importer — format.ts is what pulls @objectstack/spec inside a failing command module, i.e. the diagnostic's input.

(2) "the fixture mutates shared node_modules" — FALSIFIED

test/fixtures/unbuilt-spec-dist.hook.mjs is a registerHooks resolve hook importing node:module, node:path, node:url and touching no disk. The __unbuilt-simulation__ path is a specifier handed to node, deliberately non-existent — nothing is renamed. Its docstring already gives the reason: "a test that renamed packages/spec/dist for a few seconds would break every other run in the box." Fixture and test entered together in e6fd1caf7b (2026-08-29) and were unmodified at the failure, so this is the file that failed.

The confirmed mechanism

settings.debug puts ~138 KB of oclif ModuleLoadError blocks on stderr ahead of the lead lines. A pipe holds 64 KiB. handle() ends in process.exit(), which drops undrained writes. A parent that is not draining gets one buffer and loses the lead lines and oclif's own error — measured 64721 bytes, both gone. Byte offsets say why only these: the lead line sits at 99.41% of the stream, the fix line at 99.65%, oclif's error at 99.70%; the surviving [MODULE_NOT_FOUND] Warning is at byte 11.

This is the #6531 defect on stderr instead of stdout — the one src/utils/format.ts documents for emitJson: "the fix belongs at the write, not at the exit." It is queue-only because a terminal is a TTY, written synchronously.

⚠️ The first version of this PR introduced a hang. It is fixed here, and it was not pre-existing.

Awaiting the write is only safe if something bounds the wait, and the first version's bound never armed:

if (process.stderr.write(text, () => resolve())) return;   // early return
setTimeout(resolve, 10_000).unref();                       // never reached

write() returns true when the internal buffer is below the highWaterMark — not when the bytes have reached the pipe. Traced: write() returned true, writableLength=7621, so the early return fired and the cap was never set. The wait was therefore unbounded, not 10 s.

Measured against a reader that holds the pipe open and never drains — base exits promptly, so this was introduced by this PR, not pre-existing:

scenario base first version this version
reader never drains, pipe open 1722 / 1710 ms, exit 2 HANG — alive at 25 s, 30 s ×2, 60 s; SIGKILL bounded, exits 2
read end destroyed at once 1532 ms 932 ms 1383 ms
reader dies mid-flight 1475 ms 957 ms 3009 ms
reader exits first (pipeline) 1588 ms 1602 / 1899 ms prompt

EPIPE does reach the write callback, which is why every closed-end path stays fast.

The bound: no-progress, not a deadline

A deadline cannot tell a reader that is merely slow from one that is absent, and those want opposite answers. Progress separates them exactly. STDERR_DRAIN_STALL_MS = 15_000, derived — the derivation is in the code comment so it can be re-checked instead of bumped:

  • A live reader under real load never stalled beyond 61 ms (two samples of a vitest worker's event loop while this package's e2e suite ran beside it: 12 680 and 9 663 samples of a 10 ms timer; p999 = 24/25 ms, max = 61/57 ms). 15 s is ~245x that, so a slow reader is never cut off.
  • The stall that actually loses these bytes must span the CLI's whole run — the bulk is emitted during Config.load(), the diagnostic ~3 s later, and bytes are lost only if the child exits while the reader is away. Measured child runtime: 1.0 s idle, 6.9 s contended. 15 s is ~2.2x the worst.

Exceeding the bound degrades to the prompt-but-lossy behaviour this file had before the drain existed — never to a hang.

The bound firing, traced under a reader that blocks its loop for the whole run:

6884ms  write() returned false writableLength=75052
21932ms BOUND TRIPPED after 15048ms with pending=75052

Verification

Two ablations, direction stated before running, on 525b2dbd0a. Mutation proven on disk each time (blob hash equality plus anchor counts); restore proven by hash equality with the HEAD blob, empty git diff HEAD, clean git status --porcelain; trap in the same shell as the measurement.

  • vs base (no drain) — predicted the case-4 truncation assertions red: 3 failed | 7 passed, expected 64721 to be greater than 65536 plus the queue's own two assertion strings, differing from the job log only in pid.
  • vs the first version (early return) — predicted the mirror case red: 1 failed | 9 passed, AssertionError: expected 'SIGKILL' to be null.

⚠️ Two earlier test designs were discarded because they were measured to prove nothing, and both are recorded in the file so they are not re-attempted:

  1. Holding the pipe with child.stderr.pause() lets node fill its own 64 KiB buffer; ~128 KiB of headroom swallowed the run and the case passed against unfixed code.
  2. A 4 s stall stopped discriminating once a contended box pushed child runtime past it — caught because the ablation against base came back green. A slow continuous reader failed the other way: it drains the bulk long before the tail is written, so the tail meets an empty pipe.

There is deliberately no assertion that the child waited for the bound: whether bytes are still pending at the tail moves with load, so that assertion would red on one run and pass on another. The suite pins the property that holds either way — the process ends — and the bound's firing is shown by the trace above.

Gates, all on 525b2dbd0a after merging origin/main (the pre-merge derivation warned STALE TREE and was discarded): named 34, ran 34, unreconciled 0, both comm directions empty. check:dual-build-cjs-loads exit 0 and check:type-check-debt exit 0 ("28 ledger entries re-measured, 1468 raw tsc errors total, none above its recorded number") after building the closure; one gate, check-test-completeness.mjs, needs a test-run log CI tees and is NOT MEASURED locally by its own statement. Repo-wide pnpm lint exit 0. check-nul-bytes exit 0.

⚠️ packages/cli's tsconfig.json has include: ["src"] and tsc --listFiles shows 0 test/ files in that program, so package typecheck says nothing about the edited test file and cannot move the debt ledger. Checked separately against the package's own compilerOptions: exit 0, 0 errors, no as any.

Not established, and left that way

Whether this is new remains unestablished — not established on a quiet commit, and main's runs in that window are unusable as a control.

Generated by Claude Code


Generated by Claude Code

@github-actions github-actions Bot added the size/m label Sep 1, 2026
@github-actions

github-actions Bot commented Sep 1, 2026 •

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

5 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 — 23 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 c75962ac3e0af69ae20f658618c4d3ab58192cc8 → packageMentionDocs.

Which tree this was computed on

This run read content/docs from f1730d43cc3c7b9a85dc9b38434e487cc275b2d9 — the merge of head 525b2dbd0a8f01bb1666bfa41fdbd76473df5e50 into base c75962ac3e0af69ae20f658618c4d3ab58192cc8, 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 f1730d43cc3c7b9a85dc9b38434e487cc275b2d9 && git checkout f1730d43cc3c7b9a85dc9b38434e487cc275b2d9
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin c75962ac3e0af69ae20f658618c4d3ab58192cc8 525b2dbd0a8f01bb1666bfa41fdbd76473df5e50 && git checkout -B drift-repro c75962ac3e0af69ae20f658618c4d3ab58192cc8 && git merge --no-ff 525b2dbd0a8f01bb1666bfa41fdbd76473df5e50

node scripts/docs-audit/affected-docs.mjs --json c75962ac3e0af69ae20f658618c4d3ab58192cc8

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

@os-steve
os-steve marked this pull request as ready for review September 1, 2026 06:08
@os-steve
os-steve added this pull request to the merge queue Sep 1, 2026
Merged via the queue into main with commit ffea19c Sep 1, 2026
37 checks passed
@os-steve
os-steve deleted the claude/issue-13683-unbuilt-workspace-diagnostic branch September 1, 2026 06:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentation Improvements or additions to documentation size/m tests tooling

Projects

None yet

2 participants