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
5package time_test
6
7import (
8	"errors"
9	"fmt"
10	"runtime"
11	"strings"
12	"sync"
13	"sync/atomic"
14	"testing"
15	. "time"
16)
17
18// Go runtime uses different Windows timers for time.Now and sleeping.
19// These can tick at different frequencies and can arrive out of sync.
20// The effect can be seen, for example, as time.Sleep(100ms) is actually
21// shorter then 100ms when measured as difference between time.Now before and
22// after time.Sleep call. This was observed on Windows XP SP3 (windows/386).
23// windowsInaccuracy is to ignore such errors.
24const windowsInaccuracy = 17 * Millisecond
25
26func TestSleep(t *testing.T) {
27	const delay = 100 * Millisecond
28	go func() {
29		Sleep(delay / 2)
30		Interrupt()
31	}()
32	start := Now()
33	Sleep(delay)
34	delayadj := delay
35	if runtime.GOOS == "windows" {
36		delayadj -= windowsInaccuracy
37	}
38	duration := Now().Sub(start)
39	if duration < delayadj {
40		t.Fatalf("Sleep(%s) slept for only %s", delay, duration)
41	}
42}
43
44// Test the basic function calling behavior. Correct queueing
45// behavior is tested elsewhere, since After and AfterFunc share
46// the same code.
47func TestAfterFunc(t *testing.T) {
48	i := 10
49	c := make(chan bool)
50	var f func()
51	f = func() {
52		i--
53		if i >= 0 {
54			AfterFunc(0, f)
55			Sleep(1 * Second)
56		} else {
57			c <- true
58		}
59	}
60
61	AfterFunc(0, f)
62	<-c
63}
64
65func TestAfterStress(t *testing.T) {
66	stop := uint32(0)
67	go func() {
68		for atomic.LoadUint32(&stop) == 0 {
69			runtime.GC()
70			// Yield so that the OS can wake up the timer thread,
71			// so that it can generate channel sends for the main goroutine,
72			// which will eventually set stop = 1 for us.
73			Sleep(Nanosecond)
74		}
75	}()
76	ticker := NewTicker(1)
77	for i := 0; i < 100; i++ {
78		<-ticker.C
79	}
80	ticker.Stop()
81	atomic.StoreUint32(&stop, 1)
82}
83
84func benchmark(b *testing.B, bench func(n int)) {
85
86	// Create equal number of garbage timers on each P before starting
87	// the benchmark.
88	var wg sync.WaitGroup
89	garbageAll := make([][]*Timer, runtime.GOMAXPROCS(0))
90	for i := range garbageAll {
91		wg.Add(1)
92		go func(i int) {
93			defer wg.Done()
94			garbage := make([]*Timer, 1<<15)
95			for j := range garbage {
96				garbage[j] = AfterFunc(Hour, nil)
97			}
98			garbageAll[i] = garbage
99		}(i)
100	}
101	wg.Wait()
102
103	b.ResetTimer()
104	b.RunParallel(func(pb *testing.PB) {
105		for pb.Next() {
106			bench(1000)
107		}
108	})
109	b.StopTimer()
110
111	for _, garbage := range garbageAll {
112		for _, t := range garbage {
113			t.Stop()
114		}
115	}
116}
117
118func BenchmarkAfterFunc(b *testing.B) {
119	benchmark(b, func(n int) {
120		c := make(chan bool)
121		var f func()
122		f = func() {
123			n--
124			if n >= 0 {
125				AfterFunc(0, f)
126			} else {
127				c <- true
128			}
129		}
130
131		AfterFunc(0, f)
132		<-c
133	})
134}
135
136func BenchmarkAfter(b *testing.B) {
137	benchmark(b, func(n int) {
138		for i := 0; i < n; i++ {
139			<-After(1)
140		}
141	})
142}
143
144func BenchmarkStop(b *testing.B) {
145	benchmark(b, func(n int) {
146		for i := 0; i < n; i++ {
147			NewTimer(1 * Second).Stop()
148		}
149	})
150}
151
152func BenchmarkSimultaneousAfterFunc(b *testing.B) {
153	benchmark(b, func(n int) {
154		var wg sync.WaitGroup
155		wg.Add(n)
156		for i := 0; i < n; i++ {
157			AfterFunc(0, wg.Done)
158		}
159		wg.Wait()
160	})
161}
162
163func BenchmarkStartStop(b *testing.B) {
164	benchmark(b, func(n int) {
165		timers := make([]*Timer, n)
166		for i := 0; i < n; i++ {
167			timers[i] = AfterFunc(Hour, nil)
168		}
169
170		for i := 0; i < n; i++ {
171			timers[i].Stop()
172		}
173	})
174}
175
176func BenchmarkReset(b *testing.B) {
177	benchmark(b, func(n int) {
178		t := NewTimer(Hour)
179		for i := 0; i < n; i++ {
180			t.Reset(Hour)
181		}
182		t.Stop()
183	})
184}
185
186func BenchmarkSleep(b *testing.B) {
187	benchmark(b, func(n int) {
188		var wg sync.WaitGroup
189		wg.Add(n)
190		for i := 0; i < n; i++ {
191			go func() {
192				Sleep(Nanosecond)
193				wg.Done()
194			}()
195		}
196		wg.Wait()
197	})
198}
199
200func TestAfter(t *testing.T) {
201	const delay = 100 * Millisecond
202	start := Now()
203	end := <-After(delay)
204	delayadj := delay
205	if runtime.GOOS == "windows" {
206		delayadj -= windowsInaccuracy
207	}
208	if duration := Now().Sub(start); duration < delayadj {
209		t.Fatalf("After(%s) slept for only %d ns", delay, duration)
210	}
211	if min := start.Add(delayadj); end.Before(min) {
212		t.Fatalf("After(%s) expect >= %s, got %s", delay, min, end)
213	}
214}
215
216func TestAfterTick(t *testing.T) {
217	const Count = 10
218	Delta := 100 * Millisecond
219	if testing.Short() {
220		Delta = 10 * Millisecond
221	}
222	t0 := Now()
223	for i := 0; i < Count; i++ {
224		<-After(Delta)
225	}
226	t1 := Now()
227	d := t1.Sub(t0)
228	target := Delta * Count
229	if d < target*9/10 {
230		t.Fatalf("%d ticks of %s too fast: took %s, expected %s", Count, Delta, d, target)
231	}
232	if !testing.Short() && d > target*30/10 {
233		t.Fatalf("%d ticks of %s too slow: took %s, expected %s", Count, Delta, d, target)
234	}
235}
236
237func TestAfterStop(t *testing.T) {
238	AfterFunc(100*Millisecond, func() {})
239	t0 := NewTimer(50 * Millisecond)
240	c1 := make(chan bool, 1)
241	t1 := AfterFunc(150*Millisecond, func() { c1 <- true })
242	c2 := After(200 * Millisecond)
243	if !t0.Stop() {
244		t.Fatalf("failed to stop event 0")
245	}
246	if !t1.Stop() {
247		t.Fatalf("failed to stop event 1")
248	}
249	<-c2
250	select {
251	case <-t0.C:
252		t.Fatalf("event 0 was not stopped")
253	case <-c1:
254		t.Fatalf("event 1 was not stopped")
255	default:
256	}
257	if t1.Stop() {
258		t.Fatalf("Stop returned true twice")
259	}
260}
261
262func TestAfterQueuing(t *testing.T) {
263	// This test flakes out on some systems,
264	// so we'll try it a few times before declaring it a failure.
265	const attempts = 5
266	err := errors.New("!=nil")
267	for i := 0; i < attempts && err != nil; i++ {
268		delta := Duration(20+i*50) * Millisecond
269		if err = testAfterQueuing(delta); err != nil {
270			t.Logf("attempt %v failed: %v", i, err)
271		}
272	}
273	if err != nil {
274		t.Fatal(err)
275	}
276}
277
278// For gccgo omit 0 for now because it can take too long to start the
279var slots = []int{5, 3, 6, 6, 6, 1, 1, 2, 7, 9, 4, 8 /*0*/}
280
281type afterResult struct {
282	slot int
283	t    Time
284}
285
286func await(slot int, result chan<- afterResult, ac <-chan Time) {
287	result <- afterResult{slot, <-ac}
288}
289
290func testAfterQueuing(delta Duration) error {
291	// make the result channel buffered because we don't want
292	// to depend on channel queueing semantics that might
293	// possibly change in the future.
294	result := make(chan afterResult, len(slots))
295
296	t0 := Now()
297	for _, slot := range slots {
298		go await(slot, result, After(Duration(slot)*delta))
299	}
300	var order []int
301	var times []Time
302	for range slots {
303		r := <-result
304		order = append(order, r.slot)
305		times = append(times, r.t)
306	}
307	for i := range order {
308		if i > 0 && order[i] < order[i-1] {
309			return fmt.Errorf("After calls returned out of order: %v", order)
310		}
311	}
312	for i, t := range times {
313		dt := t.Sub(t0)
314		target := Duration(order[i]) * delta
315		if dt < target-delta/2 || dt > target+delta*10 {
316			return fmt.Errorf("After(%s) arrived at %s, expected [%s,%s]", target, dt, target-delta/2, target+delta*10)
317		}
318	}
319	return nil
320}
321
322func TestTimerStopStress(t *testing.T) {
323	if testing.Short() {
324		return
325	}
326	for i := 0; i < 100; i++ {
327		go func(i int) {
328			timer := AfterFunc(2*Second, func() {
329				t.Fatalf("timer %d was not stopped", i)
330			})
331			Sleep(1 * Second)
332			timer.Stop()
333		}(i)
334	}
335	Sleep(3 * Second)
336}
337
338func TestSleepZeroDeadlock(t *testing.T) {
339	// Sleep(0) used to hang, the sequence of events was as follows.
340	// Sleep(0) sets G's status to Gwaiting, but then immediately returns leaving the status.
341	// Then the goroutine calls e.g. new and falls down into the scheduler due to pending GC.
342	// After the GC nobody wakes up the goroutine from Gwaiting status.
343	defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(4))
344	c := make(chan bool)
345	go func() {
346		for i := 0; i < 100; i++ {
347			runtime.GC()
348		}
349		c <- true
350	}()
351	for i := 0; i < 100; i++ {
352		Sleep(0)
353		tmp := make(chan bool, 1)
354		tmp <- true
355		<-tmp
356	}
357	<-c
358}
359
360func testReset(d Duration) error {
361	t0 := NewTimer(2 * d)
362	Sleep(d)
363	if t0.Reset(3*d) != true {
364		return errors.New("resetting unfired timer returned false")
365	}
366	Sleep(2 * d)
367	select {
368	case <-t0.C:
369		return errors.New("timer fired early")
370	default:
371	}
372	Sleep(2 * d)
373	select {
374	case <-t0.C:
375	default:
376		return errors.New("reset timer did not fire")
377	}
378
379	if t0.Reset(50*Millisecond) != false {
380		return errors.New("resetting expired timer returned true")
381	}
382	return nil
383}
384
385func TestReset(t *testing.T) {
386	// We try to run this test with increasingly larger multiples
387	// until one works so slow, loaded hardware isn't as flaky,
388	// but without slowing down fast machines unnecessarily.
389	const unit = 25 * Millisecond
390	tries := []Duration{
391		1 * unit,
392		3 * unit,
393		7 * unit,
394		15 * unit,
395	}
396	var err error
397	for _, d := range tries {
398		err = testReset(d)
399		if err == nil {
400			t.Logf("passed using duration %v", d)
401			return
402		}
403	}
404	t.Error(err)
405}
406
407// Test that sleeping for an interval so large it overflows does not
408// result in a short sleep duration.
409func TestOverflowSleep(t *testing.T) {
410	const big = Duration(int64(1<<63 - 1))
411	select {
412	case <-After(big):
413		t.Fatalf("big timeout fired")
414	case <-After(25 * Millisecond):
415		// OK
416	}
417	const neg = Duration(-1 << 63)
418	select {
419	case <-After(neg):
420		// OK
421	case <-After(1 * Second):
422		t.Fatalf("negative timeout didn't fire")
423	}
424}
425
426// Test that a panic while deleting a timer does not leave
427// the timers mutex held, deadlocking a ticker.Stop in a defer.
428func TestIssue5745(t *testing.T) {
429	if runtime.GOOS == "darwin" && runtime.GOARCH == "arm" {
430		t.Skipf("skipping on %s/%s, see issue 10043", runtime.GOOS, runtime.GOARCH)
431	}
432
433	ticker := NewTicker(Hour)
434	defer func() {
435		// would deadlock here before the fix due to
436		// lock taken before the segfault.
437		ticker.Stop()
438
439		if r := recover(); r == nil {
440			t.Error("Expected panic, but none happened.")
441		}
442	}()
443
444	// cause a panic due to a segfault
445	var timer *Timer
446	timer.Stop()
447	t.Error("Should be unreachable.")
448}
449
450func TestOverflowRuntimeTimer(t *testing.T) {
451	if testing.Short() {
452		t.Skip("skipping in short mode, see issue 6874")
453	}
454	// This may hang forever if timers are broken. See comment near
455	// the end of CheckRuntimeTimerOverflow in internal_test.go.
456	CheckRuntimeTimerOverflow()
457}
458
459func checkZeroPanicString(t *testing.T) {
460	e := recover()
461	s, _ := e.(string)
462	if want := "called on uninitialized Timer"; !strings.Contains(s, want) {
463		t.Errorf("panic = %v; want substring %q", e, want)
464	}
465}
466
467func TestZeroTimerResetPanics(t *testing.T) {
468	defer checkZeroPanicString(t)
469	var tr Timer
470	tr.Reset(1)
471}
472
473func TestZeroTimerStopPanics(t *testing.T) {
474	defer checkZeroPanicString(t)
475	var tr Timer
476	tr.Stop()
477}
478