Sleep in golang causes a tenfold difference in time interval

user_6117189 0
Viewed 349

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:

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

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:

https://miro.medium.com/max/633/1*UbwdgTQ2sgQIVVMDiM-qvg.png

All those operation takes time, as JimB commented.

VonC_63090
Related