Repository navigation
Fix two ways a grpctunnel goroutine could outlive its test and panic the package - #167
Merged
Merged
Conversation
The grpctunnel package failed intermittently under the race detector with "panic: Log in goroutine after TestCall_ServerCancelAbortsBackend has completed", on the "Call execution failed" line in runCall. handleCallFrame removed a call from the table as soon as the server's Cancel frame arrived, while the call goroutine was still unwinding the backend and had its error and completion log lines left to write. The table is what the heartbeat check and the test barrier in newTestCallTable use to mean "a call goroutine is still running", so the barrier saw an empty table, the test returned, and the goroutine logged through a finished test's logger. A panic ends the package run, which is why the failing run was shorter than a passing one. The cancel path now cancels and closes the body but leaves removal to the goroutine's own defer, as every other path already did. A Data frame for a cancelled call that has not yet left the table now fails its pipe write at once instead of being dropped as unknown, with the same debug line either way. TestCall_ServerCancelKeepsCallInTableUntilGoroutineExits pins the invariant and fails deterministically against the old code. Running TestCall_ServerCancelAbortsBackend 400 times under -race panicked once before the change and is clean after it. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Start ran startAsync on a goroutine outside the wait group. A Close that raced it returned with registration, worker startup and the "gRPC tunnel started" line still to happen: workers were added to the wait group after Wait had returned, and the log line landed after the caller had torn the client down. Under the test logger that is the same "Log in goroutine after test has completed" panic as the cancelled-call case, and startAsync showed up as the other goroutine in that position when Start and Close were looped under -race. startAsync is now counted in the wait group, so Close waits for it. Its registration loop already aborts on the parent context, and the loops it launches exit on the same context, so a Close during startup still returns promptly. TestStartThenClose_WaitsForStartup loops Start and Close fifty times and fails under -race against the old code on the first iteration or two. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
keithfz
approved these changes
Oct 14, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Symptom
go test -race ./server/grpctunnel/failed intermittently, about once in twenty runs when other packages ran alongside it, with the package finishing faster than a passing run. Reproduced on clean main with the full log captured:A goroutine logging through
zaptestafter its test has returned is a panic, and a panic ends the package run early.Root cause (commit 1)
handleCallFrameremoved a call from the call table as soon as the server's Cancel frame arrived, while the call goroutine was still unwinding the backend and had its error and completion log lines left to write. The table is what the heartbeat check and the test barrier innewTestCallTableuse to mean "a call goroutine is still running", so the barrier saw an empty table, the test returned, and the goroutine's log landed on a finished test.The cancel path now cancels and closes the body but leaves removal to the goroutine's own defer, as every other path already did.
TestCall_ServerCancelKeepsCallInTableUntilGoroutineExitspins the invariant and fails deterministically against the old code.TestCall_ServerCancelAbortsBackend× 400 under-raceSame class, found while looking (commit 2)
StartranstartAsyncon a goroutine outside the wait group, soClosecould return with registration, worker startup and the "gRPC tunnel started" log line still to happen. Looping Start and Close under-racehit it within the first couple of iterations.startAsyncis now counted in the wait group; its registration loop and the loops it launches already exit on the parent context, so a Close during startup still returns promptly.TestStartThenClose_WaitsForStartupcovers it.Verification
make -C agent testandmake -C agent test-racepass.-raceinvocation that originally failed: grpctunnel ok every time.grpctunnelis still not inRACE_CLEAN_PKGS. It has been clean across every race run on this branch, so promoting it is a reasonable follow-up once this has soaked.🤖 Generated with Claude Code