runtime/pprof: TestCPUProfileMultithreaded has too few samples on Windows

[bradfitz]

Random test failure:

windows-amd64-gce at 5c7f944
http://build.golang.org/log/135576b3d6ecdc234707e6e75b2829b9c6ea5bef

--- FAIL: TestCPUProfileMultithreaded (0.44s)
    pprof_test.go:164: total 4 CPU profile samples collected
    pprof_test.go:173: runtime/pprof_test.cpuHog1: 2
    pprof_test.go:173: runtime/pprof_test.cpuHog2: 0
    pprof_test.go:187: runtime/pprof_test.cpuHog2 has 0 samples out of 2, want at least 1, ideally 1
FAIL
FAIL    runtime/pprof   8.433s

No flaky tests are tolerated. Let's deflake or delete.

/cc @alexbrainman @dvyukov @minux

[rsc]

The bigger problem here is that there were only 4 CPU samples collected in 0.44 seconds. That sounds like the sampling is doing 10 Hz instead of 100 Hz.

[alexbrainman]

... That sounds like the sampling is doing 10 Hz instead of 100 Hz.

I suspect it is all what schedule does. Ours together with Windows scheduler. It varies between different environments - how many CPUs you have, whether you're running in VM or not.

My windows xp 386 2*CPU:

C:\>go test -v -run=TestCPUProfileMultithreaded runtime/pprof
=== RUN   TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (0.27s)
        pprof_test.go:165: total 48 CPU profile samples collected
        pprof_test.go:174: runtime/pprof_test.cpuHog1: 24
        pprof_test.go:174: runtime/pprof_test.cpuHog2: 24
PASS
ok      runtime/pprof   0.453s

Another vm windows 7 amd64 1*CPU:

c:\>go test -v -run=TestCPUProfileMultithreaded runtime/pprof
=== RUN   TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (0.35s)
        pprof_test.go:165: total 27 CPU profile samples collected
        pprof_test.go:174: runtime/pprof_test.cpuHog1: 16
        pprof_test.go:174: runtime/pprof_test.cpuHog2: 10
PASS
ok      runtime/pprof   0.395s

As far as I remember, I have seen numbers vary if your PC is busy doing other staff.

It has been a while since I have seen this issue on our builders.

Alex

[dvyukov]

Maybe timeBeginPeriod call failed in os1_windows.go? That would give 15ms timer precision instead of 1ms.

[gopherbot]

CL https://golang.org/cl/12529 mentions this issue.

[alexbrainman]

Maybe timeBeginPeriod call failed in os1_windows.go?

No, it didn't - https://go-review.googlesource.com/#/c/12546/

Alex