It is a well-known issue: starting from Go 1.16 time.Sleep in MS Windows uses low resolution timer, as bad as 1/64 second. Sleeping for 1 ms in Windows is anything between 1 and 16 ms.
Try printing microsecond timestamps:
package main
import (
"fmt"
"time"
)
func count() {
fmt.Println(time.Now().Nanosecond() / 1000)
for i := 0; i < 5; i++ {
fmt.Println(i, time.Now().Nanosecond()/1000)
time.Sleep(time.Millisecond * 1)
}
}
func main() {
// if runtime.GOOS == "windows" {
// initTimer()
// }
ts := time.Now().UnixNano()
fmt.Println("Main started: ", ts, (ts%1_000_000_000)/1000)
go count()
time.Sleep(time.Millisecond * 2)
fmt.Println("Hello World", time.Now().Nanosecond()/1000)
time.Sleep(time.Millisecond * 5)
fmt.Println("Main done", time.Now().Nanosecond()/1000)
}
On my Windows 10:
Main started: 1663345297398120000 398120
398703
0 398703
Hello World 405757
1 405757
2 421481
Main done 421481
The numbers are microseconds. See, how big are the intervals.
To improve timer resolution you can call timeBeginPeriod function.
//go:build windows
// +build windows
package main
import "syscall"
func initTimer() {
winmmDLL := syscall.NewLazyDLL("winmm.dll")
procTimeBeginPeriod := winmmDLL.NewProc("timeBeginPeriod")
procTimeBeginPeriod.Call(uintptr(1))
}
Calling initTimer helps a lot:
Main started: 1663345544132793500 132793
132793
0 133301
Hello World 134854
1 134854
2 136403
3 137964
4 139627
Main done 140696
Still the resolution is not 1 ms, but better than 2 ms.
The full code is here: https://go.dev/play/p/LGPv74cgN_h
Discussion thread in Golang issues: https://github.com/golang/go/issues/44343