Repository navigation
Conversation
mafredri
marked this pull request as ready for review
November 3, 2026 20:29
mafredri
marked this pull request as draft
November 3, 2026 21:03
Timer.fire registered a test cleanup each time a channel timer fired, from the goroutine that Advance starts. If the test stopped waiting on the Advance, for example because MustWait's context had expired, the fire could run after the test's cleanups, so its cleanup never ran and the goroutine writing to C leaked. Inside a testing/synctest bubble that panics with "main bubble goroutine has exited but blocked goroutines remain". Each fire also grew the test's cleanup list. The cleanup that NewMock registers now closes a channel that every pending write also selects on, and a timer that fires after it skips the write, so timer channels still cannot be read after the test ends. Pending writes now end when that cleanup runs, so cleanups registered after NewMock can still read a timer that has fired.
The comment in Timer.fire said pending writes end when the test ends. They end when the cleanup registered by NewMock runs, so cleanups registered before NewMock cannot read a fired timer, while cleanups registered after it can. The Mock.done comment also explained why there is no per-fire cleanup; it now only says what done does.
pprof.Do adds a frame that testing cannot skip, so the mock's Advance log line pointed at the closure inside labeledAdvance, or at runtime/pprof when the closure was marked as a helper. Setting the labels with SetGoroutineLabels and marking labeledAdvance as a helper makes the log line point at the test.
The write goroutine may not have reached its select when NewMock's cleanup closes done, so a reader waiting at that moment can still get the value. The previous comment said channels cannot be read after the cleanup runs.
The pprof label helpers, cleanupTB, and the cleanup registration count tested how the fix works. verifyNoLeakTestMain already reports a write goroutine that outlives the tests, so TestNoLeak_Go123 now also fires a timer after the test that owns the Mock has ended. On 9591439 that subtest leaks the write goroutine and the leak check fails. Without the done case in the write select, FiredDuringTest fails the same way.
done already ends a write that starts after NewMock's cleanup has run, so the skip only decided whether a reader already waiting on C at that moment gets the value. No test covered it, and the leak tests pass, and fail when the done case is removed, without it.
The note that a write can still reach a reader already waiting on C describes done, so it now sits on the done field instead of in Timer.fire. The interrupt paragraph is rewrapped to 100 columns and names what ends the write goroutine.
Tests often stop a server in a cleanup registered after NewMock, and the server's workers may read a timer that fired while they were busy. On main, the cleanup that each fire registered ran before that cleanup and ended the write, so the worker blocked and the shutdown hung. TestTimer_ReadableDuringCleanup fails on main and passes here.
A timer write that reaches its select after NewMock's cleanup has closed done, while a reader is already waiting on C, has two ready cases, and select picks one at random. In a probe, the waiting reader got the value in 93 of 200 runs. The write now tries a non-blocking send first, so a waiting reader always gets the value (200 of 200). A write with no waiting reader still ends on done, Stop or Reset, so it does not outlive the test, and no value can be received after Stop or Reset returns.
Without synctest, a test cannot know that a reader is waiting on C before the write starts, so the check would be flaky. synctest.Test is stable since Go 1.25 and go.mod says 1.23, hence the build tag.
Mock.done was created by NewMock, outside any synctest bubble. When a Mock created with the outer test's t had a timer created and fired inside a bubble, the write goroutine also waited on done, which synctest does not count as durably blocked, so the test hung until go test's timeout instead of panicking at once as on main. NewMock's cleanup now ends each pending write by receiving on that timer's interrupt channel, as Stop does. That channel is created where the timer fires, so it belongs to the bubble. The Mock tracks timers with a write in flight, and a write that delivers its value removes its timer. A timer that fires after the cleanup starts no goroutine and only reaches a reader that is already waiting.
Cleanups run in reverse order, so a cleanup registered before NewMock runs after the pending timer writes have ended. If it waits for code that reads a fired timer, that code never gets the value and the wait hangs. The NewMock doc now says what is dropped and which order works.
A timer that fires after NewMock's cleanup no longer starts a write goroutine, so this test stopped reaching the send that tries a waiting reader first, and removing that send passed. The FiredBeforeCleanup row fires the timer as the test's last step: in a bubble the write goroutine often starts after the cleanup waits on interrupt. Without the first send it fails 200 of 200 runs, and about half of them with -race. FiredAfterCleanup fails every run when fire sends nothing after the cleanup. Each round is a new bubble with one timer. Ten timers in one bubble failed only 78 of 200 runs without the first send, because only the write the cleanup ends first meets a waiting interrupt.
One line was 101 columns. The comment above the interrupt check started with "Otherwise", which reads as a note on the check's else branch; it now names the condition it describes.
NewTimer and Reset fire a timer with a non-positive duration from a new goroutine, so NewTimer(0) followed by Reset(0) often fires the timer twice before the first write ends. The second fire replaced interrupt, and the Mock tracks one write per timer, so nothing ended the first write and it leaked: 93 to 99 of 100 rounds in the new TimerFiredTwice subtest. fire now ends the earlier write first, as Reset does.
go.mod now requires Go 1.26, so testing/synctest is always available and the go1.25 build tag no longer selects anything.
TestTickerFunc_ContextDoneDuringTick checked that Wait had not returned by waiting 100ms of wall time, which passes when Wait is merely slow. In a synctest bubble, synctest.Wait returns once every goroutine is blocked, so the check runs when Wait has either returned or is waiting for the callback. TestTimer_ReadableDuringCleanup waited 10 seconds before reporting a worker that never received. Bubble time moves as soon as every goroutine is blocked, so the failure is reported at once, and a quit channel lets the stuck worker exit so the bubble can end.
A time.Timer whose value has not been received counts as active since Go
1.23: Stop and Reset discard the value and return true. The mock
returned false, so the idiom `if !t.Stop() { <-t.C }` blocked forever
after a fire, because Stop had already ended the write. coder/coder uses
that idiom in coderd/database/pubsub/watchdog.go and
enterprise/coderd/usage/generator.go.
Stop and Reset now return true when they end a write that had not sent
the value. TestTimerStop_Go123 and TestTimerReset_Go123 asserted the old
results; TestTimer_StopAndReset replaces them with the results of a
time.Timer on Go 1.26 and adds a row for the idiom.
NewTimer and Reset fire a timer with a non-positive duration from a new goroutine. When Stop or Reset ran before that goroutine, the fire still sent its value after they returned, and a Reset's new schedule was removed: NewTimer(0) then Reset(time.Hour) delivered a value and left no event in 200 of 200 synctest runs. A fire that Advance started has the same race with a Stop or Reset that gets the lock first. fire now returns without effect when the timer was stopped or nxt no longer matches the fire's time, and NewTimer, AfterFunc and Reset set nxt to the current time for a non-positive duration so their own fire still matches. Two fires can no longer both start a write, so fire no longer ends an earlier one. The new StopZeroDuration and ResetZeroDuration rows fail without the check.
A Stop or Reset right after Advance returns usually gets the lock before the fire that Advance started, and before the previous commit that fire still sent its value afterward: 1998 of 2000 runs after Stop and 1996 of 2000 after Reset. Without the check in fire, the new rows fail 100 of 100 runs, and about 63 of 100 with -race.
The check that drops replaced fires also covers AfterFunc: with AfterFunc(0, f) and an immediate Stop, Stop returned true and f still ran in 200 of 200 synctest runs before that check, and in 0 of 200 after it. A time.AfterFunc timer never runs f after Stop returns true. The new StopAfterFuncZeroDuration row checks that Stop's result agrees with whether f ran, because f's goroutine can run before or after Stop. Without the check in fire it fails 100 of 100 runs. The start functions now also return the channel the fire sends on: C, or one that f sends on.
"The Mock's timers" can be read to include tickers, but a ticker still stops when the cleanup that NewTicker registers runs, so calling NewMock first does not keep its ticks readable. The NewMock doc now says so and points to NewTicker.
The start function comment said each returns the channel its fire sends on, but for the AfterFunc row f sends on it and fire sends nothing. The AfterFunc row checks that Stop's result agrees with whether f ran instead of expecting true, and the comment did not say why. Stop gets the Mock's lock before f's goroutine in practice, but that goroutine got it first in 19 of 32000 runs with -race, and no Mock call can hold it back, so a row that expected true would fail in those runs.
"This does not cover tickers; see NewTicker" did not say what happens to a ticker. Its ticks stop when the cleanup that NewTicker registers runs, which is before any cleanup registered earlier in the test, so the NewMock doc now says that.
The NewTicker doc said a ticker sends no ticks after the test ends, and the NewMock doc said a ticker stops when its NewTicker cleanup runs. Both are false once Reset is called after that cleanup: Reset starts a new runLoop, ticks are sent again, and only Stop ends it. Both docs now say so, and the NewMock doc names NewTicker tickers, because a TickerFunc keeps calling its function until its context ends.
The comment gave one measured count, but repeated measurements vary: f's goroutine got the lock first in 19 of 32000 runs with -race here and in 28 to 45 of 32000 in a review. "A few in ten thousand" holds for all of them.
The NewMock doc now says first what a cleanup registered after NewMock can rely on, then what NewMock's cleanup drops and what a later fire sends, and points to NewTicker for ticks. NewTicker no longer describes a Reset after its cleanup: #38 removes that cleanup, so the sentence would only be churn.
The comment named Stop and Reset as the reasons a fire is dropped, but the check also drops the second fire after NewTimer(0) and Reset(0), where the first fire has already removed the timer.
e6cbe10 moved this test into a synctest bubble so that it no longer waits 100ms of wall time. That change is unrelated to the timer fixes here and will be done separately.
StopAfterFuncZeroDuration failed with "got false, want true", which did
not say whether f ran after Stop returned true or Stop returned false
before f ran. It now runs after the table as its own subtest that names
the disagreement, and the AfterFunc race is explained once there. With
the AfterFunc row gone, the start functions return only the timer.
StopAndDrainFiredUnread is gone: it passes whenever StopFiredUnread
does, and a mutation that breaks Stop's result for a fired timer fails
StopFiredUnread alone. StopFiredUnread now says that its result keeps if
!t.Stop() { <-t.C } from blocking.
TimerFiredTwice named a result that the fix prevents. The new name says what the subtest does.
On this branch a Reset after the ticker's own cleanup starts its runLoop again, and ticks then arrive until Stop, also after NewMock's cleanup. 09613b7 dropped that from the NewTicker doc because #38 removes the per-ticker cleanup, but this branch can merge first, so its docs must hold without #38. NewMock's pointer to NewTicker now names the exception too.
mafredri
force-pushed
the
mafredri/timer-fire-cleanup
branch
from
November 4, 2026 18:16
5eaccd7 to
65aed39
Compare
mafredri
changed the title
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.
Stacked on #41.
A test can hang at shutdown when a worker reads a mock timer during the test's own cleanup. The usual setup: the test calls
NewMock, thent.Cleanup(srv.Close); the timer fires while the worker is busy;Closeunblocks the worker, which then readstmr.C.Timer.fireregistered a cleanup on every fire, which ran beforeCloseand ended the write, so the worker andCloseblocked forever. That cleanup also leaked when a fire registered it after the test's cleanups had run, as after anAdvancethe test stopped waiting on. Inside atesting/synctestbubble the test then panicked withdeadlock: main bubble goroutine has exited but blocked goroutines remain.This PR:
NewMock's cleanup instead, so a fired timer stays readable until then, and a later fire sends only to a reader already waiting onC. TheNewMockdoc says to callNewMockbefore registering cleanups that wait for code reading its timers.StopandResetreturntruefor a timer that has fired but whose value was not received, and discard the value, as atime.Timerdoes on Go 1.26. The mock returnedfalse, soif !t.Stop() { <-t.C }blocked forever after a fire, as in coder/coder'scoderd/database/pubsub/watchdog.goandenterprise/coderd/usage/generator.go.StoporResetthat gets the lock after they return. Before,StoporResetright afterNewTimer(0)orAdvancewas followed by a stale value in almost every run, andAfterFunc(0, f)ranfafterStopreturnedtrue.Not fixed:
Advance(...).MustWaitmisses the value in almost every run, and in over a third of runs with-race, because the goroutine that sends it may not be waiting yet; a blocking receive orsynctest.Waitgets it.Please use this description as the squash commit body.