Fix: bound the captured start-up streams and report a child that exits without closing its pipes - #558
Open
AmaadMartin wants to merge 3 commits into
Conversation
added 3 commits
August 2, 2026 20:37
…s without closing its pipes Two gaps left by the start-up handshake rework this stacks on. The captured buffers grew without limit for the whole readiness window -- a server stuck in a log loop could make the harness hold everything it wrote, and only the trailing excerpt was ever used. The cap moves from format time to accumulation time via appendCapped(), so the bound now applies to what is retained rather than only to what is printed; excerpt() keeps the empty-stream fallback that is still its own concern. The handshake also settled on 'close' alone. A child that leaves a grandchild holding the inherited stdio pipes -- `go run` does exactly that, which is why stop() already reaps on 'exit' rather than 'close' -- emits 'exit' with its exit code and then never closes, so the wait ran to the full readiness timeout and blamed a slow start for what was an immediate exit. 'exit' now arms a short flush-grace timer that reports through the same path, so 'close' is still preferred when the pipes do drain and the exit code is reported when they do not. The timer is cleared and the listener detached in settle() with the others.
The per-chunk `console.error` echo in onStderr predates this work and was the only thing surfacing stderr from a server that starts cleanly and fails later: retention stops when the handshake settles, so after the rework nothing the child wrote to stderr mid-test reached the CI log. Echo unconditionally, ahead of the `capturing` gate, keeping the original `<server> Stderr: <chunk>` wording so existing log searches still match. The listener already outlives the handshake, so no other change is needed. The new test writes to stderr *after* the handshake has settled, which pins the echo's placement and not merely its presence -- moving the call back behind the `capturing` gate fails it.
…out hunk Simplifications from the complexity review. waitForChild and waitForLine both hand-rolled a poll loop that Vitest ships as vi.waitFor. waitForLine went further and re-implemented spy.mock.calls with an array and a mockImplementation; asserting on the spy directly removes the array, the custom implementation and the helper, and keeps the same assertion. One WAIT_FOR_OPTIONS names the shared budget so the two call sites cannot drift. excerpt() lost its reason to exist when the cap moved to ingest: what remained was a named function around a `||`, called once on the next line. Inlined, with the placeholder kept as a constant since it appears on both streams. The REAL_INTERPRETER_TIMEOUT_MS hunk in unsafe_local_code_executor_test is restored to its base state. It arrived with the branch this stacks on but belongs to neither: different vitest project, different subject, no shared code with the harness. It also sets the same constant that open fork branch fix/unsafe-local-code-executor-windows-shell-test-timeouts sets to 60000, so carrying it here would collide. The file passes 18/18 without it.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Please ensure you have read the contribution guide before creating a pull request.
Link to Issue or Description of Change
Related: Fix: allocate integration test-server ports from the OS and attach child output to start-up failures #546
Stacked on #546 (
fix/windows-ci-flaky-server-harness) — this PR targets that branch, notmain. Review #546 first.Collision check. Run before writing any code, against all 457 open PRs on the fork:
It found the task I was given already implemented by #546 — OS-reserved port before the spawn,
getRandomPort()deleted,urlas a getter,successLogMessageremoved, both streams embedded in every rejection, accumulated-buffer readiness match, rejection on'close',stop()awaiting exit — and a second overlapping rewrite of the same class in #545 (process_utils.ts). So this is deliberately not a competing implementation: I stacked on #546 and this PR contains only the two gaps left against the specification. One "gap" I initially flagged, the droppedhttp://localhost:<port>banner scrape, turned out to be correct in #546 and is not re-added: with the port reserved before the spawn the child cannot bind anything else, so the scraped port could only ever equal the one already held.Problem: three defects remain in the start-up handshake after #546.
Unbounded retention.
onStdout/onStderraccumulated withstdout += data.toString()and the 4000-char bound was applied only byexcerpt()at message-format time. Retention was therefore bounded in time (until the handshake settles) but not in size: a server stuck in a log loop writes for the whole readiness window — 60000 ms for theintegrationproject — and the harness holds every byte, of which only the tail is ever used.A child that exits without closing its pipes is reported as a timeout. The handshake settled on
'close'alone. A child that leaves a grandchild holding the inherited stdio pipes emits'exit'carrying its exit code and then never emits'close', because the pipes never reach EOF. This is not hypothetical in this repo: it is exactly why #546's ownstop()reaps on'exit'rather than'close'(go runleaves the built binary holding the pipes), and #546 has astop()test for it.startProcesskept the'close'-only wait, so the same child dying during start-up stalls for the full readiness budget and then reportsTimeout waiting for <server> to start.— blaming a slow start for what was an immediate exit, and discarding the exit code the child already handed us.Mid-test stderr is silently discarded. The harness's per-chunk
console.error(Stderr:)echo predates all of this work and was dropped during the rework.onStderronly appended to the capped buffer, and retention stops when the handshake settles — so once the server was up, nothing it wrote to stderr reached the CI log or anywhere else. Start-up diagnosability improved while post-start-up diagnosability became strictly worse than before.Solution: three small changes, no new dependency, no
process.platformbranch, no retry.Move the bound from format time to accumulation time. New module-level
appendCapped(buffer, chunk, maxChars = OUTPUT_EXCERPT_CHARS)keeps the trailingmaxChars; both'data'handlers go through it. The bound now constrains what is retained, not just what is printed — one bound, in one place. Message content is unchanged, since both spellings surface the same tail.excerpt()goes with its now-dead slice: what was left was a named function wrapping a||, called once on the next line, so the empty-stream placeholder is now aNO_OUTPUTconstant used inline byformatCapturedOutput.Bound the wait for a drained pipe.
'exit'now arms aSTDIO_FLUSH_GRACE_MS(250 ms) timer that reports through the existingonClosepath with the code and signal'exit'supplied.'close'is still preferred and still wins whenever the pipes actually drain, so complete output remains the normal case; the grace timer only fires when'close'is never coming. The timer is cleared and the'exit'listener detached insettle()alongside the others, so the promise still settles exactly once and leaves no timer behind on any path.This cannot truncate a successful handshake: pending pipe data is delivered far inside 250 ms, so
onStdoutstill settles first for a child that prints its banner and exits immediately.Restore the stderr echo. One unconditional
console.errorinonStderr, ahead of thecapturinggate, with the original wording so existing CI log searches still match. The listener already outlives the handshake, so nothing else was needed. No other console call is added: the base class still logs exactly onestarted atline.One inherited hunk is reverted out of this stack.
core/test/code_executors/unsafe_local_code_executor_test.tsarrived with #546 carrying aREAL_INTERPRETER_TIMEOUT_MS = 40000per-test budget. It belongs to neither PR: different vitest project, different subject, no shared code with the harness, and it sets the same constant that open branchfix/unsafe-local-code-executor-windows-shell-test-timeoutssets to60000. Restored to its base state here so the stack does not carry it tomain; the file passes 18/18 without it. It should also be dropped at source in #546.Test helpers use the stdlib.
waitForChildandwaitForLineeach hand-rolled a poll loop that Vitest 3.2.6 ships asvi.waitFor, andwaitForLineadditionally re-implementedspy.mock.callswith an array and amockImplementation. Asserting on the spy directly deletes the array, the custom implementation and the helper, with the same assertion; oneWAIT_FOR_OPTIONSnames the shared budget. No test case or assertion was removed.Testing Plan
Please describe the tests that you ran to verify your changes. This is required for all PRs that are not small documentation or typo fixes.
Unit Tests:
[x] I have added or updated unit tests for my change.
[x] All unit tests pass locally.
Eight new cases in
tests/integration/test_case_utils_test.ts(26 passed, 0 failed). No existing test was modified, deleted, skipped or weakened.appendCapped— below the cap, exactly at the cap, over the cap (tail kept, head dropped), a single chunk that alone exceeds the cap, still capped after 100 appends, and the default cap.reports the exit code when a grandchild holds the pipes open— the child spawns a grandchild withstdio: 'inherit', writes a marker to each stream, then exits 3. Asserts the rejection carriesexited prematurely with code 3and both markers, within a 10000 ms readiness budget it must not reach. Teardown reaps the grandchild by pid.echoes stderr written after the handshake has settled— the child writes to stderr 50 ms after printing its banner, so the echo can only come from a listener that outlived the handshake. This pins the echo's placement, not just its presence.Proof each test can fail (mutations applied to the source, tests re-run, then reverted):
stdout = appendCapped(...)→stdout += data.toString()(both streams)keeps only the tail of a noisy childfails:expected 'Scripted exited prematurely with code…' not to contain 'HEAD-MARKER'child.on('exit', onExit)reports the exit code when a grandchild holds the pipes openfails after 10026 ms:expected [Function] to throw error including 'Scripted exited prematurely with code…' but got 'Timeout waiting for scripted to start…'appendCappedreturnsbuffer + chunk(no slice)expected 'abcde' to be 'bcde',expected … to have a length of 15 but got 1000,expected … to have a length of 4000 but got 5000, plus the noisy-child testconsole.errorecho fromonStderrechoes stderr written after the handshake has settledfails:never echoed Scripted Stderr: MID-TEST-FAILUREconsole.errorbehind thecapturinggateThe first mutation is worth calling out: because the bound moved to accumulation time, #546's pre-existing
keeps only the tail of a noisy childtest now pins the retention cap rather than the format-time slice, so it is a real regression fence for this change rather than one that passes either way.Honest limits. The grandchild mutation was verified on Linux. On Windows the grandchild is torn down with its parent, so
'close'may arrive on its own and the test can pass through the'close'path there — the assertion is on behaviour, not on which path produced it. And the unbounded-retention defect has no other externally observable symptom than peak memory; the evidence that the wiring is live is the mutation above, not a memory measurement.Manual End-to-End (E2E) Tests:
CI does not run on this PR:
.github/workflows/validation.yamltriggers onpull_request: branches: [main], and this PR is based onfix/windows-ci-flaky-server-harness. Validated locally instead, on the exact pushed commit:The four integration suites are the regression fence:
input_required_test.tsprovesTEST_API_SERVER_PORTstill reaches the child, andwebui_test.tsexercises the explicitport: 0path.To see the diagnostic difference by hand, apply the second mutation above and re-run the grandchild test: the harness stalls for the whole readiness budget and reports a start-up timeout instead of
Scripted exited prematurely with code 3plus the child's own output.Checklist
[x] I have read the CONTRIBUTING.md document.
[x] I have performed a self-review of my own code.
[x] I have commented my code, particularly in hard-to-understand areas.
[x] I have added tests that prove my fix is effective or that my feature works.
[x] New and existing unit tests pass locally with my changes.