go: runtime: time.Sleep problem on Windows 10, but not Windows 7 or Linux
What version of Go are you using (go version
)?
go version go1.20.5 windows/amd64 - “new” go version go1.15.13 windows/amd64 - “old”
Does this issue reproduce with the latest release?
Yes
What operating system and processor architecture are you using (go env
)?
windows_amd64 - Windows 10 Pro, 22H2, Build 19045.2965 windows_amd64 - Windows 7 Ultimate, 6.1.7601, Service Pack 1, Build 7601
What did you do?
package main
import (
"fmt"
"time"
)
func main() {
fmt.Println()
fmt.Println("Time Resolution")
for i := 0; i < 10; i++ {
fmt.Printf(" %v\n", timeDiff())
}
fmt.Println()
fmt.Println("Sleep Resolution")
time.Sleep(1) // sync with the sleep timer
for i := 0; i < 10; i++ {
fmt.Printf(" %v\n", sleepDiff())
}
}
func timeDiff() time.Duration {
t0 := time.Now()
for {
t := time.Now()
if t != t0 {
return t.Sub(t0)
}
}
}
func sleepDiff() time.Duration {
t0 := time.Now()
time.Sleep(1)
return time.Now().Sub(t0)
}
What did you expect to see?
Results using Go v1.15.13 or v1.20.5 code on Windows 7. Time Resolution is fine. Sleep Resolution is fine.
Time Resolution
1.0001ms
1ms
1.0001ms
1ms
1.0001ms
1ms
1.0001ms
1.0001ms
1ms
1.0001ms
Sleep Resolution
1ms
1.0001ms
1.0001ms
1ms
1.0001ms
1ms
1.0001ms
1ms
1.0001ms
1.0001ms
What did you see instead?
Results using Go v1.20.5 code on Windows 10. Time Resolution is fine. Sleep Resolution is bad. It should be ~1ms.
Time Resolution
509.5µs
555.1µs
587.7µs
95.9µs
585.7µs
585.4µs
596.7µs
514.4µs
514.4µs
514.1µs
Sleep Resolution
15.2307ms
34.8µs
13.9486ms
14.8512ms
15.1862ms
15.0722ms
15.7843ms
15.6718ms
898.4µs
14.525ms
Results using Go v1.15.13 code on Windows 10. Time Resolution is ok. Sleep Resolution is ok. Neither are as good as when run on Windows 7, but they are certainly usable.
Time Resolution
1.0394ms
1.0505ms
918.6µs
1.022ms
997.7µs
1.0016ms
1.0788ms
986.7µs
1.0057ms
993.9µs
Sleep Resolution
1.0853ms
1.1475ms
1.1202ms
995.8µs
1.211ms
1.2033ms
1.2386ms
1.2209ms
1.0501ms
1.1822ms
=== Comments
Comments:
A problem I was having with a program I was working on led me to this issue. So yes, it makes a difference in the real world.
I don’t have a Windows 11 PC. It would be interesting to see if it has the problem or not.
The “new” code was built on the Windows 10 PC. The “old” code was build on the Windows 7 PC.
Both Windows PC clocks were running at 1ms due to other software on them. This was verified using TimerTool.exe. But this is moot, since the very first Sleep should have caused Go’s auto-clock-switch to force it to 1ms and keep it there till 50ms after the last Sleep.
The Windows 10 PC is about 5 times faster than the much older Windows 7 PC. Yet the results from the older PC are much “cleaner” (less latency error).
The “new” (I didn’t try old) code was fine on both a Linux server and Raspberry Pi 4.
About this issue
- Original URL
- State: closed
- Created a year ago
- Comments: 27 (12 by maintainers)
is this #44343 ?
@ChrisHines
No response. What’s the procedure for a proposal?
Thanks.
I agree this looks like a duplicate of #44343 to me.
@johnrs If you haven’t seen them yet, these two comments from that issue should give enough information to understand what change caused the regression starting with Go 1.16 and a lot of detail about how the runtime timers are interacting with Windows at the moment:
I don’t understand one of your points from above, though:
What I don’t understand is when you are seeing sleeps shorter than the requested duration. I invested quite a lot of time understanding how the runtime timers code works a few years ago and I can’t think of any way for that to actually happen. As I noted in https://github.com/golang/go/issues/44343#issuecomment-781065368 I’ve actually seen the linux kernal wakeup earlier than Go asked it to, but the Go runtime knew it was too early and just went to sleep again.
I don’t see any examples of “short sleeps” in the example you gave in the top post. All the calls to
time.Sleep(1)
in the code request a 1ns sleep. So right away the only possible shorter value Go could report is 0ns, becausetime.Duration
has a 1ns resolution. The shortest wakeup time in the shown results is 34.8µs, which is certainly >= 1ns.If I understand right, you are suggesting that sometimes a call like
time.Sleep(20 * time.Millisecond)
will return andtime.Since(start)
would report a time less than 20ms. I don’t think that will ever happen in normal operation. Here’s a very simple explanation of how it works:time.Sleep
queues a runtime timer that records the target wakeup time.That’s an extreme simplification, but it highlights the fact that
time.Sleep
should not return until the clock has advanced past its scheduled wake up time as calculated when the call was made.I suspect they are the same issue (especially given the Go version ranges). Could you elaborate on which of the symptoms are different? Thanks.
Also, if you’re so inclined, it should be straightforward to identify if it’s the same issue by trying https://github.com/golang/go/commit/8fdc79e18a9704185bd6471b592db1e8004bd993 and the commit before.