Race conditions in fakeTicker

[pcman312]

TL;DR

I discovered a rather nasty little race condition (technically several) in the fakeTicker. It's in the fakeTicker.tick() function and how it references the fake clock.

Steps to reproduce

1. Create fake clock
2. Create fake ticker from fake clock
3. Advance clock so a tick should fire
4. Attempt to pull off of the ticker channel - sometimes doesn't get a tick on the channel

Test to reproduce:

This fails pretty much every time I run this, but you can also throw this in a for loop to test it a bunch of times and you'll be pretty much guaranteed to reproduce it.

func TestFakeTicker_Race(t *testing.T) {
    fc := NewFakeClock()

    tickTime := 1 * time.Millisecond
    ticker := fc.NewTicker(tickTime)
    defer ticker.Stop()

    fc.Advance(tickTime)

    timeout := time.NewTimer(500 * time.Millisecond)
    defer timeout.Stop()

    select {
    case <-ticker.Chan():
        // Pass
    case <-timeout.C:
        t.Fatalf("Ticker didn't detect the clock advance!")
    }
}

Races

I've found two races so far. Both of them are basically the same, just in two different places.

Race 1

The very first thing the tick function does is retrieve the current time from the fake clock for use in the service loop. Unfortunately, when this is actually executed depends on when the ticker goroutine is run by the scheduler. In the test code above, this order of operations can happen:

1. Test thread - Create ticker
2. Test thread - Ticker spawns goroutine, but scheduler hasn't scheduled it yet
3. Test thread - Advances the clock past the tick point
4. Ticker thread - Grabs the current time from the fake clock which has already been advanced. The ticker then does not fire a tick as the clock has not advanced past when it should

This race can be solved by passing in the "now" timestamp to the function when the goroutine starts. A simple two line fix to change fakeTicker.tick to take in tick time.Time and update the fakeClock.NewTicker to call go ft.tick(fc.Now()).

Race 2

During the service loop in fakeTicker.tick the remaining time is calculated based off of a call to ft.clock.Now(). Later on in the loop, ft.clock.After(remaining) is called. Unfortunately, the clock can be advanced between those two calls resulting in a lost tick:

1. Test thread - Create ticker (let's say the duration is 5ms)
2. Test thread - Ticker spawns goroutine
3. Ticker thread - Executes until remaining := tick.Sub(ft.clock.Now()) is called (remaining = 5ms because the clock hasn't advanced yet)
4. Test thread - Advances clock 5ms
5. Ticker thread - remaining is greater than 0, so it doesn't fire a tick. It then falls through to the second select and ultimately calls ft.clock.After(5ms) even though the clock has already advanced to 5ms.

[vgough]

Looks like a simple initialization race. I've fixed it in my branch. Thanks for the test case.