test(runtime): fix flaky server-readiness wait (port auto-increment race) - #529
Conversation
…ace) TestRunner_JSONRPC_WorkflowContextThreadsThroughDispatcher (and the other runner-startup tests) flaked in CI with "server did not start within 5s" while the logs showed agent_card_published — i.e. the server WAS up, just not on the polled port. Root cause: findFreePort binds :0, closes, and returns the port; under CI contention that port is grabbed before the runner binds, so server.Start auto-increments to port+1..+9 — but waitForServer kept polling (and the caller kept requesting) the original port. - waitForServer now scans the server's auto-increment window (requestedPort.. +9, matching server.Start's 10 attempts) and RETURNS the base URL the server actually came up on; callers reassign `baseURL = waitForServer(...)` so their subsequent requests hit the right port. - Readiness ceiling raised 5s -> serverReadyTimeout (20s). It only elapses on failure (a green run returns as soon as /healthz answers), so it costs nothing on passing runs while absorbing CI startup jitter. - New TestWaitForServer_ResolvesAutoIncrementedPort proves the scan resolves a server that came up on a higher port than requested. Test-only; no production behavior change.
initializ-mk
left a comment
There was a problem hiding this comment.
Self-review — verified against source ✅
Clean, well-scoped test-only fix; posting as a COMMENT (own PR). No production changes.
Verified good:
waitForServerscan is correct: parses the port, scansbase..base+9(matchesserver.Start's 10 auto-increment attempts), returns the resolved base URL; deadline error names the scanned range.- All callers that use
baseURLfor requests reassignbaseURL = waitForServer(...);tracing_runner_test.gocorrectly doesn't (readiness-only —baseURLisn't used for requests there). - Timeout 5s →
serverReadyTimeout(20s) only elapses on failure; free on green runs. TestWaitForServer_ResolvesAutoIncrementedPortis a genuine regression test.
Scoping call is right: the rarer ephemeral-port-exhaustion mode (tight-loop bind failure) is a different failure, not how CI runs, and its durable fix is a bigger change — correctly deferred.
Two observations — captured in the follow-up #530 (not blocking):
- The scan has no server-identity check — under heavy parallel port-window overlap it could match a neighbor's
/healthz. Eliminated by exposing the runner's resolved port (no more guessing). - 6 of 8 startup sites do
_ = runner.Run(ctx), swallowing startup errors — which is exactly why this flake presented as an opaque timeout. Template for the fix already exists inrunner_test.go/tracing_runner_test.go(errCh <- runner.Run(ctx)).
Verdict: LGTM. Needs a second reviewer to merge (own PR).
(Author-name note retracted: the PR/commits correctly show initializ-mk; the raw commit object's author.name is just MK from the local git config on that machine — email + account are correct, no attribution issue.)
| } | ||
| resp, err := http.Get(baseURL + "/healthz") | ||
| if err == nil { | ||
| for off := range portWindow { |
There was a problem hiding this comment.
Scan is correct for the fix. Note (follow-up #530, non-blocking): probing /healthz across the window has no server-identity check — under heavy parallel overlap it could match a neighbor test's server on a lower port in the window. Rare and strictly better than the pre-fix timeout, but the durable fix is to have the runner expose its resolved port so tests never guess (tracked in #530, alongside surfacing Run's error in the 6 _ = runner.Run(ctx) sites).
The failure
CI failed on
mainwith:…but the log also showed
agent_card_publishedjust before the timeout — so the server did start. It just wasn't on the port the test was polling.Root cause —
findFreePortTOCTOU + server port auto-incrementfindFreePortbinds:0, records the port, closes the listener, and returns the port. Under CI contention that port can be grabbed before the runner callsnet.Listen, soserver.Start(which tries the requested port then auto-increments up to 10 times on conflict) comes up onport+1..+9. ButwaitForServer— and the caller's subsequent requests — kept using the original port → 5s timeout even though the server was healthy.This affects every runner-startup test (6 files, 8
waitForServercalls), not just the one that happened to lose the race in CI.Fix (test-only)
waitForServerscans the auto-increment window (requestedPort..+9, matchingserver.Start's 10 attempts) and returns the base URL the server actually came up on. Callers reassignbaseURL = waitForServer(...)so their requests hit the right port.serverReadyTimeout(20s). It only ever elapses on failure — a green run returns the instant/healthzanswers — so a higher ceiling costs nothing on passing runs while absorbing CI startup jitter.TestWaitForServer_ResolvesAutoIncrementedPortstands a healthz server on an OS-assigned port and assertswaitForServer, told the server is one port lower, resolves the real one.No production code changes.
Verification
TestRunner_JSONRPC_WorkflowContextThreadsThroughDispatcher+ the new regression test pass under-count=3.go test ./runtime/green;go vet+golangci-lint0 issues;gofmtclean; nogo.work.sumchurn.Note / possible follow-up
There is a separate, much rarer failure mode I could only reproduce by running the entire package in a tight loop locally (10+ back-to-back server startups exhausting ephemeral ports so
Run's bind fails outright) — not the reported failure and not how CI runs (single pass). The durable fix for that would be to have the runner accept a pre-boundnet.Listener(or expose its resolved port) so tests never guess a port; noting it here rather than expanding this PR's scope.