Source file src/time/tick_test.go

     1  // Copyright 2009 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package time_test
     6  
     7  import (
     8  	"fmt"
     9  	"runtime"
    10  	"strings"
    11  	"sync"
    12  	"testing"
    13  	. "time"
    14  )
    15  
    16  func TestTicker(t *testing.T) {
    17  	t.Parallel()
    18  
    19  	// We want to test that a ticker takes as much time as expected.
    20  	// Since we don't want the test to run for too long, we don't
    21  	// want to use lengthy times. This makes the test inherently flaky.
    22  	// Start with a short time, but try again with a long one if the
    23  	// first test fails.
    24  
    25  	baseCount := 10
    26  	baseDelta := 20 * Millisecond
    27  
    28  	// On Darwin ARM64 the tick frequency seems limited. Issue 35692.
    29  	if (runtime.GOOS == "darwin" || runtime.GOOS == "ios") && runtime.GOARCH == "arm64" {
    30  		// The following test will run ticker count/2 times then reset
    31  		// the ticker to double the duration for the rest of count/2.
    32  		// Since tick frequency is limited on Darwin ARM64, use even
    33  		// number to give the ticks more time to let the test pass.
    34  		// See CL 220638.
    35  		baseCount = 6
    36  		baseDelta = 100 * Millisecond
    37  	}
    38  
    39  	var errs []string
    40  	logErrs := func() {
    41  		for _, e := range errs {
    42  			t.Log(e)
    43  		}
    44  	}
    45  
    46  	for _, test := range []struct {
    47  		count int
    48  		delta Duration
    49  	}{{
    50  		count: baseCount,
    51  		delta: baseDelta,
    52  	}, {
    53  		count: 8,
    54  		delta: 1 * Second,
    55  	}} {
    56  		count, delta := test.count, test.delta
    57  		ticker := NewTicker(delta)
    58  		t0 := Now()
    59  		for range count / 2 {
    60  			<-ticker.C
    61  		}
    62  		ticker.Reset(delta * 2)
    63  		for range count - count/2 {
    64  			<-ticker.C
    65  		}
    66  		ticker.Stop()
    67  		t1 := Now()
    68  		dt := t1.Sub(t0)
    69  		target := 3 * delta * Duration(count/2)
    70  		slop := target * 3 / 10
    71  		if dt < target-slop || dt > target+slop {
    72  			errs = append(errs, fmt.Sprintf("%d %s ticks then %d %s ticks took %s, expected [%s,%s]", count/2, delta, count/2, delta*2, dt, target-slop, target+slop))
    73  			if dt > target+slop {
    74  				// System may be overloaded; sleep a bit
    75  				// in the hopes it will recover.
    76  				Sleep(Second / 2)
    77  			}
    78  			continue
    79  		}
    80  		// Now test that the ticker stopped.
    81  		Sleep(2 * delta)
    82  		select {
    83  		case <-ticker.C:
    84  			errs = append(errs, "Ticker did not shut down")
    85  			continue
    86  		default:
    87  			// ok
    88  		}
    89  
    90  		// Test passed, so all done.
    91  		if len(errs) > 0 {
    92  			t.Logf("saw %d errors, ignoring to avoid flakiness", len(errs))
    93  			logErrs()
    94  		}
    95  
    96  		return
    97  	}
    98  
    99  	t.Errorf("saw %d errors", len(errs))
   100  	logErrs()
   101  }
   102  
   103  // Issue 21874
   104  func TestTickerStopWithDirectInitialization(t *testing.T) {
   105  	c := make(chan Time)
   106  	tk := &Ticker{C: c}
   107  	tk.Stop()
   108  }
   109  
   110  // Test that a bug tearing down a ticker has been fixed. This routine should not deadlock.
   111  func TestTeardown(t *testing.T) {
   112  	t.Parallel()
   113  
   114  	Delta := 100 * Millisecond
   115  	if testing.Short() {
   116  		Delta = 20 * Millisecond
   117  	}
   118  	for range 3 {
   119  		ticker := NewTicker(Delta)
   120  		<-ticker.C
   121  		ticker.Stop()
   122  	}
   123  }
   124  
   125  // Test the Tick convenience wrapper.
   126  func TestTick(t *testing.T) {
   127  	// Test that giving a negative duration returns nil.
   128  	if got := Tick(-1); got != nil {
   129  		t.Errorf("Tick(-1) = %v; want nil", got)
   130  	}
   131  }
   132  
   133  // Test that NewTicker panics when given a duration less than zero.
   134  func TestNewTickerLtZeroDuration(t *testing.T) {
   135  	defer func() {
   136  		if err := recover(); err == nil {
   137  			t.Errorf("NewTicker(-1) should have panicked")
   138  		}
   139  	}()
   140  	NewTicker(-1)
   141  }
   142  
   143  // Test that Ticker.Reset panics when given a duration less than zero.
   144  func TestTickerResetLtZeroDuration(t *testing.T) {
   145  	defer func() {
   146  		if err := recover(); err == nil {
   147  			t.Errorf("Ticker.Reset(0) should have panicked")
   148  		}
   149  	}()
   150  	tk := NewTicker(Second)
   151  	tk.Reset(0)
   152  }
   153  
   154  func TestLongAdjustTimers(t *testing.T) {
   155  	if runtime.GOOS == "android" || runtime.GOOS == "ios" || runtime.GOOS == "plan9" {
   156  		t.Skipf("skipping on %s - too slow", runtime.GOOS)
   157  	}
   158  	if testing.Short() && runtime.NumCPU() < 2 {
   159  		t.Skipf("skipping in short mode, insufficient CPUs")
   160  	}
   161  
   162  	t.Parallel()
   163  	var wg sync.WaitGroup
   164  	defer wg.Wait()
   165  
   166  	// Build up the timer heap.
   167  	const count = 5000
   168  	wg.Add(count)
   169  	for range count {
   170  		go func() {
   171  			defer wg.Done()
   172  			Sleep(10 * Microsecond)
   173  		}()
   174  	}
   175  	for range count {
   176  		Sleep(1 * Microsecond)
   177  	}
   178  
   179  	// Give ourselves 60 seconds to complete.
   180  	// This used to reliably fail on a Mac M3 laptop,
   181  	// which needed 77 seconds.
   182  	// Trybots are slower, so it will fail even more reliably there.
   183  	// With the fix, the code runs in under a second.
   184  	done := make(chan bool)
   185  	AfterFunc(60*Second, func() { close(done) })
   186  
   187  	// Set up a queuing goroutine to ping pong through the scheduler.
   188  	inQ := make(chan func())
   189  	outQ := make(chan func())
   190  
   191  	defer close(inQ)
   192  
   193  	wg.Add(1)
   194  	go func() {
   195  		defer wg.Done()
   196  		defer close(outQ)
   197  		var q []func()
   198  		for {
   199  			var sendTo chan func()
   200  			var send func()
   201  			if len(q) > 0 {
   202  				sendTo = outQ
   203  				send = q[0]
   204  			}
   205  			select {
   206  			case sendTo <- send:
   207  				q = q[1:]
   208  			case f, ok := <-inQ:
   209  				if !ok {
   210  					return
   211  				}
   212  				q = append(q, f)
   213  			case <-done:
   214  				return
   215  			}
   216  		}
   217  	}()
   218  
   219  	for i := range 50000 {
   220  		const try = 20
   221  		for range try {
   222  			inQ <- func() {}
   223  		}
   224  		for range try {
   225  			select {
   226  			case _, ok := <-outQ:
   227  				if !ok {
   228  					t.Fatal("output channel is closed")
   229  				}
   230  			case <-After(5 * Second):
   231  				t.Fatalf("failed to read work, iteration %d", i)
   232  			case <-done:
   233  				t.Fatal("timer expired")
   234  			}
   235  		}
   236  	}
   237  }
   238  func BenchmarkTicker(b *testing.B) {
   239  	benchmark(b, func(pb *testing.PB) {
   240  		ticker := NewTicker(Nanosecond)
   241  		for pb.Next() {
   242  			<-ticker.C
   243  		}
   244  		ticker.Stop()
   245  	})
   246  }
   247  
   248  func BenchmarkTickerReset(b *testing.B) {
   249  	benchmark(b, func(pb *testing.PB) {
   250  		ticker := NewTicker(Nanosecond)
   251  		for pb.Next() {
   252  			ticker.Reset(Nanosecond * 2)
   253  		}
   254  		ticker.Stop()
   255  	})
   256  }
   257  
   258  func BenchmarkTickerResetNaive(b *testing.B) {
   259  	benchmark(b, func(pb *testing.PB) {
   260  		ticker := NewTicker(Nanosecond)
   261  		for pb.Next() {
   262  			ticker.Stop()
   263  			ticker = NewTicker(Nanosecond * 2)
   264  		}
   265  		ticker.Stop()
   266  	})
   267  }
   268  
   269  func TestTimerGC(t *testing.T) {
   270  	run := func(t *testing.T, what string, f func()) {
   271  		t.Helper()
   272  		t.Run(what, func(t *testing.T) {
   273  			t.Helper()
   274  			const N = 1e4
   275  			var stats runtime.MemStats
   276  			runtime.GC()
   277  			runtime.GC()
   278  			runtime.GC()
   279  			runtime.ReadMemStats(&stats)
   280  			before := int64(stats.Mallocs - stats.Frees)
   281  
   282  			for j := 0; j < N; j++ {
   283  				f()
   284  			}
   285  
   286  			runtime.GC()
   287  			runtime.GC()
   288  			runtime.GC()
   289  			runtime.ReadMemStats(&stats)
   290  			after := int64(stats.Mallocs - stats.Frees)
   291  
   292  			// Allow some slack, but inuse >= N means at least 1 allocation per iteration.
   293  			inuse := after - before
   294  			if inuse >= N {
   295  				t.Errorf("%s did not get GC'ed: %d allocations", what, inuse)
   296  
   297  				Sleep(1 * Second)
   298  				runtime.ReadMemStats(&stats)
   299  				after := int64(stats.Mallocs - stats.Frees)
   300  				inuse = after - before
   301  				t.Errorf("after a sleep: %d allocations", inuse)
   302  			}
   303  		})
   304  	}
   305  
   306  	run(t, "After", func() { After(Hour) })
   307  	run(t, "Tick", func() { Tick(Hour) })
   308  	run(t, "NewTimer", func() { NewTimer(Hour) })
   309  	run(t, "NewTicker", func() { NewTicker(Hour) })
   310  	run(t, "NewTimerStop", func() { NewTimer(Hour).Stop() })
   311  	run(t, "NewTickerStop", func() { NewTicker(Hour).Stop() })
   312  }
   313  
   314  func TestChan(t *testing.T) {
   315  	t.Run("Timer", func(t *testing.T) {
   316  		tim := NewTimer(10000 * Second)
   317  		testTimerChan(t, tim, tim.C)
   318  	})
   319  	t.Run("Ticker", func(t *testing.T) {
   320  		tim := &tickerTimer{Ticker: NewTicker(10000 * Second)}
   321  		testTimerChan(t, tim, tim.C)
   322  	})
   323  }
   324  
   325  type timer interface {
   326  	Stop() bool
   327  	Reset(Duration) bool
   328  }
   329  
   330  // tickerTimer is a Timer with Reset and Stop methods that return bools,
   331  // to have the same signatures as Timer.
   332  type tickerTimer struct {
   333  	*Ticker
   334  	stopped bool
   335  }
   336  
   337  func (t *tickerTimer) Stop() bool {
   338  	pending := !t.stopped
   339  	t.stopped = true
   340  	t.Ticker.Stop()
   341  	return pending
   342  }
   343  
   344  func (t *tickerTimer) Reset(d Duration) bool {
   345  	pending := !t.stopped
   346  	t.stopped = false
   347  	t.Ticker.Reset(d)
   348  	return pending
   349  }
   350  
   351  func testTimerChan(t *testing.T, tim timer, C <-chan Time) {
   352  	_, isTimer := tim.(*Timer)
   353  	isTicker := !isTimer
   354  
   355  	// Retry parameters. Enough to deflake even on slow machines.
   356  	// Windows in particular has very coarse timers so we have to
   357  	// wait 10ms just to make a timer go off.
   358  	const (
   359  		sched      = 10 * Millisecond
   360  		tries      = 100
   361  		drainTries = 5
   362  	)
   363  
   364  	noTick := func() {
   365  		t.Helper()
   366  		select {
   367  		default:
   368  		case <-C:
   369  			t.Errorf("extra tick")
   370  		}
   371  	}
   372  	assertTick := func() {
   373  		t.Helper()
   374  		select {
   375  		default:
   376  		case <-C:
   377  			return
   378  		}
   379  		for range tries {
   380  			Sleep(sched)
   381  			select {
   382  			default:
   383  			case <-C:
   384  				return
   385  			}
   386  		}
   387  		t.Errorf("missing tick")
   388  	}
   389  
   390  	// Test simple stop; timer never in heap.
   391  	tim.Stop()
   392  	noTick()
   393  
   394  	// Test modify of timer not in heap.
   395  	tim.Reset(10000 * Second)
   396  	noTick()
   397  
   398  	// Test modify of timer in heap.
   399  	tim.Reset(1)
   400  	Sleep(sched)
   401  	if l, c := len(C), cap(C); l != 0 || c != 0 {
   402  		t.Fatalf("len(C), cap(C) = %d, %d, want 0, 0", l, c)
   403  	}
   404  	assertTick()
   405  
   406  	// Sleep long enough that a second tick must happen if this is a ticker.
   407  	// Test that Reset does not lose the tick that should have happened.
   408  	Sleep(sched)
   409  	tim.Reset(10000 * Second)
   410  	noTick()
   411  
   412  	notDone := func(done chan bool) {
   413  		t.Helper()
   414  		select {
   415  		default:
   416  		case <-done:
   417  			t.Fatalf("early done")
   418  		}
   419  	}
   420  
   421  	waitDone := func(done chan bool) {
   422  		t.Helper()
   423  		for range tries {
   424  			Sleep(sched)
   425  			select {
   426  			case <-done:
   427  				return
   428  			default:
   429  			}
   430  		}
   431  		t.Fatalf("never got done")
   432  	}
   433  
   434  	// Reset timer in heap (already reset above, but just in case).
   435  	tim.Reset(10000 * Second)
   436  
   437  	// Test stop while timer in heap (because goroutine is blocked on <-C).
   438  	done := make(chan bool)
   439  	notDone(done)
   440  	go func() {
   441  		<-C
   442  		close(done)
   443  	}()
   444  	Sleep(sched)
   445  	notDone(done)
   446  
   447  	// Test reset far away while timer in heap.
   448  	tim.Reset(20000 * Second)
   449  	Sleep(sched)
   450  	notDone(done)
   451  
   452  	// Test imminent reset while in heap.
   453  	tim.Reset(1)
   454  	waitDone(done)
   455  
   456  	// If this is a ticker, another tick should have come in already
   457  	// (they are 1ns apart). If a timer, it should have stopped.
   458  	if isTicker {
   459  		assertTick()
   460  	} else {
   461  		noTick()
   462  	}
   463  
   464  	tim.Stop()
   465  	noTick()
   466  
   467  	// Again using select and with two goroutines waiting.
   468  	tim.Reset(10000 * Second)
   469  	done = make(chan bool, 2)
   470  	done1 := make(chan bool)
   471  	done2 := make(chan bool)
   472  	stop := make(chan bool)
   473  	go func() {
   474  		select {
   475  		case <-C:
   476  			done <- true
   477  		case <-stop:
   478  		}
   479  		close(done1)
   480  	}()
   481  	go func() {
   482  		select {
   483  		case <-C:
   484  			done <- true
   485  		case <-stop:
   486  		}
   487  		close(done2)
   488  	}()
   489  	Sleep(sched)
   490  	notDone(done)
   491  	tim.Reset(sched / 2)
   492  	Sleep(sched)
   493  	waitDone(done)
   494  	tim.Stop()
   495  	close(stop)
   496  	waitDone(done1)
   497  	waitDone(done2)
   498  	if isTicker {
   499  		// extra send might have sent done again
   500  		// (handled by buffering done above).
   501  		select {
   502  		default:
   503  		case <-done:
   504  		}
   505  		// extra send after that might have filled C.
   506  		select {
   507  		default:
   508  		case <-C:
   509  		}
   510  	}
   511  	notDone(done)
   512  
   513  	// Test enqueueTimerChan when timer is stopped.
   514  	stop = make(chan bool)
   515  	done = make(chan bool, 2)
   516  	for range 2 {
   517  		go func() {
   518  			select {
   519  			case <-C:
   520  				panic("unexpected data")
   521  			case <-stop:
   522  			}
   523  			done <- true
   524  		}()
   525  	}
   526  	Sleep(sched)
   527  	close(stop)
   528  	waitDone(done)
   529  	waitDone(done)
   530  
   531  	// Test that Stop and Reset block old values from being received.
   532  	// (Proposal go.dev/issue/37196.)
   533  	tim.Reset(1)
   534  	Sleep(10 * Millisecond)
   535  	if pending := tim.Stop(); pending != true {
   536  		t.Errorf("tim.Stop() = %v, want true", pending)
   537  	}
   538  	noTick()
   539  
   540  	tim.Reset(Hour)
   541  	noTick()
   542  	if pending := tim.Reset(1); pending != true {
   543  		t.Errorf("tim.Stop() = %v, want true", pending)
   544  	}
   545  	assertTick()
   546  	Sleep(10 * Millisecond)
   547  	if isTicker {
   548  		assertTick()
   549  		Sleep(10 * Millisecond)
   550  	} else {
   551  		noTick()
   552  	}
   553  	if pending, want := tim.Reset(Hour), isTicker; pending != want {
   554  		t.Errorf("tim.Stop() = %v, want %v", pending, want)
   555  	}
   556  	noTick()
   557  }
   558  
   559  func TestManualTicker(t *testing.T) {
   560  	// Code should not do this, but some old code dating to Go 1.9 does.
   561  	// Make sure this doesn't crash.
   562  	// See go.dev/issue/21874.
   563  	c := make(chan Time)
   564  	tick := &Ticker{C: c}
   565  	tick.Stop()
   566  }
   567  
   568  func TestAfterTimes(t *testing.T) {
   569  	t.Parallel()
   570  	// Using After(10ms) but waiting for 500ms to read the channel
   571  	// should produce a time from start+10ms, not start+500ms.
   572  	// Make sure it does.
   573  	// To avoid flakes due to very long scheduling delays,
   574  	// require 10 failures in a row before deciding something is wrong.
   575  	for range 10 {
   576  		start := Now()
   577  		c := After(10 * Millisecond)
   578  		Sleep(500 * Millisecond)
   579  		dt := (<-c).Sub(start)
   580  		if dt < 400*Millisecond {
   581  			return
   582  		}
   583  		t.Logf("After(10ms) time is +%v, want <400ms", dt)
   584  	}
   585  	t.Errorf("not working")
   586  }
   587  
   588  func TestTickTimes(t *testing.T) {
   589  	t.Parallel()
   590  	// See comment in TestAfterTimes
   591  	for range 10 {
   592  		start := Now()
   593  		c := Tick(10 * Millisecond)
   594  		Sleep(500 * Millisecond)
   595  		dt := (<-c).Sub(start)
   596  		if dt < 400*Millisecond {
   597  			return
   598  		}
   599  		t.Logf("Tick(10ms) time is +%v, want <400ms", dt)
   600  	}
   601  	t.Errorf("not working")
   602  }
   603  
   604  func checkZeroTickerPanicString(t *testing.T) {
   605  	e := recover()
   606  	s, _ := e.(string)
   607  	if want := "called on uninitialized Ticker"; !strings.Contains(s, want) {
   608  		t.Errorf("panic = %v; want substring %q", e, want)
   609  	}
   610  }
   611  
   612  func TestZeroTickerResetDoesntPanic(t *testing.T) {
   613  	defer checkZeroTickerPanicString(t)
   614  	var tr Ticker
   615  	tr.Reset(1)
   616  }
   617  
   618  func TestZeroTimerStopDoesntPanic(t *testing.T) {
   619  	// This is misuse, and the same for time.Timer would panic,
   620  	// but this didn't always panic, and we keep it not panicking
   621  	// to avoid breaking old programs. See issue 21874.
   622  	var tr Ticker
   623  	tr.Stop()
   624  }
   625  
   626  func checkCopiedTickerPanicString(t *testing.T) {
   627  	e := recover()
   628  	s, _ := e.(string)
   629  	if want := "called on copied Ticker"; !strings.Contains(s, want) {
   630  		t.Errorf("panic = %v; want substring %q", e, want)
   631  	}
   632  }
   633  
   634  func TestCopiedTickerResetPanics(t *testing.T) {
   635  	defer checkCopiedTickerPanicString(t)
   636  	var tr Ticker
   637  	tr = *NewTicker(1)
   638  	tr.Reset(1)
   639  }
   640  
   641  func TestCopiedTickerStopDoesntPanic(t *testing.T) {
   642  	// This is misuse, and the same for time.Timer would panic,
   643  	// but this didn't always panic, and we keep it not panicking
   644  	// to avoid breaking old programs. See issue 21874.
   645  	var tr Ticker
   646  	tr = *NewTicker(1)
   647  	tr.Stop()
   648  }
   649  

View as plain text