Skip to content

TestKeepAlive_ConcurrentFramesNoInterleaving fails deterministically on fast machines (timing-dependent assertion) #219

Description

@jhrozek

Symptom

TestKeepAlive_ConcurrentFramesNoInterleaving in mcpcompat/server fails on main (currently at 80fa11d), reproducibly:

--- FAIL: TestKeepAlive_ConcurrentFramesNoInterleaving (0.00s)
    keepalive_internal_test.go:363:
        Error:    "0" is not positive
        Messages: the ticker should have emitted at least one comment
FAIL    github.com/stacklok/toolhive-core/mcpcompat/server

10/10 runs failed on an M-series macOS dev machine (go1.26.5, darwin/arm64). It is presumably passing in CI, since it merged green in aea3634 — so this looks machine-speed dependent rather than universally broken.

Reproduce:

go test -count=1 -run TestKeepAlive_ConcurrentFramesNoInterleaving ./mcpcompat/server/

Root cause

mcpcompat/server/keepalive_internal_test.go:314-364. The test starts a keep-alive ticker at a 1ms interval, then has 8 goroutines write 200 frames each, then immediately stops the ticker:

k := newKeepAliveWriter(rw, time.Millisecond, nil)
...
wg.Wait()
k.stopKeepAlive()
...
assert.Positive(t, comments, "the ticker should have emitted at least one comment")

1600 in-memory writes to a recordingWriter complete in well under 1ms on a fast machine, so stopKeepAlive() runs before the ticker ever fires and comments is 0. The final assertion is therefore a race against wall-clock time that the test does nothing to win.

Note the test's primary guarantee — that output is a clean concatenation of whole frames and comments, with no interleaving — passes fine. It is only the "at least one comment was emitted" side assertion that fails. So this is a test-design flaw, not a bug in keepAliveWriter.

Suggested fix

Separate the two concerns rather than making the timing tighter, since any sleep-based fix is just a slower race:

  • Keep the interleaving assertion in this test and drop the comments > 0 assertion from it. It does not need a tick to be meaningful; interleaving is checked over whatever the buffer contains.
  • Assert "the ticker emits comments" in a separate deterministic test that waits for evidence of a tick rather than assuming one, e.g. poll rw.commentCount() with require.Eventually before calling stopKeepAlive(), or inject the tick source so the test can drive it explicitly.

The second option is the more robust of the two: newKeepAliveWriter already takes the interval as a parameter, so a seam for an injectable ticker would make this fully deterministic and remove the wall-clock dependency for good.

Context

Found incidentally while verifying an unrelated branch: a per-commit go test ./... sweep reported failures at every commit, which turned out to be this pre-existing failure on main rather than anything in the branch. Not urgent, but it does mean go test ./... is currently red on developer machines, which masks real regressions during exactly this kind of verification.

Metadata

Metadata

Assignees

No one assigned

    Labels

    needs-triageIssue needs initial triage by a maintainer

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions