mathias/hyperguild
1
0
Fork 0
Code Issues 30 Pull Requests 3 Actions Packages Projects Releases Wiki Activity

flake: TestRoutingPodEndToEnd port-wait deadline exceeded under load #15

New Issue
Closed
opened 2026-05-18 15:23:58 +00:00 by mathias · 1 comment
mathias commented 2026-05-18 15:23:58 +00:00
Owner
Copy Link
Copy Source

Symptom

TestRoutingPodEndToEnd in cmd/routing/main_test.go intermittently fails at line 58 with:

Error: Received unexpected error: context deadline exceeded
Test: TestRoutingPodEndToEnd

The 5s deadline is waitForPort(t, "127.0.0.1:33310", 5*time.Second) (main_test.go:58, 85–104) waiting for the freshly-built routing binary to bind its HTTP listener.

Observed during #14 e2e work (2026-05-18)

Failed twice in a row:

  1. task check (full project test suite with -race -count=1)
  2. go test -race -count=1 ./cmd/routing/... immediately after

Both at ~5.23s. Then it stopped reproducing — 5/5 passes in isolation with -race -count=1, including with cold test cache (go clean -testcache).

Pattern: triggered under load, not by code.

Likely causes (untriaged)

  1. go build cost inside the test. buildRouting(t) compiles ./cmd/routing into a temp dir. Cold build + -race instrumentation can take >5s on a loaded machine. Running the produced binary directly outside the test starts in <2s, so the bottleneck is build, not bind.
  2. Port 33310 contention. Hardcoded port; a previous test or stray process could hold it briefly. ss -tlnp | grep 33310 was empty when checked, but a previous TIME_WAIT or another test could collide.
  3. osPath() returns empty PATH. Lines 116–122 iterate exec.Command("env").Env which is the child Cmd's env (nil unless set), not the parent's. The test passes PATH= (empty) to the routing subprocess. The binary doesn't need PATH at runtime (statically linked Go), so this is probably benign — but it is incorrect and worth fixing while we're here.

Proposed fix

Cheap, low risk:

  • Increase waitForPort deadline to 30s (cost only paid on failure paths).
  • Replace hardcoded port 33310 with a net.Listen("tcp", ":0") random port allocation passed via ROUTING_PORT env.
  • Fix osPath() to read parent process env via os.Getenv("PATH") (or just drop the explicit PATH= and rely on cmd.Env inheriting).

Acceptance criteria

  • go test -race -count=10 ./cmd/routing/... is green
  • task check is green across 3 consecutive runs
  • Port no longer hardcoded
  • osPath() either correct or removed

References

  • cmd/routing/main_test.go:30–80 — test body
  • cmd/routing/main_test.go:85–104 — waitForPort
  • cmd/routing/main_test.go:116–122 — osPath
  • Surfaced during #14 verification (commit 937355c).
## Symptom `TestRoutingPodEndToEnd` in `cmd/routing/main_test.go` intermittently fails at line 58 with: ``` Error: Received unexpected error: context deadline exceeded Test: TestRoutingPodEndToEnd ``` The 5s deadline is `waitForPort(t, "127.0.0.1:33310", 5*time.Second)` (main_test.go:58, 85–104) waiting for the freshly-built routing binary to bind its HTTP listener. ## Observed during #14 e2e work (2026-05-18) Failed twice in a row: 1. `task check` (full project test suite with `-race -count=1`) 2. `go test -race -count=1 ./cmd/routing/...` immediately after Both at ~5.23s. Then it stopped reproducing — 5/5 passes in isolation with `-race -count=1`, including with cold test cache (`go clean -testcache`). Pattern: triggered under load, not by code. ## Likely causes (untriaged) 1. **`go build` cost inside the test.** `buildRouting(t)` compiles `./cmd/routing` into a temp dir. Cold build + `-race` instrumentation can take >5s on a loaded machine. Running the produced binary directly outside the test starts in <2s, so the bottleneck is build, not bind. 2. **Port 33310 contention.** Hardcoded port; a previous test or stray process could hold it briefly. `ss -tlnp | grep 33310` was empty when checked, but a previous TIME_WAIT or another test could collide. 3. **`osPath()` returns empty PATH.** Lines 116–122 iterate `exec.Command("env").Env` which is the *child* Cmd's env (nil unless set), not the parent's. The test passes `PATH=` (empty) to the routing subprocess. The binary doesn't need PATH at runtime (statically linked Go), so this is probably benign — but it is incorrect and worth fixing while we're here. ## Proposed fix Cheap, low risk: - Increase `waitForPort` deadline to 30s (cost only paid on failure paths). - Replace hardcoded port `33310` with a `net.Listen("tcp", ":0")` random port allocation passed via `ROUTING_PORT` env. - Fix `osPath()` to read parent process env via `os.Getenv("PATH")` (or just drop the explicit `PATH=` and rely on `cmd.Env` inheriting). ## Acceptance criteria - [ ] `go test -race -count=10 ./cmd/routing/...` is green - [ ] `task check` is green across 3 consecutive runs - [ ] Port no longer hardcoded - [ ] `osPath()` either correct or removed ## References - `cmd/routing/main_test.go:30–80` — test body - `cmd/routing/main_test.go:85–104` — `waitForPort` - `cmd/routing/main_test.go:116–122` — `osPath` - Surfaced during #14 verification (commit `937355c`).
mathias commented 2026-05-18 18:00:34 +00:00
Author
Owner
Copy Link
Copy Source

Fixed in fe18e4e.

Root cause (confirmed)

All three suspects from the issue body played a role:

  1. Hardcoded port 33310 — primary trigger. Under task check parallel package execution another test or stray process could hold the port long enough that the routing binary bound it late or failed Listen. Now freePort(t) grabs :0, releases, passes the OS-assigned port via ROUTING_PORT.
  2. 5s waitForPort deadline — too tight when go build -race runs cold under load. Bumped to 30s; only paid in failure mode.
  3. osPath() always returned empty — iterating exec.Command("env").Env reads the child Cmd's env (nil), not the parent's. The binary worked anyway (static Go), but the helper was a no-op masquerading as PATH inheritance. Replaced with explicit PATH= + HOME= via os.Getenv.

Why not os.Environ() for full inheritance

Tried that first. It leaked ROUTING_MCP_TOKEN from my shell into the test subprocess, flipping the routing pod into bearer-auth-required mode → all calls 401 unauthorized. Explicit minimal env keeps the test hermetic.

Verification

$ go clean -testcache && go test -race -count=10 ./cmd/routing/...
ok  github.com/mathiasbq/supervisor/cmd/routing  3.414s

$ task check   # ran 3 times consecutively
✓ context: canonical and adapters are in sync
0 issues. 0 issues. ok across all packages.
No vulnerabilities found.

Diff: +28/-16, single file cmd/routing/main_test.go.

Closing.

Fixed in `fe18e4e`. ### Root cause (confirmed) All three suspects from the issue body played a role: 1. **Hardcoded port 33310** — primary trigger. Under `task check` parallel package execution another test or stray process could hold the port long enough that the routing binary bound it late or failed `Listen`. Now `freePort(t)` grabs `:0`, releases, passes the OS-assigned port via `ROUTING_PORT`. 2. **5s `waitForPort` deadline** — too tight when `go build -race` runs cold under load. Bumped to 30s; only paid in failure mode. 3. **`osPath()` always returned empty** — iterating `exec.Command("env").Env` reads the *child* `Cmd`'s env (nil), not the parent's. The binary worked anyway (static Go), but the helper was a no-op masquerading as PATH inheritance. Replaced with explicit `PATH=` + `HOME=` via `os.Getenv`. ### Why not `os.Environ()` for full inheritance Tried that first. It leaked `ROUTING_MCP_TOKEN` from my shell into the test subprocess, flipping the routing pod into bearer-auth-required mode → all calls `401 unauthorized`. Explicit minimal env keeps the test hermetic. ### Verification ``` $ go clean -testcache && go test -race -count=10 ./cmd/routing/... ok github.com/mathiasbq/supervisor/cmd/routing 3.414s $ task check # ran 3 times consecutively ✓ context: canonical and adapters are in sync 0 issues. 0 issues. ok across all packages. No vulnerabilities found. ``` Diff: +28/-16, single file `cmd/routing/main_test.go`. Closing.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
agent/ready
Meets the agent-ready contract; authorizes unattended execution
 blocked/client
Waiting on the client
 blocked/supplier
Waiting on a supplier
 blocked/upstream
Waiting on an upstream project or vendor
 risk/high
Irreversible, security-relevant, or control plane
 risk/low
Reversible, local, test-covered
 risk/medium
Touches shared state, deploys or data
 size/l
Too big - split it
 size/m
Under two days
 size/s
Under half a day
 size/xs
Under an hour
 status:dispatch
status:dispatched
status:review
status:reviewing
type/chore
Maintenance, no behaviour change
 type/decision
Human decision required; never agent/ready
 type/docs
Documentation only
 type/feat
New capability
 type/fix
Corrects broken behaviour
 type/ops
Infrastructure, deploy, runtime
 type/research
Investigate; output is a finding, not code
 type/test
Test coverage only
No labels
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
renovate-bot mathias
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: mathias/hyperguild#15