Skip to content

Commit 2cc42f7

Browse files
rscgopherbot
authored andcommitted
time: more flake removal in asynctimerchan test
Trying to write a test for the corner cases in the old async timer chan implementation may have been a mistake, especially since this isn't going to be the default timer chan implementation anymore. But let's try one more time to fix the test. I reproduced the remaining builder failures on my Mac laptop by overloading the CPU in one window and then running 48 instances of the flaky test in loops using 'stress' in another window. It turns out that, contrary to my understanding of async timers and therefore contrary to what the test expected, it is technically possible for t := time.NewTicker(1) t.Reset(1000*time.Hour) <-t.C <-t.C to observe two time values on t.C, as opposed to blocking forever. We always expect the first time value, since the ticker goes off immediately (after 1ns) and sends that value into the channel buffer. To get the second value, the ticker has to be in the process of going off (which it is doing constantly anyway), and the timer goroutine has to be about to call sendTime and then get rescheduled. Then t.Reset and the first <-t.C have to happen. Then the timer goroutine gets rescheduled and can run sendTime's non-blocking send on t.C, which finds an empty buffer and writes a value. This is unlikely, of course, but it definitely happens. This program always panics in just a second or two on my laptop: package main import ( "os" "time" ) func main() { os.Setenv("GODEBUG", "asynctimerchan=1") for { go func() { t := time.NewTicker(1) t.Reset(1000*time.Hour) <-t.C select { case <-t.C: panic("two receives") case <-time.After(1*time.Second): } }() } } Because I did not understand this nuance, the test did not expect it. This CL rewrites the test to expect that possibility. I can no longer make the test fail under 'stress' on my laptop. For #66322. Change-Id: I15c75d2c6f24197c43094da20d6ab55306a0a9f1 Reviewed-on: https://go-review.googlesource.com/c/go/+/585359 Reviewed-by: Cherry Mui <[email protected]> Reviewed-by: Ian Lance Taylor <[email protected]> Auto-Submit: Russ Cox <[email protected]> LUCI-TryBot-Result: Go LUCI <[email protected]>
1 parent 0767ffd commit 2cc42f7

File tree

1 file changed

+39
-20
lines changed

1 file changed

+39
-20
lines changed

src/time/tick_test.go

+39-20
Original file line numberDiff line numberDiff line change
@@ -361,7 +361,11 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
361361
drainTries = 5
362362
)
363363

364-
drain := func() {
364+
// drain1 removes one potential stale time value
365+
// from the timer/ticker channel after Reset.
366+
// When using Go 1.23 sync timers/tickers, draining is never needed
367+
// (that's the whole point of the sync timer/ticker change).
368+
drain1 := func() {
365369
for range drainTries {
366370
select {
367371
case <-C:
@@ -371,6 +375,34 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
371375
Sleep(sched)
372376
}
373377
}
378+
379+
// drainAsync removes potential stale time values after Stop/Reset.
380+
// When using Go 1 async timers, draining one or two values
381+
// may be needed after Reset or Stop (see comments in body for details).
382+
drainAsync := func() {
383+
if synctimerchan {
384+
// sync timers must have the right semantics without draining:
385+
// there are no stale values.
386+
return
387+
}
388+
389+
// async timers can send one stale value (then the timer is disabled).
390+
drain1()
391+
if isTicker {
392+
// async tickers can send two stale values: there may be one
393+
// sitting in the channel buffer, and there may also be one
394+
// send racing with the Reset/Stop+drain that arrives after
395+
// the first drain1 has pulled the value out.
396+
// This is rare, but it does happen on overloaded builder machines.
397+
// It can also be reproduced on an M3 MacBook Pro using:
398+
//
399+
// go test -c strings
400+
// stress ./strings.test & # chew up CPU
401+
// go test -c -race time
402+
// stress -p 48 ./time.test -test.count=10 -test.run=TestChan/asynctimerchan=1/Ticker
403+
drain1()
404+
}
405+
}
374406
noTick := func() {
375407
t.Helper()
376408
select {
@@ -439,9 +471,7 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
439471
assertTick()
440472
Sleep(sched)
441473
tim.Reset(10000 * Second)
442-
if isTicker {
443-
drain()
444-
}
474+
drainAsync()
445475
noTick()
446476

447477
// Test that len sees an immediate tick arrive
@@ -453,9 +483,7 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
453483
// Test that len sees an immediate tick arrive
454484
// for Reset of timer NOT in heap.
455485
tim.Stop()
456-
if !synctimerchan {
457-
drain()
458-
}
486+
drainAsync()
459487
tim.Reset(1)
460488
assertLen()
461489
assertTick()
@@ -465,9 +493,7 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
465493
// Test that Reset does not lose the tick that should have happened.
466494
Sleep(sched)
467495
tim.Reset(10000 * Second)
468-
if !synctimerchan && isTicker {
469-
drain()
470-
}
496+
drainAsync()
471497
noTick()
472498

473499
notDone := func(done chan bool) {
@@ -494,9 +520,7 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
494520

495521
// Reset timer in heap (already reset above, but just in case).
496522
tim.Reset(10000 * Second)
497-
if !synctimerchan {
498-
drain()
499-
}
523+
drainAsync()
500524

501525
// Test stop while timer in heap (because goroutine is blocked on <-C).
502526
done := make(chan bool)
@@ -526,17 +550,12 @@ func testTimerChan(t *testing.T, tim timer, C <-chan Time, synctimerchan bool) {
526550
}
527551

528552
tim.Stop()
529-
if isTicker || !synctimerchan {
530-
t.Logf("drain")
531-
drain()
532-
}
553+
drainAsync()
533554
noTick()
534555

535556
// Again using select and with two goroutines waiting.
536557
tim.Reset(10000 * Second)
537-
if !synctimerchan {
538-
drain()
539-
}
558+
drainAsync()
540559
done = make(chan bool, 2)
541560
done1 := make(chan bool)
542561
done2 := make(chan bool)

0 commit comments

Comments
 (0)