Skip to content

Stop two grpctunnel tests racing their own teardown - #129

Merged
shawnburke merged 2 commits into
mainfrom
grpc/accept-1-flake
Aug 27, 2026
Merged

Stop two grpctunnel tests racing their own teardown#129
shawnburke merged 2 commits into
mainfrom
grpc/accept-1-flake

Conversation

@shawnburke

@shawnburke shawnburke commented Aug 27, 2026

Copy link
Copy Markdown
Collaborator

Stack 1/4 — unrelated to the accept-file work, split out because it was making CI flaky while that work was in flight. Independent of the rest; mergeable on its own.

Two separate flakes in server/grpctunnel, both pre-existing on main. Test-only: no production file is touched, and nothing is skipped, disabled or quarantined.

1. TestInitialConnectRetry_RefusedDial waited for the wrong number

connectionsActive counts streams, and the client under test runs two idle streams per server, so the gauge settles at 2 — nondeterministically, since a slot still backing off leaves it at 1. The test waited for exactly 1.

It does pass through 1 on the way up, but waitFor polls every 10ms and the two slots connect within a few of each other. In the CI failure they landed 6ms apart, so the poll saw 0 and then 2, and the equality never held — the test then sat for its full 10s.

What the test is actually about is that the client connects at all after a refused dial, which is what >= 1 says. TestClose_ShutsDownCleanly already spells it that way against the same gauge; this was the outlier.

Confirmed by sampling the settled value: 2, 1, 2 across three runs. The fixed test passes 20 consecutive runs.

2. A finished test could still be logged into

This one took down the whole package, and it is what failed test on 4/4's earlier head:

panic: Log in goroutine after TestInflightCap_QueueTimeout has completed:
... Request completed {"callId": "r1", "method": "GET", "status": 200, "durationMs": 2000}

TestInflightCap_QueueTimeout asserts on r2's queue timeout and returns while r1 is still running a 2s backend call. When r1 finishes it logs into a zaptest logger whose test has completed, which panics.

Waiting on the terminal frame would not have covered it — that Request completed line is a defer inside runCall, so it runs after the frame is sent. table.remove, in the outermost defer of the goroutine startCall launches, runs after both. An empty call table is therefore the barrier that says nothing will log again, so newTestCallTable registers it as t.Cleanup (cancelling anything still in flight first, so a test that deliberately parks a slow call doesn't pay its full delay).

Applied at the table rather than in the one test that happened to panic: the other delayed-backend tests have the same shape and only avoid it by timing, and a new test now gets the barrier just by using the helper.

Reproduced within 3 runs before the fix; 5 plain runs and 3 -race runs green after.


The stack

PR
1 this one flake fixes
2 #130 warn-and-ignore
3 #131 matching parity
4 #128 wildcard origins, auth, pools

🤖 Generated with Claude Code

https://claude.ai/code/session_01DFYsRuHoCbCBWEFvuaj9kV

connectionsActive counts streams, and the client under test runs two idle
streams per server, so the gauge settles at 2 — nondeterministically, since
a slot still backing off leaves it at 1. The test waited for exactly 1. It
passes through 1 on the way up, but waitFor polls every 10ms and the two
slots connect within a few of each other: in CI they landed 6ms apart, so
the poll saw 0 and then 2, and the equality never held.

What the test is about is that the client connects at all after a refused
dial, which is what >= 1 says. TestClose_ShutsDownCleanly already spells it
that way against the same gauge; this was the outlier.

Confirmed by sampling the settled value: 2, 1, 2 across three runs. Fixed
test passes 20 consecutive runs.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DFYsRuHoCbCBWEFvuaj9kV
TestInflightCap_QueueTimeout asserts on r2's queue timeout and returns while
r1 is still running a 2s backend call. When r1 finishes it logs into a
zaptest logger whose test has completed, which panics the whole package:

    panic: Log in goroutine after TestInflightCap_QueueTimeout has completed:
    ... Request completed {"callId": "r1", ...}

Waiting for the terminal frame would not have covered it — that log is a
defer inside runCall, so it runs after the frame is sent. table.remove, in
the outermost defer of the goroutine startCall launches, runs after both.
An empty call table is therefore the barrier that says nothing will log
again, so newTestCallTable registers it as cleanup.

Applied at the table rather than in the one test: the other delayed-backend
tests have the same shape and only avoid it by timing, and a new test gets
the barrier by using the helper.

Panicked within 3 runs before; 5 plain runs and 3 -race runs green after.
@shawnburke shawnburke changed the title Stop TestInitialConnectRetry_RefusedDial racing its own gauge Stop two grpctunnel tests racing their own teardown Aug 27, 2026
@shawnburke
shawnburke merged commit 89ff471 into main Aug 27, 2026
21 checks passed
@shawnburke
shawnburke deleted the grpc/accept-1-flake branch August 27, 2026 01:47
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.

3 participants