Sleep in golang causes a tenfold difference in time interval

Question

I was doing pressure testing in my project and found a large gap in the time interval due to time.Sleep, which I abstracted to the following code: code 1:

func TestSleep(t *testing.T) {
    for i := 0; i < 8; i++ {
        //time.Sleep(time.Second)
        t1 := time.Now()
        fmt.Println( time.Since(t1))
    }
}

output:

229ns
37ns
36ns
37ns
36ns
38ns
37ns
39ns

code 2(add time.Sleep):

func TestSleep(t *testing.T) {
    for i := 0; i < 8; i++ {
        time.Sleep(time.Second)
        t1 := time.Now()
        fmt.Println( time.Since(t1))
    }
}

471ns
267ns
855ns
484ns
359ns
296ns
324ns
302ns

I have two questions:

Why is there such a big difference between the two results (only the time.Sleep difference)?
Why is the first output in code1 much larger than the next?

`time.Sleep` effects how the goroutine is scheduled, which is obviously having a slight impact on a subsequent calls. `Sleep` is only guaranteed to sleep for _at least_ the given duration so there is no issue here, but to know for sure you will have to look into the specific implementation you are using. — JimB, Nov 04 '21 at 13:39
@JimB Thanks for the reply, I was wondering why time.sleep would have an effect on the code that follows. — helios, Nov 04 '21 at 13:52
Go isn't written to be a hard-realtime language, so runtime scheduling is always going to effect timing within goroutines. You just happen to be specifically forcing it here, but if you make the sleep very short (e.g. 1 microsecond) it may prevent the goroutine from being parked and not have the same effect. The reason the vert first output is longer is the same reason the sleep outputs are longer, because that's the amount of time it took. — JimB, Nov 04 '21 at 14:06

score 1 · Answer 1 · answered Nov 09 '21 at 07:10

As mentioned in "Behavior of sleep and select in go" by mna,

time.Sleep is actually defined in the runtime:

Which in retrospect makes a lot of sense, as it has to interact with the goroutine scheduler.

It ends up calling goparkunlock, which "puts the goroutine into a waiting state".

time.Sleep creates a runtime.timer with a callback function that is called when the timer expires - that callback function wakes up the goroutine by calling goready. See next section for more details on the runtime.timer.

You can see more about parking in "Go: g0, Special Goroutine" from Vincent Blanchon

The goroutine receiving the message will switch to g0 and unlock the parked goroutine by putting it on the local queue:

All those operation takes time, as JimB commented.

Sleep in golang causes a tenfold difference in time interval

1 Answers1