go test -timeout=500s is sometimes returning after only 497 seconds. So it seems to be a similar problem. Are there two different timers being used? Perhaps hardware vs. software clocks? Maybe my machine is not synchronized with itself.

Yes, one is monotonic time and one is wall time.

Does this only happen in Qubes for you, which I believe is running your process under Xen?

I've only seen it so far on Qubes, which indeed uses Xen. I also had several AppVMs running at once, which means that they were being switched out. I'm guessing that's the source of the discrepency.

5ms out of 500ms is a 1% error. I would be shocked if monotonic and wall time were that different over a half a second.

Do you have ntpd running in your VM? Or are you using Xen's clock syncing? What is the output of cat /sys/devices/system/clocksource/clocksource0/current_clocksource ?

looks like xen is running as the clock source.

output is xen

This was caused by 86c976f which was done for #6007: the 500ms sleep is monotonic clock ms, and the measured 495ms is wall time ms.

The fact is that if your monotonic and wall clocks don't line up, you're going to be in for trouble one way or another. It used to be one way. Now it's another. I wish we hadn't changed it, but not enough to change it back.

FWIW, I expect this program to work as expected now if built with Go's master branch, after the fix for #12914 that landed today. Both the time.After and the time.Now().Sub(start) shold be using the same clock, and they should both report 500ms. If you were to subtract t.UnixNano() or something like that, you'd still see 495ms, but I expect that is an accurate reflection of xen turning your clock back.