Understanding race condition in Go

I have the following very simple code:

for i := 0; i < 100; i++ {
    tt := time.AfterFunc(10*time.Microsecond, func() { log.Fatal("bleh!") })
    time.Sleep(2 * time.Microsecond)
    tt.Stop()
}

Now, it should seem that it would do nothing, and when I run it on the Go playground, it just quietly exits as expected, but when I run this on my Macbook, I invariably get errors, like:

go run example.go
2017/03/02 22:21:50 bleh!
2017/03/02 22:21:50 bleh!
exit status 1

And I can put that time on the AfterFunc quite high indeed, even as high as 50 or 100 μs and I'll still get the occasional "bleh!" and death. What are the guarantees around time.Sleep in Go? And what is a better way of testing that something ran within a specific amount of time?

The guarantee is that time.Sleep(2 * time.Microsecond) will sleep for at least 2 microseconds, and time.AfterFunc(10 * time.Microsecond, ...) will call its callback after at least 10 microseconds. No upper limit is guaranteed (the underlying operating system could do anything it wants), and no relative ordering is guaranteed — if the sleep happens to take more than 10 microseconds, then the AfterFunc could end up before or after it.

If you used reasonably long periods of time then it's very likely that you would observe things happening in the right order, because the Sleeping goroutine would get scheduled before the timer expired. But a microsecond is a very short period of time, and so, unscientifically speaking, deadlines that happen within microseconds of each other are very likely to happen in whatever order they feel like.

The playground uses a modified runtime that fakes time, which incidentally is the best approach for testing as well. Modifying the runtime isn't really practical for most, but you might try the clockwork package which provides an interface to both real and fake clock objects. Otherwise, follow the same approach yourself — if you want something to be testable, it can't depend on time, because time is global and irreproducible. Instead, it has to get its notifications from some component that uses time in production, but is replaceable for testing.

func Sleep

> Sleep pauses the current goroutine for at least the duration d. A negative or zero duration causes Sleep to return immediately.

The most significant here is that "at least". It means Sleep could take more time than a passed value. This behavior is dependent from a current state of os.

for i := 0; i < 100; i++ {
    tt := time.AfterFunc(
        10*time.Microsecond,
        func() {log.Fatal("bleh!") }) // has time to be executed
    time.Sleep(2 * time.Microsecond) // Slept more than 10 microsecond
    tt.Stop()
}