array index not starting at 0

[Leah Stapleton]

go version go1.21.5 windows/amd64

There have been 9 garbage collections according to NumGC and also the PauseEnd array; However, the PauseNs array only shows two pause times, and they are incorrectly positioned in the array (the first time is logged at PauseNs[4] rather than PauseNs[0])

Can anyone provide some information about this. 

Leah

,"PauseTotalNs":1999400,"PauseNs":[0,0,0,0,1000100,999300,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"PauseEnd":[1706534601618276400,1706534601625558600,1706534601643261400,1706534601677238900,1706534601781174700,1706534602022683900,1706534602465533900,1706534603516006900,1706534604837389800,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"NumGC":9,

[Leah Stapleton]

Is it possible that some PauseNs numbers are so small that they're rounded down to 0?

[Michael Knyszek]

I see that you're on Windows. The clock granularity on Windows is really coarse (15 ms) because AFAIK there are no fast fine-grained OS-level clocks available.

There are fine-grained clocks, but they're heavyweight. They're too heavyweight for many situations in the runtime, but honestly, they're probably not too heavyweight in this particular scenario. Alas, the runtime tends to just use the default OS clock it picks (the nanotime function) everywhere, since the granularity is very fine on most other popular platforms.

I suspect that is the cause of all the zeroes. More specifically, the measurement happens entirely within a 15 ms epoch. For this particular measurement, the runtime just uses that coarse OS clock. As an easier workaround, we could probably estimate durations like this from RDTSC like we do for other things, like some profiles on Windows. This is not great for actually measuring timestamps, but it's probably OK (though far from perfect) for durations.

Do you mind filing an issue at https://github.com/golang/go/issues? Thanks.