libgo/go/time/sleep_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         "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.
  24 const windowsInaccuracy = 17 * Millisecond
  25
  26 func 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.
  47 func 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
  65 func 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
  84 func 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
 118 func 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
 136 func BenchmarkAfter(b *testing.B) {
 137         benchmark(b, func(n int) {
 138                 for i := 0; i < n; i++ {
 139                         <-After(1)
 140                 }
 141         })
 142 }
 143
 144 func 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
 152 func 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
 163 func 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
 176 func 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
 186 func 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
 200 func 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
 216 func 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
 237 func TestAfterStop(t *testing.T) {
 238         // We want to test that we stop a timer before it runs.
 239         // We also want to test that it didn't run after a longer timer.
 240         // Since we don't want the test to run for too long, we don't
 241         // want to use lengthy times. That makes the test inherently flaky.
 242         // So only report an error if it fails five times in a row.
 243
 244         var errs []string
 245         logErrs := func() {
 246                 for _, e := range errs {
 247                         t.Log(e)
 248                 }
 249         }
 250
 251         for i := 0; i < 5; i++ {
 252                 AfterFunc(100*Millisecond, func() {})
 253                 t0 := NewTimer(50 * Millisecond)
 254                 c1 := make(chan bool, 1)
 255                 t1 := AfterFunc(150*Millisecond, func() { c1 <- true })
 256                 c2 := After(200 * Millisecond)
 257                 if !t0.Stop() {
 258                         errs = append(errs, "failed to stop event 0")
 259                         continue
 260                 }
 261                 if !t1.Stop() {
 262                         errs = append(errs, "failed to stop event 1")
 263                         continue
 264                 }
 265                 <-c2
 266                 select {
 267                 case <-t0.C:
 268                         errs = append(errs, "event 0 was not stopped")
 269                         continue
 270                 case <-c1:
 271                         errs = append(errs, "event 1 was not stopped")
 272                         continue
 273                 default:
 274                 }
 275                 if t1.Stop() {
 276                         errs = append(errs, "Stop returned true twice")
 277                         continue
 278                 }
 279
 280                 // Test passed, so all done.
 281                 if len(errs) > 0 {
 282                         t.Logf("saw %d errors, ignoring to avoid flakiness", len(errs))
 283                         logErrs()
 284                 }
 285
 286                 return
 287         }
 288
 289         t.Errorf("saw %d errors", len(errs))
 290         logErrs()
 291 }
 292
 293 func TestAfterQueuing(t *testing.T) {
 294         // This test flakes out on some systems,
 295         // so we'll try it a few times before declaring it a failure.
 296         const attempts = 5
 297         err := errors.New("!=nil")
 298         for i := 0; i < attempts && err != nil; i++ {
 299                 delta := Duration(20+i*50) * Millisecond
 300                 if err = testAfterQueuing(delta); err != nil {
 301                         t.Logf("attempt %v failed: %v", i, err)
 302                 }
 303         }
 304         if err != nil {
 305                 t.Fatal(err)
 306         }
 307 }
 308
 309 // For gccgo omit 0 for now because it can take too long to start the
 310 var slots = []int{5, 3, 6, 6, 6, 1, 1, 2, 7, 9, 4, 8 /*0*/}
 311
 312 type afterResult struct {
 313         slot int
 314         t    Time
 315 }
 316
 317 func await(slot int, result chan<- afterResult, ac <-chan Time) {
 318         result <- afterResult{slot, <-ac}
 319 }
 320
 321 func testAfterQueuing(delta Duration) error {
 322         // make the result channel buffered because we don't want
 323         // to depend on channel queueing semantics that might
 324         // possibly change in the future.
 325         result := make(chan afterResult, len(slots))
 326
 327         t0 := Now()
 328         for _, slot := range slots {
 329                 go await(slot, result, After(Duration(slot)*delta))
 330         }
 331         var order []int
 332         var times []Time
 333         for range slots {
 334                 r := <-result
 335                 order = append(order, r.slot)
 336                 times = append(times, r.t)
 337         }
 338         for i := range order {
 339                 if i > 0 && order[i] < order[i-1] {
 340                         return fmt.Errorf("After calls returned out of order: %v", order)
 341                 }
 342         }
 343         for i, t := range times {
 344                 dt := t.Sub(t0)
 345                 target := Duration(order[i]) * delta
 346                 if dt < target-delta/2 || dt > target+delta*10 {
 347                         return fmt.Errorf("After(%s) arrived at %s, expected [%s,%s]", target, dt, target-delta/2, target+delta*10)
 348                 }
 349         }
 350         return nil
 351 }
 352
 353 func TestTimerStopStress(t *testing.T) {
 354         if testing.Short() {
 355                 return
 356         }
 357         for i := 0; i < 100; i++ {
 358                 go func(i int) {
 359                         timer := AfterFunc(2*Second, func() {
 360                                 t.Fatalf("timer %d was not stopped", i)
 361                         })
 362                         Sleep(1 * Second)
 363                         timer.Stop()
 364                 }(i)
 365         }
 366         Sleep(3 * Second)
 367 }
 368
 369 func TestSleepZeroDeadlock(t *testing.T) {
 370         // Sleep(0) used to hang, the sequence of events was as follows.
 371         // Sleep(0) sets G's status to Gwaiting, but then immediately returns leaving the status.
 372         // Then the goroutine calls e.g. new and falls down into the scheduler due to pending GC.
 373         // After the GC nobody wakes up the goroutine from Gwaiting status.
 374         defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(4))
 375         c := make(chan bool)
 376         go func() {
 377                 for i := 0; i < 100; i++ {
 378                         runtime.GC()
 379                 }
 380                 c <- true
 381         }()
 382         for i := 0; i < 100; i++ {
 383                 Sleep(0)
 384                 tmp := make(chan bool, 1)
 385                 tmp <- true
 386                 <-tmp
 387         }
 388         <-c
 389 }
 390
 391 func testReset(d Duration) error {
 392         t0 := NewTimer(2 * d)
 393         Sleep(d)
 394         if !t0.Reset(3 * d) {
 395                 return errors.New("resetting unfired timer returned false")
 396         }
 397         Sleep(2 * d)
 398         select {
 399         case <-t0.C:
 400                 return errors.New("timer fired early")
 401         default:
 402         }
 403         Sleep(2 * d)
 404         select {
 405         case <-t0.C:
 406         default:
 407                 return errors.New("reset timer did not fire")
 408         }
 409
 410         if t0.Reset(50 * Millisecond) {
 411                 return errors.New("resetting expired timer returned true")
 412         }
 413         return nil
 414 }
 415
 416 func TestReset(t *testing.T) {
 417         // We try to run this test with increasingly larger multiples
 418         // until one works so slow, loaded hardware isn't as flaky,
 419         // but without slowing down fast machines unnecessarily.
 420         const unit = 25 * Millisecond
 421         tries := []Duration{
 422                 1 * unit,
 423                 3 * unit,
 424                 7 * unit,
 425                 15 * unit,
 426         }
 427         var err error
 428         for _, d := range tries {
 429                 err = testReset(d)
 430                 if err == nil {
 431                         t.Logf("passed using duration %v", d)
 432                         return
 433                 }
 434         }
 435         t.Error(err)
 436 }
 437
 438 // Test that sleeping for an interval so large it overflows does not
 439 // result in a short sleep duration.
 440 func TestOverflowSleep(t *testing.T) {
 441         const big = Duration(int64(1<<63 - 1))
 442         select {
 443         case <-After(big):
 444                 t.Fatalf("big timeout fired")
 445         case <-After(25 * Millisecond):
 446                 // OK
 447         }
 448         const neg = Duration(-1 << 63)
 449         select {
 450         case <-After(neg):
 451                 // OK
 452         case <-After(1 * Second):
 453                 t.Fatalf("negative timeout didn't fire")
 454         }
 455 }
 456
 457 // Test that a panic while deleting a timer does not leave
 458 // the timers mutex held, deadlocking a ticker.Stop in a defer.
 459 func TestIssue5745(t *testing.T) {
 460         ticker := NewTicker(Hour)
 461         defer func() {
 462                 // would deadlock here before the fix due to
 463                 // lock taken before the segfault.
 464                 ticker.Stop()
 465
 466                 if r := recover(); r == nil {
 467                         t.Error("Expected panic, but none happened.")
 468                 }
 469         }()
 470
 471         // cause a panic due to a segfault
 472         var timer *Timer
 473         timer.Stop()
 474         t.Error("Should be unreachable.")
 475 }
 476
 477 func TestOverflowRuntimeTimer(t *testing.T) {
 478         if testing.Short() {
 479                 t.Skip("skipping in short mode, see issue 6874")
 480         }
 481         // This may hang forever if timers are broken. See comment near
 482         // the end of CheckRuntimeTimerOverflow in internal_test.go.
 483         CheckRuntimeTimerOverflow()
 484 }
 485
 486 func checkZeroPanicString(t *testing.T) {
 487         e := recover()
 488         s, _ := e.(string)
 489         if want := "called on uninitialized Timer"; !strings.Contains(s, want) {
 490                 t.Errorf("panic = %v; want substring %q", e, want)
 491         }
 492 }
 493
 494 func TestZeroTimerResetPanics(t *testing.T) {
 495         defer checkZeroPanicString(t)
 496         var tr Timer
 497         tr.Reset(1)
 498 }
 499
 500 func TestZeroTimerStopPanics(t *testing.T) {
 501         defer checkZeroPanicString(t)
 502         var tr Timer
 503         tr.Stop()
 504 }