Skip to content

Make a subprocess timeout say where the child got to - #47

Merged
its-janghoon merged 1 commit into
developfrom
feature/diagnosable-subprocess-timeout
Sep 21, 2026
Merged

its-janghoon merged 1 commit into
developfrom
feature/diagnosable-subprocess-timeout

Conversation

@its-janghoon

Copy link
Copy Markdown
Contributor

What I found, and the wrong turn I nearly took

A Windows shard fails intermittently with expected exit 0, got -1 after 30200ms. The harness's own dump showed an empty stdout and an empty stderr — which reads as a child that produced nothing at all, a hang before first output.

It was neither. Both streams were empty because the failure path discarded them, at two separate layers:

// packages/core/src/process.ts — the buffers `collect` was filling are dropped
orElse: () => Effect.fail(new AppProcessError({ command: description, cause: new Error("Timed out") }))

// packages/redrob/test/lib/cli-process.ts — and then hardcoded empty on top
stdout: Buffer.alloc(0),

So every subprocess timeout reported the same thing regardless of cause, and the one piece of evidence that separates "hung before writing a byte" from "did most of its work and stalled" was being thrown away. Raising the timeout first would have masked this and taught us nothing.

Fixed at both layers

collectStream now accepts the accumulator so a caller can own it. The fold mutates one object and hands the same one back on every chunk, so a caller holding the reference sees whatever arrived even when the fold is interrupted — which is exactly what Effect.timeoutOrElse does to it. AppProcessError gained a stdout field to carry it, and the harness passes the child's real output through.

Verified by reverting the preservation:

(fail) AppProcess > run > a timeout reports the output the child produced before it was killed

The bound drift, which was a real bug

cliIt.concurrent carried a comment saying Bun's test timeout must stay above the child timeout — while 60_000 and 30_000 sat in different functions as unrelated literals with nothing keeping them in step. Raising either alone breaks the invariant the comment promises, and the symptom (a test expiring while holding no spawn permit) looks like a slow command rather than a mis-tuned harness. All three bounds are now derived from one number.

The Windows factor is a mitigation, and says so

Windows gets 3× the base: every redrob.spawn is bun run over the TypeScript entry, so each pays a cold transpile plus that platform's process-creation cost. This is not a diagnosis — it is labelled as a mitigation at the definition, because the flake it responds to timed out at exactly the bound with no evidence preserved. The next occurrence will report what the child printed, and the number should be revisited against that rather than raised again by feel.

Gates

typecheck        0 errors across the monorepo
packages/core    971 pass / 3 fail — the same 3 fail on clean develop
                 (ModelsDev static fallback: limit.output expects 32000, gets 64000)
packages/redrob  3380 pass / 0 fail

A Windows shard failed intermittently with `expected exit 0, got -1 after
30200ms`, and the harness's own dump showed an empty stdout and an empty stderr.
That reads as a child which produced nothing at all -- a hang before first output
-- which is a very different diagnosis from one that did most of its work and
then stalled.

It was neither. Both streams were empty because the failure path DISCARDED them.
`AppProcess.run`'s timeout built its error as
`new AppProcessError({ command, cause: "Timed out" })`, dropping the buffers
`collect` had been filling, and the test harness then hardcoded
`stdout: Buffer.alloc(0)` on top of that. So every subprocess timeout reported
the same thing regardless of cause, and the one piece of evidence needed to tell
these cases apart was being thrown away at two separate layers.

Fixed at both. `collectStream` now accepts the accumulator so a CALLER can own
it -- the fold mutates one object and returns it on every chunk, so a caller
holding the reference sees whatever arrived even when the fold is interrupted,
which is what `Effect.timeoutOrElse` does to it. `AppProcessError` gained a
`stdout` field to carry it, and the harness passes the child's real output
through instead of an empty buffer.

The wait bounds are now derived from one number instead of written three times.
`cliIt.concurrent` carried a comment saying Bun's test timeout must stay ABOVE
the child timeout, while `60_000` and `30_000` sat in different functions as
unrelated literals with nothing keeping them in step; raising either alone breaks
the invariant the comment promises, and the symptom -- a test expiring while
holding no spawn permit -- looks like a slow command rather than a mis-tuned
harness.

Windows gets three times the base. Every `redrob.spawn` is `bun run` over the
TypeScript entry, so each one pays a cold transpile plus that platform's
process-creation cost. This is a MITIGATION, not a diagnosis, and it is labelled
as one at the definition: the flake it responds to timed out at exactly the bound
with no evidence preserved. The next occurrence will report what the child
printed, and this number should be revisited against that rather than raised
again by feel.

Verified by reverting the preservation: the new test fails without it.
@its-janghoon
its-janghoon merged commit fad8164 into develop Sep 21, 2026
15 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant