Why does a very short time.Sleep take longer than the requested (about 300 ns) in benchmarks?

Question

I'm playing around with benchmarks in Go and I have a simple function that just sleeps for 5 Nanoseconds, however when I run a benchmark test it shows 298.1 ns/op. I'm curious why is that. Shouldn't it be 5 ns/op?

Go version:

go version go1.19 linux/amd64

The code:

package andrei

import (
    "testing"
    "time"
)

func Hi() {
    time.Sleep(5 * time.Nanosecond)
}

func BenchmarkHi(b *testing.B) {
    for i := 0; i < b.N; i++ {
        Hi()
    }
}

The results:

$ go test -run none -bench  . -benchmem ./andrei

goos: linux
goarch: amd64
pkg: andrei/andrei
cpu: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz
BenchmarkHi-8            3861392               298.1 ns/op             0 B/op          0 allocs/op
PASS
ok      andrei/andrei   1.470s

Ask yourself: How many clock cycles of your CPU correspond to 5ns? How would you measure 5ns? — Volker, Sep 02 '22 at 06:47
@Volker: Fortunately this benchmark isn't trying to *measure* each sleep separately, but yeah it is trying to sleep for very short times. `rdtsc` throughput on Ice Lake / Tiger Lake is about 27 cycles (https://uops.info/), so that's about one per 5.7 ns at max turbo 4.7 GHz. But you can be sure that separate `time.Sleep` calls will need to do more than just check the current time-stamp counter once! — Peter Cordes, Sep 02 '22 at 12:40
Tiger Lake doesn't have the WAITPKG extension for `tpause` to pause the CPU until a short deadline; that was new in Tremont and Alder Lake. And even that would need rdtsc + tpause, after checking that the sleep was too short to make a system call to let it schedule another task until we're ready to wake up. Anyway yeah, trying to sleep or delay for about 20 clock cycles isn't something that makes sense in a high-level language; you'd better be writing asm by hand for a known uarch. See also ([How to calculate time for an asm delay loop on x86 linux?](https://stackoverflow.com/q/49924102)) — Peter Cordes, Sep 02 '22 at 12:42

score 5 · Accepted Answer · answered Sep 02 '22 at 05:58

time.Sleep only guarantees that it will sleep at least as long as the argument. How long it actually sleeps depends on your operating system and other factors.

On Windows, it sleeps at least 1.9ms. On my MacBook, I get 408 ns/op, and you are seeing 298.1 ns/op.

You can find out more details about this problem in this ticket in the Go github repository:

https://github.com/golang/go/issues/29485

score 4 · Answer 2 · answered Sep 02 '22 at 05:57

The article "How to Write Accurate Benchmarks in Go" (Teiva Harsanyi, Aug. 2022) and the Benchmarks wiki page both mention perflock (on Linux):

We should make sure the machine executing the benchmark is idle. However, external processes may run in the background, which may affect benchmark results.

For that reason, tools such as perflock can limit how much CPU a benchmark can consume.

For example, we can run a benchmark with 70% of the total available CPU, giving 30% to the OS and other processes and reducing the impact of the machine activity factor on the results.

See also "issues 44343: runtime: time.Sleep takes more time than expected".

For Linux, we should use epoll_pwait2, like https://go.dev/cl/363417.
This system call is on the newer side, but this will improve things going forward and provide a workaround (upgrade the kernel) for particularly affected users.

Why does a very short time.Sleep take longer than the requested (about 300 ns) in benchmarks?

2 Answers2