code review 140110043: runtime/pprof: adjust cpuHogger so that tests pass on w...

runtime/pprof: adjust cpuHogger so that tests pass on windows builders

[brainman, 2014-09-01 11:36:17]

Hello dvyukov@google.com (cc: golang-codereviews@googlegroups.com),

I'd like you to review this change to
https://go.googlecode.com/hg/

[dvyukov, 2014-09-01 14:25:14]

Freebsd-race is still not happy as well:

--- FAIL: TestCPUProfileMultithreaded (0.51s)
	pprof_test.go:165: runtime/pprof_test.cpuHog1: 10
	pprof_test.go:165: runtime/pprof_test.cpuHog2: 0
	pprof_test.go:179: runtime/pprof_test.cpuHog2 has 0 samples out of 10, want at
least 1, ideally 5

http://build.golang.org/log/2947dc2a9f94a860fd757e6caeb3d98154c746be

[dvyukov, 2014-09-01 14:26:36]

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
File src/pkg/runtime/pprof/pprof_test.go (right):

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
src/pkg/runtime/pprof/pprof_test.go:29: // thread is scheduled during the 1000ms
period.
s/1000ms/1 second/

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
src/pkg/runtime/pprof/pprof_test.go:31: for i := 0; i < 2000 || time.Since(t0) <
1000*time.Millisecond; i++ {
s/1000*time.Millisecond/time.Second/

[dvyukov, 2014-09-01 14:28:04]

This test will now run for 2 seconds, which is long for short tests.
Can you sync back to a3136bee82dd9e7b1619c8252af8f847167fba78 (before my change)
and check how long the test was running then? Post a typical -v output. Maybe it
was running for 2 seconds before as well..

[brainman, 2014-09-02 00:42:47]

> This test will now run for 2 seconds, which is long for short tests.

I doubled current value to make windows-amd64 builder pass. I had to double that
again for windows-386 builder.

> Can you sync back to a3136bee82dd9e7b1619c8252af8f847167fba78 (before my
> change) and check how long the test was running then? Post a typical -v
> output. Maybe it was running for 2 seconds before as well..

I did this

hg up -r a3136bee82dd
go test runtime/pprof -v -short

my windows-386 pc:

=== RUN TestCPUProfile
--- PASS: TestCPUProfile (0.33s)
        pprof_test.go:136: crc32.ChecksumIEEE: 30
=== RUN TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (0.66s)
        pprof_test.go:136: crc32.ChecksumIEEE: 61
        pprof_test.go:136: crc32.Update: 61
=== RUN TestCPUProfileWithFork
--- PASS: TestCPUProfileWithFork (0.53s)
=== RUN TestGoroutineSwitch
--- PASS: TestGoroutineSwitch (0.23s)
=== RUN TestMathBigDivide
--- PASS: TestMathBigDivide (5.00s)
=== RUN TestBlockProfile
--- PASS: TestBlockProfile (0.19s)
PASS
ok      runtime/pprof   7.000s

my windows-amd64 pc:

=== RUN TestCPUProfile
--- PASS: TestCPUProfile (0.44s)
        pprof_test.go:136: crc32.ChecksumIEEE: 38
=== RUN TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (1.74s)
        pprof_test.go:136: crc32.ChecksumIEEE: 30
        pprof_test.go:136: crc32.Update: 34
=== RUN TestCPUProfileWithFork
--- PASS: TestCPUProfileWithFork (0.54s)
=== RUN TestGoroutineSwitch
--- PASS: TestGoroutineSwitch (0.18s)
=== RUN TestMathBigDivide
--- PASS: TestMathBigDivide (5.47s)
=== RUN TestBlockProfile
--- PASS: TestBlockProfile (0.18s)
PASS
ok      runtime/pprof   8.746s

our windows-386 builder

=== RUN TestCPUProfile
--- PASS: TestCPUProfile (1.00s)
        pprof_test.go:136: crc32.ChecksumIEEE: 4
=== RUN TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (4.38s)
        pprof_test.go:136: crc32.ChecksumIEEE: 18
        pprof_test.go:136: crc32.Update: 33
=== RUN TestCPUProfileWithFork
--- PASS: TestCPUProfileWithFork (1.08s)
=== RUN TestGoroutineSwitch
--- PASS: TestGoroutineSwitch (0.45s)
=== RUN TestMathBigDivide
--- PASS: TestMathBigDivide (5.29s)
=== RUN TestBlockProfile
--- PASS: TestBlockProfile (0.17s)
PASS
ok      runtime/pprof   12.516s

our windows-amd64 builder

=== RUN TestCPUProfile
--- PASS: TestCPUProfile (0.46s)
        pprof_test.go:136: crc32.ChecksumIEEE: 7
=== RUN TestCPUProfileMultithreaded
--- PASS: TestCPUProfileMultithreaded (1.83s)
        pprof_test.go:136: crc32.ChecksumIEEE: 25
        pprof_test.go:136: crc32.Update: 55
=== RUN TestCPUProfileWithFork
--- PASS: TestCPUProfileWithFork (0.54s)
=== RUN TestGoroutineSwitch
--- PASS: TestGoroutineSwitch (0.30s)
=== RUN TestMathBigDivide
--- PASS: TestMathBigDivide (5.68s)
=== RUN TestBlockProfile
--- PASS: TestBlockProfile (0.18s)
PASS
ok      runtime/pprof   9.224s

Alex

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
File src/pkg/runtime/pprof/pprof_test.go (right):

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
src/pkg/runtime/pprof/pprof_test.go:29: // thread is scheduled during the 1000ms
period.
On 2014/09/01 14:26:36, dvyukov wrote:
> s/1000ms/1 second/

Done.

https://codereview.appspot.com/140110043/diff/40001/src/pkg/runtime/pprof/ppr...
src/pkg/runtime/pprof/pprof_test.go:31: for i := 0; i < 2000 || time.Since(t0) <
1000*time.Millisecond; i++ {
On 2014/09/01 14:26:36, dvyukov wrote:
> s/1000*time.Millisecond/time.Second/

Done.

[brainman, 2014-09-02 00:43:01]

Hello dvyukov@google.com (cc: golang-codereviews@googlegroups.com),

Please take another look.

[rsc, 2014-09-02 03:04:57]

LGTM but

I think there is something we don't understand about thread scheduling on
windows. If we have two runnable threads, how is it that one might run for a
full second before the other gets a chance?

[rsc, 2014-09-02 03:06:24]

*** Submitted as https://code.google.com/p/go/source/detail?r=17b5fc2aa130 ***

runtime/pprof: adjust cpuHogger so that tests pass on windows builders

LGTM=rsc
R=dvyukov, rsc
CC=golang-codereviews
https://codereview.appspot.com/140110043

Committer: Russ Cox <rsc@golang.org>

[brainman, 2014-09-03 02:46:33]

On 2014/09/02 03:04:57, rsc wrote:
> 
> I think there is something we don't understand about thread scheduling on
> windows. If we have two runnable threads, how is it that one might run for a
> full second before the other gets a chance?

I did some investigations on our builders. I think the reason for failure is
simple enough. See CLs 133500043 and 134360043 for details.

Alex