Skip to content

Fix: allocate integration test-server ports from the OS and attach child output to start-up failures - #546

Open
AmaadMartin wants to merge 5 commits into
mainfrom
fix/windows-ci-flaky-server-harness
Open

Fix: allocate integration test-server ports from the OS and attach child output to start-up failures#546
AmaadMartin wants to merge 5 commits into
mainfrom
fix/windows-ci-flaky-server-harness

Conversation

@AmaadMartin

@AmaadMartin AmaadMartin commented Aug 2, 2026

Copy link
Copy Markdown
Owner

Please ensure you have read the contribution guide before creating a pull request.

Link to Issue or Description of Change

  1. Link to an existing issue (if applicable):
    No existing issue. This targets the intermittently red windows-latest leg of the run-tests matrix in .github/workflows/validation.yaml (os: [ubuntu-latest, windows-latest, macos-latest]).
  2. Or, if no issue exists, describe the change:
    Problem: two unrelated defects make the windows-latest leg fail with no code change to blame, so contributors cannot tell a real regression from CI noise.

Cause 1 — the integration harness guesses its port. BaseTestServer picked its port as 40000 + Math.floor(Math.random() * 10000) and passed that guess to the spawned CLI as an explicit --port. Nothing checked the guess was bindable. AdkTsApiServer always lands in that branch — it calls super('localhost', params.port || 0), so both port: 0 and an omitted port collapsed to the guess. A failed bind is fatal to the child: AdkApiServer.start() rejects from its server.on('error') handler, the api_server/web command logs and calls process.exit(1), and the harness reports CLI exited prematurely with code 1. Windows is where a guessed port is most likely to be unusable — the OS reserves TCP blocks for Hyper-V/WinNAT (netsh int ipv4 show excludedportrange protocol=tcp) and several vitest workers draw independently from the same 10000-port range concurrently. Corroboration inside a single failing file: webui_test.ts runs the same assertions twice via describe.each, once against the CLI-spawned server (guessed port) and once against the in-process AdkApiServer with port: 0, which asks the OS for a port — and only the first flakes.

Compounding it, the failure was undiagnosable. The rejected Error carried only the exit code; the child's stdout went to a separate console.error, and its stderr was echoed per chunk and never accumulated at all, so in an interleaved CI log the reason never reached the error the reporter shows.

Cause 2 — a real-interpreter test on a 5000 ms budget. 'should execute shell code and return stdout' runs real code through UnsafeLocalCodeExecutor, which on Windows spawns powershell with -NoLogo -NoProfile -ExecutionPolicy Bypass -File script.ps1. The file lives in the unit:core vitest project, which sets no testTimeout and therefore inherits Vitest's 5000 ms default — unlike the integration project, which sets 60000 ms explicitly. A PowerShell cold start under V8 coverage instrumentation (npm run test:coverage) on a loaded shared runner is marginal against 5000 ms.

Solution:

Cause 1 — remove the guess, do not retry it. New reserveFreePort(host) binds port: 0, reads the assignment back off server.address() and releases the probe, so the port handed to the child is one the OS just confirmed free. It runs before spawnProcess() because both subclasses read this.port from inside that closure (--port and TEST_API_SERVER_PORT), and multi_hop_remote_agent.ts reads TEST_API_SERVER_PORT at child start-up to build its own agent-card URL — so passing --port 0 and reading the banner afterwards would not be sufficient. There is deliberately no retry loop around server start-up: the allocation is fixed so the start does not fail. static getRandomPort() is deleted (grep confirms no callers outside the class) and url becomes a getter so it can never disagree with port.

The handshake now accumulates both streams and embeds them in every rejection, along with the terminating signal. It matches the start message against the accumulated buffer rather than a single chunk, so a split write cannot lose the handshake; it rejects on 'close' rather than 'exit', because 'close' fires only after the stdio pipes are drained, which is what guarantees the captured output is complete; and every settle path (resolve, error, premature close, timeout) goes through one settle() that clears the timer and detaches its listeners, so no timer outlives the handshake. The two 'data' listeners stay attached for the life of the child so the pipes keep draining — a chatty server would otherwise block on a full 64 KB pipe buffer — and only retention is gated, by a capturing flag.

stop() waits for the child's 'exit' event with a bounded SIGKILL escalation instead of sleeping a fixed 500 ms while the child may still hold its port. The subscription is taken before the kill so a fast exit cannot be missed, and an already-exited child returns early because the event would never fire again for it.

'exit' rather than 'close' here is load-bearing, and the first push of this PR got it wrong: the cross-language suite spawns go run ., which leaves the built binary running as a grandchild holding the inherited stdio pipes. 'close' fires only once those pipes are released, so it can outlive the process stop() is trying to reap — killing the wrapper emitted 'exit' but never 'close', and ts_a2a_go_test.ts's afterAll hung until its 60 s budget expired (Error: Hook timed out in 60000ms). 'exit' means the child itself is gone and is guaranteed after the SIGKILL escalation. The start-up handshake still rejects on 'close', where waiting for the pipes to drain is exactly the point.

One line in go_server.ts follows: successLogMessage interpolated this.url eagerly, i.e. before the port is allocated, so it now reads 'Test Go Server started'.

Cause 2 — one per-test budget. A single named, doc-commented constant REAL_INTERPRETER_TIMEOUT_MS = 40000 applied as the third argument to that one it(). Neither the project-level nor the file-level timeout was raised, and the mocked-spawn cases in the nested describe('spawn arguments') keep the 5000 ms default. The value sits above UnsafeLocalCodeExecutor's own default timeoutSeconds ?? 30 on purpose, so a genuinely stuck interpreter reports the executor's own timeout message instead of an opaque Vitest timeout.

Simplifications from the complexity review (a fifth commit, 2696ca3b):

  • The old banner-port-adoption path (parse http://localhost:<n> out of stdout and adopt it) is now unreachable, so it is deleted along with its regex and its two tests. Once the port is reserved before the spawn, every subclass hands the child that exact port, and neither child can bind anything else: AdkApiServer rejects on EADDRINUSE rather than rebinding (adk_api_server.ts:975-982) and the Go server log.Fatalfs (go_backend/server.go:25-27). The Go banner could not match the pattern in any case — it prints 127.0.0.1 and the regex required localhost. The parsed port could only ever equal the port we already had.
  • reserveFreePort no longer hand-rolls a promise around listen(); node:events' once() does exactly that and rejects on 'error' by design, and it was already imported for stop().
  • formatStream/formatCapturedOutput were two functions and two doc comments for one string; excerpt() keeps only the part worth naming.
  • successLogMessage is gone. It restated serverName at every call site, and it was the root cause of the go_server.ts change in the first place: the argument was evaluated before the port was reserved, so interpolating this.url rendered :0, which my first pass worked around by deleting the URL from the string. Logging after the await from serverName + this.url removes the parameter and restores the URL the Go server had lost. This does touch test_api_server.ts, which the plan asked to leave alone — the plan's reason was that it already reads this.port lazily, which is still true; removing a parameter it passes is unavoidable and is called out here rather than left silent.
  • The one-use TerminationSignal alias is inlined at its single use. Note it is inlined as ChildProcessWithoutNullStreams['signalCode'], not NodeJS.Signals | null: the bare NodeJS identifier fails this repo's no-undef lint rule, which is why the alias existed at all.

Scope: test-infrastructure only. No file under core/src, dev/src or integrations/src changes, and coverage.include is limited to those three trees, so the coverage thresholds are untouched by construction. package.json/package-lock.json are not touched.

Collision check (recorded as required): gh pr list --repo AmaadMartin/adk-js --state open --limit 1000 returned 445 open PRs; I then ran gh pr diff --name-only over all 445 rather than filtering by title, and found 27 that touch these files. Substantive overlaps: #218 (fix/flaky-install-bound-integration-suites) adds a reserveFreePort with the same signature plus the go_server.ts line; #545 adds the same allocation as getFreePort with a bounded capture; #375 reworks the same handshake for listener cleanup; #224, #498, #254 and #61 all give the shell test a larger budget. None of them is merged, all six are still open, and none changes stop(). I did not branch from or stack on any of them, since stacking would mean picking one of three mutually-conflicting unmerged rewrites of the same region as a base. Whoever triages this should dedupe against #218/#545 for cause 1 and #224/#498 for cause 2 — only one of these should land.

CI on this branch (fork, commit 14b2475d): run-tests (windows-latest) pass (9m28s), run-tests (ubuntu-latest) pass, run-tests (macos-latest) pass, run-tests (cross-language) pass, check-license pass.

Two rounds of red on the way there, both caused by this change and both fixed rather than worked around, which is worth recording because each was a genuine defect the local Linux run could not have caught:

  1. stop() waiting on 'close' hung the cross-language afterAll (see above). Fixed by reaping on 'exit'; the diagnosis was then reproduced and re-verified locally.
  2. Three of the new cases encoded POSIX signal semantics and failed on windows-latest. Windows reports the signal a child was asked to terminate with but surfaces a self-termination only as exit code 1, so the signal-naming case now kills from the test; Windows emulates SIGINT as unconditional termination so the SIGKILL escalation never arms there, and that case now expects the signal each platform actually produces while still pinning that stop() returns with the child reaped; and Windows tears the grandchild down with its parent, so teardown now tolerates ESRCH specifically and rethrows anything else. No suite is skipped and no timeout was widened to accommodate them.

Size note: the diff is ~594 insertions, but ~400 of those are the new test file that proves the fix, and the production-side change is 169/-52 lines in one harness file plus 30/-13 and 1/-1. I did not split it into a stack because separating the tests from the code they pin would make both halves unreviewable, and a stacked part would get no CI on the fork (the workflow triggers on pull_request: branches: [main]).

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.

New file tests/integration/test_case_utils_test.ts (18 cases). It does not depend on a built CLI — a local ScriptedTestServer subclass spawns process.execPath -e <script>, which is portable and needs no shell quoting. It records the child handle and this.port from inside its own spawn closure, so nothing reaches into a protected member.

npx vitest run --project integration tests/integration/test_case_utils_test.ts
  -> Test Files 1 passed (1); Tests 18 passed (18)

npx vitest run --project integration tests/integration/a2a tests/integration/adk_web
  -> Test Files 4 passed (4); Tests 8 passed (8)
     (the four files the flake was observed on)

npx vitest run --project cross-language
  -> Test Files 2 passed (2); Tests 4 passed (4)
     (both files drive BaseTestServer via `go run`; run with go1.26.5)

npx vitest run --project unit:core core/test/code_executors/unsafe_local_code_executor_test.ts
  -> Tests 3 failed | 15 passed (18)

Those 3 failures are pre-existing and unrelatedshould materialize input files…, should return only new files…, should infer correct mimeType… fail identically on a clean checkout of the base commit (verified via git stash: 3 failed | 15 passed both with and without this change). They are FileContentEncoding string-literal mismatches in test fixtures, in code this PR does not touch. The shell case this PR does touch passes.

npx tsc --noEmit -p tsconfig.json     -> 0 errors
npx eslint <the 4 changed files>      -> clean
npx prettier --check <the 4 changed>  -> all files use Prettier code style

Coverage of the new harness code, measured with a throwaway config (these files sit outside coverage.include, so the repo gate is unaffected): 97.50% branch on test_case_utils.ts, with exactly one uncovered branch — address === null || typeof address === 'string' in reserveFreePort. That is a type-narrowing guard for Server.address()'s AddressInfo | string | null signature; the string form is only produced by IPC servers, which this never is, so it is unreachable for a TCP listen. I kept it rather than delete it or replace it with a non-null assertion: removing a guard to make a number go up is the wrong trade. Every other new branch is executed, including the !capturing retention gate on both streams, parsedPort > 0 in both directions, the signal-present and signal-absent close paths, the empty-capture path, tail truncation, and all four stop() paths.

Prove each test can fail — each mutation was applied to the fixed code, the test run, and the mutation reverted:

# Mutation Test Failure
1 Drop the captured output from the premature-exit rejection surfaces both captured streams when the child exits prematurely AssertionError: expected [Function] to throw error including 'STDERR-REASON' but got 'Scripted exited prematurely with code…'
2 Move the reserveFreePort call to after spawnProcess() reserves the port before the child is spawned AssertionError: expected 0 to be greater than 0
3 Match the banner against the per-chunk string instead of the accumulated buffer completes the handshake when the banner is split across writes AssertionError: promise rejected "Error: Timeout waiting for scripted to st…" instead of resolving
4 Restore the fixed await new Promise(r => setTimeout(r, 500)) in stop() returns only once the child has actually exited AssertionError: expected false to be true
5 Set REAL_INTERPRETER_TIMEOUT_MS = 1 should execute shell code and return stdout Error: Test timed out in 1ms.
6 Wait on 'close' instead of 'exit' in stop() returns when a grandchild still holds the inherited stdio pipes Error: Test timed out in 60000ms.

Mutation 6 also reproduces end to end: with 'close', npx vitest run --project cross-language tests/cross_language/a2a/ts_go/ts_a2a_go_test.ts fails locally with the same Error: Hook timed out in 60000ms that CI reported, and passes with 'exit'. The regression test's grandchild is kept alive for 60 s and reaped in teardown, so the case cannot pass by simply outlasting the pipe holder — an earlier version of it used a 3 s grandchild and passed against the bug.

Mutation 4 does fail on Linux here — the case scripts a child that installs a SIGINT handler and delays its exit by 800 ms, which outlasts the old 500 ms sleep, so the old code returns while the child is still alive.

Limitation stated plainly: mutation 5 proves only that the budget is wired to that test. The Windows PowerShell slowness that motivates cause 2 cannot be reproduced on a Linux dev machine, so there is no local proof that 40000 ms is the right number — only that the previous 5000 ms was not a process-start budget and that the new value is above the executor's own 30 s deadline.

Manual End-to-End (E2E) Tests:
Please provide instructions on how to manually test your changes, including any necessary setup or configuration.

Run after npm install && npm run build (the harness spawns dev/dist/esm/cli_entrypoint.js, which only exists after a build).

  1. Occupy a port:
    node -e "require('node:net').createServer().listen(41234,'localhost',()=>console.log('held'))"

  2. In another shell, point the real CLI at it:
    node dev/dist/esm/cli_entrypoint.js api_server tests/integration/adk_web/agent --port 41234

    Observed: [ADK CLI] Error starting API server: Port 41234 is already in use, exit code 1. This is the child-side text the harness previously discarded.

  3. Confirm the harness now attaches it: with the port still held, construct new AdkTsApiServer({agentsDir: 'tests/integration/adk_web/agent', port: 41234}) and await start().

    Observed: rejects with a message containing both Port 41234 is already in use and exited prematurely with code 1. Before this change the same scenario produced only CLI exited prematurely with code 1. (Run as a scratch test and deleted afterwards; it is not part of the diff, because it depends on binding a fixed port.)

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.

Amaad Martin added 3 commits August 2, 2026 15:16
…ild output to start-up failures

The windows-latest validation leg failed intermittently from two unrelated
causes.

BaseTestServer guessed its port as 40000 + random(10000) and passed the guess
to the spawned CLI as an explicit --port. Nothing checked the guess was
bindable, so it could already be held by another concurrent vitest worker or
fall inside a TCP range Windows reserves for Hyper-V/WinNAT; a failed bind is
fatal to the child, which is what 'CLI exited prematurely with code 1' was.
reserveFreePort() now binds port 0, reads the assignment back and releases it
before the child is spawned, so the port is one the OS just confirmed free.

The rejected Error carried only the exit code: stdout went to a separate
console.error and stderr was logged per chunk and dropped. Both streams are now
accumulated and embedded in the rejection, along with the terminating signal,
so a CI log line is enough to diagnose the failure. The handshake matches the
banner against the accumulated buffer rather than a single chunk, rejects on
'close' rather than 'exit' so the capture is complete, and routes every settle
path through one settle() that clears the timer and detaches its listeners.

stop() now waits for the child's 'close' event with a bounded SIGKILL
escalation instead of sleeping a fixed 500 ms while the child may still hold
its port.

The shell case in unsafe_local_code_executor_test.ts spawns a real PowerShell
host on Windows but inherited Vitest's 5000 ms default, which is not a
process-start budget. It gets one named per-test constant; no project-level or
file-level timeout was raised.
…harness

Adds the two cases the first pass left uncovered: an explicitly requested port
must be used verbatim rather than re-reserved, and the post-handshake drain
test now floods stderr as well as stdout, so the retention gate is exercised on
both streams.
The cross-language Go suite spawns `go run .`, which leaves the built binary
running as a grandchild holding the inherited stdio pipes. 'close' fires only
once those pipes are released, so it can outlive the process stop() is trying
to reap: killing the wrapper emitted 'exit' but never 'close', and the afterAll
hook hung until its 60s budget expired. 'exit' is the event that means the
child is gone, and it is guaranteed after the SIGKILL escalation.

The informational listener moves back to 'exit' for the same reason, so a
mid-test crash of such a server is still reported. The start-up handshake keeps
rejecting on 'close', where waiting for the pipes to drain is the point --
that is what guarantees the captured output in the message is complete.

Adds a regression test whose grandchild outlives the assertion window, so it
cannot pass by merely outlasting the pipe holder.
Amaad Martin added 2 commits August 2, 2026 15:49
Three new cases encoded POSIX signal semantics and failed on windows-latest.

Windows reports the signal a child was *asked* to terminate with, but a
self-termination (process.kill(process.pid, ...)) surfaces only as exit code 1,
so the signal-naming case now kills from the test. It waits for the harness to
reach its spawn closure first, since startProcess awaits the port reservation
before the child handle exists -- the reason that case self-signalled at all.

Windows emulates SIGINT as unconditional termination, so a child cannot ignore
it and the SIGKILL escalation never arms; the escalation case now expects the
signal each platform actually produces, and still pins that stop() returns with
the child reaped.

Windows tears the grandchild down with its parent, so teardown reaped a pid
that no longer existed. It now tolerates ESRCH specifically -- that is the
outcome the test wants -- and rethrows anything else.
…bstractions

Simplifications from the complexity review.

The banner-port-adoption path is dead once the port is reserved before the
spawn: every subclass hands the child that exact port (--port and
TEST_API_SERVER_PORT, or PORT), and neither child can bind anything else --
AdkApiServer rejects on EADDRINUSE rather than rebinding and the Go server
log.Fatalf's -- so the parsed port could only ever equal the port we already
had. The Go banner could not match the regex at all, since it prints
127.0.0.1 and the pattern requires localhost. The regex, the parse block and
the two tests covering that behaviour go with it.

reserveFreePort hand-rolled a promise wrapper around listen(); node:events
once() already does exactly that and rejects on 'error' by design, and it was
imported for stop() already.

formatStream/formatCapturedOutput were two functions and two doc comments for
one string; excerpt() keeps the part worth naming.

successLogMessage restated serverName at every call site and carried nothing
the callee lacked. It was also the root cause of the go_server.ts workaround:
the argument was evaluated before the port was reserved, so interpolating
this.url rendered :0. Logging after the await from serverName + this.url drops
the parameter and restores the URL the Go server had lost.

TerminationSignal was a one-use alias; its single use now names the derived
type inline. Not NodeJS.Signals -- that identifier trips eslint no-undef in
this config, which is why the alias existed.
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