From 3bcb5122675459ae6fe8ec22f8845e1ff5133ef8 Mon Sep 17 00:00:00 2001 From: MK Date: Thu, 24 Sep 2026 20:40:01 -0400 Subject: [PATCH] test(runtime): fix flaky server-readiness wait (port auto-increment race) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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. --- .../runtime/runner_jsonrpc_headers_test.go | 5 +-- forge-cli/runtime/runner_killswitch_test.go | 3 +- .../runtime/runner_message_validation_test.go | 7 ++- forge-cli/runtime/runner_test.go | 45 ++++++++++++++++--- forge-cli/runtime/server_ready_test.go | 37 +++++++++++++++ forge-cli/runtime/tracing_runner_test.go | 3 +- 6 files changed, 84 insertions(+), 16 deletions(-) create mode 100644 forge-cli/runtime/server_ready_test.go diff --git a/forge-cli/runtime/runner_jsonrpc_headers_test.go b/forge-cli/runtime/runner_jsonrpc_headers_test.go index 28664c7e..9005ac25 100644 --- a/forge-cli/runtime/runner_jsonrpc_headers_test.go +++ b/forge-cli/runtime/runner_jsonrpc_headers_test.go @@ -8,7 +8,6 @@ import ( "net/http" "strconv" "testing" - "time" "github.com/initializ/forge/forge-core/a2a" "github.com/initializ/forge/forge-core/auth" @@ -72,7 +71,7 @@ func TestRunner_JSONRPC_TasksSend_StampsForgeUsageHeaders(t *testing.T) { go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, err := auth.LoadToken(dir) if err != nil { @@ -179,7 +178,7 @@ func TestRunner_JSONRPC_WorkflowContextThreadsThroughDispatcher(t *testing.T) { defer cancel() go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, _ := auth.LoadToken(dir) rpcReq := a2a.JSONRPCRequest{ diff --git a/forge-cli/runtime/runner_killswitch_test.go b/forge-cli/runtime/runner_killswitch_test.go index 56af6d6e..796eb363 100644 --- a/forge-cli/runtime/runner_killswitch_test.go +++ b/forge-cli/runtime/runner_killswitch_test.go @@ -6,7 +6,6 @@ import ( "fmt" "net/http" "testing" - "time" "github.com/initializ/forge/forge-core/a2a" "github.com/initializ/forge/forge-core/auth" @@ -39,7 +38,7 @@ func TestRunner_KillSwitch_RefusesNewWorkOnEveryIngress(t *testing.T) { defer cancel() go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, _ := auth.LoadToken(dir) // Trip the kill switch. Idle agent → cancelled=0, but the call must still diff --git a/forge-cli/runtime/runner_message_validation_test.go b/forge-cli/runtime/runner_message_validation_test.go index 1c9045a8..40a555cc 100644 --- a/forge-cli/runtime/runner_message_validation_test.go +++ b/forge-cli/runtime/runner_message_validation_test.go @@ -7,7 +7,6 @@ import ( "net/http" "strings" "testing" - "time" "github.com/initializ/forge/forge-core/a2a" "github.com/initializ/forge/forge-core/auth" @@ -45,7 +44,7 @@ func TestRunner_JSONRPC_TasksSend_RejectsLegacyTypeDiscriminator(t *testing.T) { defer cancel() go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, _ := auth.LoadToken(dir) // Exact payload shape from issue #119: parts use `"type"` instead @@ -125,7 +124,7 @@ func TestRunner_JSONRPC_TasksSend_SpecCompliantPayloadStillWorks(t *testing.T) { defer cancel() go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, _ := auth.LoadToken(dir) // Same payload, but with the spec-correct `"kind"` discriminator. @@ -192,7 +191,7 @@ func TestRunner_JSONRPC_TasksSend_RejectsEmptyParts(t *testing.T) { defer cancel() go func() { _ = runner.Run(ctx) }() baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) token, _ := auth.LoadToken(dir) body := []byte(`{ diff --git a/forge-cli/runtime/runner_test.go b/forge-cli/runtime/runner_test.go index 91f4378b..52f2bd78 100644 --- a/forge-cli/runtime/runner_test.go +++ b/forge-cli/runtime/runner_test.go @@ -6,8 +6,10 @@ import ( "encoding/json" "fmt" "net/http" + "net/url" "os" "path/filepath" + "strconv" "testing" "time" @@ -57,7 +59,7 @@ func TestRunner_MockIntegration(t *testing.T) { // Wait for server to be ready baseURL := fmt.Sprintf("http://localhost:%d", port) - waitForServer(t, baseURL, 5*time.Second) + baseURL = waitForServer(t, baseURL, serverReadyTimeout) // Load the auto-generated auth token. token, err := auth.LoadToken(dir) @@ -385,20 +387,51 @@ func TestExpandEgressDomains(t *testing.T) { } } -func waitForServer(t *testing.T, baseURL string, timeout time.Duration) { +// serverReadyTimeout bounds how long a test waits for the runner's HTTP server +// to become reachable. Generous on purpose: it only ever elapses on FAILURE +// (a green run returns as soon as /healthz answers), so a high ceiling costs +// nothing on passing runs while absorbing CI startup jitter that made the +// previous 5s ceiling flaky under load. +const serverReadyTimeout = 20 * time.Second + +// waitForServer polls until the runner's HTTP server is reachable and returns +// the base URL it actually came up on. +// +// The server auto-increments its port on conflict (up to 10 attempts, see +// server.Start), and the port findFreePort hands out can be stolen in the gap +// before the runner binds it — so the server may listen on requestedPort+k +// rather than the port the caller put in baseURL. Polling only the requested +// port then times out even though the server is up (the CI flake in +// TestRunner_JSONRPC_WorkflowContextThreadsThroughDispatcher). We therefore +// scan the whole increment window and return the resolved base URL, which the +// caller must use for its subsequent requests: `baseURL = waitForServer(...)`. +func waitForServer(t *testing.T, baseURL string, timeout time.Duration) string { t.Helper() + u, err := url.Parse(baseURL) + if err != nil { + t.Fatalf("waitForServer: invalid baseURL %q: %v", baseURL, err) + } + basePort, err := strconv.Atoi(u.Port()) + if err != nil { + t.Fatalf("waitForServer: no numeric port in baseURL %q: %v", baseURL, err) + } + const portWindow = 10 // matches server.Start's auto-increment attempts deadline := time.After(timeout) for { select { case <-deadline: - t.Fatalf("server did not start within %v", timeout) + t.Fatalf("server did not start within %v (scanned %s:%d-%d)", timeout, u.Hostname(), basePort, basePort+portWindow-1) default: } - resp, err := http.Get(baseURL + "/healthz") - if err == nil { + for off := range portWindow { + cand := fmt.Sprintf("%s://%s:%d", u.Scheme, u.Hostname(), basePort+off) + resp, err := http.Get(cand + "/healthz") + if err != nil { + continue + } _ = resp.Body.Close() if resp.StatusCode == http.StatusOK { - return + return cand } } time.Sleep(50 * time.Millisecond) diff --git a/forge-cli/runtime/server_ready_test.go b/forge-cli/runtime/server_ready_test.go new file mode 100644 index 00000000..77b5a4e1 --- /dev/null +++ b/forge-cli/runtime/server_ready_test.go @@ -0,0 +1,37 @@ +package runtime + +import ( + "fmt" + "net" + "net/http" + "testing" + "time" +) + +// TestWaitForServer_ResolvesAutoIncrementedPort proves the fix for the CI flake +// in TestRunner_JSONRPC_WorkflowContextThreadsThroughDispatcher: when the port +// findFreePort handed out is stolen before the runner binds, server.Start +// auto-increments and the server comes up on a higher port. waitForServer must +// discover it by scanning the increment window and return the real URL, rather +// than time out polling the requested port. +func TestWaitForServer_ResolvesAutoIncrementedPort(t *testing.T) { + ln, err := net.Listen("tcp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + actualPort := ln.Addr().(*net.TCPAddr).Port + + mux := http.NewServeMux() + mux.HandleFunc("/healthz", func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(http.StatusOK) }) + srv := &http.Server{Handler: mux, ReadHeaderTimeout: time.Second} + go func() { _ = srv.Serve(ln) }() + t.Cleanup(func() { _ = srv.Close() }) + + // The caller believes the server is one port lower (as if its requested + // port was taken and Start incremented to actualPort). + requested := fmt.Sprintf("http://127.0.0.1:%d", actualPort-1) + got := waitForServer(t, requested, 3*time.Second) + if want := fmt.Sprintf("http://127.0.0.1:%d", actualPort); got != want { + t.Errorf("waitForServer resolved %q, want %q (should scan up to the incremented port)", got, want) + } +} diff --git a/forge-cli/runtime/tracing_runner_test.go b/forge-cli/runtime/tracing_runner_test.go index 476b2bed..f5cc0eaa 100644 --- a/forge-cli/runtime/tracing_runner_test.go +++ b/forge-cli/runtime/tracing_runner_test.go @@ -87,7 +87,8 @@ func TestRunner_TracingEnabled_InstallsProviderAndShutsDownCleanly(t *testing.T) go func() { runErrCh <- runner.Run(ctx) }() baseURL := "http://localhost:" + itoa(port) - waitForServer(t, baseURL, 5*time.Second) + // This test only needs readiness (it cancels next), not the resolved URL. + waitForServer(t, baseURL, serverReadyTimeout) // At this point Run() has progressed past the tracer install (which // happens before the executor + HTTP server come up). Cancel and