Repository: go
Issue: runtime/pprof: TestCPUProfileMultithreadMagnitude fail in linux6.2 ubuntu in VirtualBox
Labels: NeedsInvestigation,compiler/runtime

<!--
Please answer these questions before submitting your issue. Thanks!
-->

### What version of Go are you using (`go version`)?

<pre>
$ go version
tip
</pre>

### Does this issue reproduce with the latest release?

yes.

### What operating system and processor architecture are you using (`go env`)?

<details><summary><code>go env</code> Output</summary><br><pre>
$ go env
GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/gocache'
GOENV='/home/qiulaidongfeng/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/gofile/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/gofile'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/home/qiulaidongfeng/.go/current'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/home/qiulaidongfeng/.go/current/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.21.3'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='0'
GOMOD='/dev/null'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build3509559278=/tmp/go-build -gno-record-gcc-switches'
</pre></details>

### What did you do?

In virtualbox

The physical machine is a GOOS=amd64 machine, and the virtual machine is also a GOOS=amd64 machine, both with 16 threads.

Virtual machine 4.5GB memory.

go test runtime/pprof


### What did you expect to see?
Test passed.


### What did you see instead?

<details>
--- FAIL: TestCPUProfileMultithreadMagnitude (322.67s)
    pprof_test.go:120: Running on Linux 6.2
    --- FAIL: TestCPUProfileMultithreadMagnitude/parallel (317.55s)
        pprof_test.go:186: Running with 16 workers
        pprof_test.go:557: total 2064 CPU profile samples collected:
            1547: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            155: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            241: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            23: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46d083 (runtime.futex:558) 0x433a0f (runtime.futexwakeup:82) 0x40c124 (runtime.notewakeup:145) 0x43e088 (runtime.startm:2635) 0x43e56b (runtime.wakep:2746) 0x44025d (runtime.resetspinning:3473) 0x44068e (runtime.schedule:3607) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x414353 (runtime.findObject:344) 0x4200cb (runtime.scanobject:1365) 0x41f999 (runtime.gcDrain:1133) 0x41c2b4 (runtime.gcDrainMarkWorkerDedicated:1027 runtime.gcBgMarkWorker.func2:1391) 0x469449 (runtime.systemstack:509) 0x41be91 (runtime.gcBgMarkWorker:1363) labels: map[]
            
            23: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            40: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            6: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            17: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x47fb44 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x44083b (runtime.checkTimers:3670) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x440ea4 (runtime.gopreempt_m:3795) 0x4693cd (runtime.mcall:458) labels: map[]
            
        pprof_test.go:628: found 2057 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 1m13.387525s user + 5.416163s system = 1m18.803688s vs 20.64s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -73.8%) want nil
        pprof_test.go:494: retrying with 10s duration
        pprof_test.go:557: total 3577 CPU profile samples collected:
            79: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2591: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            257: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            486: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            17: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            7: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            57: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46afa9 (runtime.procyield:780) 0x40bf2c (runtime.lock2:88) 0x440bca (runtime.lockWithRank:24 runtime.lock:48 runtime.goschedImpl:3763) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43ce24 (runtime.forEachP:1824) 0x463fe4 (runtime.gcMarkDone.func1:834) 0x469449 (runtime.systemstack:509) 0x41ab9e (runtime.gcMarkDone:827) 0x41bfe4 (runtime.gcBgMarkWorker:1435) labels: map[]
            
            1: 0x451d70 (runtime.gcComputeStartingStackSize:1321) 0x41acbe (runtime.gcMarkDone:907) 0x41bfe4 (runtime.gcBgMarkWorker:1435) labels: map[]
            
            4: 0x46d057 (runtime.madvise:544) 0x4171f5 (runtime.sysUnusedOS:63) 0x4235ee (runtime.sysUnused:62 runtime.(*pageAlloc).scavengeOne:780) 0x4231ae (runtime.(*pageAlloc).scavenge.func1:683) 0x469449 (runtime.systemstack:509) 0x423104 (runtime.(*pageAlloc).scavenge:682) 0x463c87 (runtime.(*scavengerState).init.func2:395) 0x422e6f (runtime.(*scavengerState).run:602) 0x422fe7 (runtime.bgscavenge:656) labels: map[]
            
            39: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            25: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            4: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x55a32a (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x458a01 (runtime.nanotime:18) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x47fb44 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
        pprof_test.go:628: found 3564 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 2m20.54274s user + 17.627246s system = 2m38.169986s vs 35.77s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -77.4%) want nil
        pprof_test.go:494: retrying with 20s duration
        pprof_test.go:557: total 7173 CPU profile samples collected:
            5278: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43c349 (runtime.stopTheWorldWithSema:1369) 0x464157 (runtime.gcStart.func1:681) 0x469449 (runtime.systemstack:509) 0x41a744 (runtime.gcStart:681) 0x40dbd6 (runtime.mallocgc:1240) 0x40de04 (runtime.newobject:1322) 0x52468d (compress/gzip.NewWriterLevel:64) 0x550905 (runtime/pprof.newProfileBuilder:260) 0x54d264 (runtime/pprof.profileWriter:806) labels: map[]
            
            922: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x427004 (runtime.getempty:352) 0x42472f (runtime.(*stackScanState).putPtr:213) 0x420304 (runtime.scanConservative:1447) 0x41f6dd (runtime.scanframeworker:941) 0x41f086 (runtime.scanstack:803) 0x41df14 (runtime.markroot.func1:240) 0x41dba7 (runtime.markroot:214) 0x41fb5c (runtime.gcDrain:1099) 0x41c204 (runtime.gcDrainMarkWorkerDedicated:1027 runtime.gcBgMarkWorker.func2:1376) 0x469449 (runtime.systemstack:509) 0x41be91 (runtime.gcBgMarkWorker:1363) labels: map[]
            
            4: 0x46d057 (runtime.madvise:544) 0x4171f5 (runtime.sysUnusedOS:63) 0x4235ee (runtime.sysUnused:62 runtime.(*pageAlloc).scavengeOne:780) 0x4231ae (runtime.(*pageAlloc).scavenge.func1:683) 0x469449 (runtime.systemstack:509) 0x423104 (runtime.(*pageAlloc).scavenge:682) 0x463c87 (runtime.(*scavengerState).init.func2:395) 0x422e6f (runtime.(*scavengerState).run:602) 0x422fe7 (runtime.bgscavenge:656) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43cce4 (runtime.forEachP:1778) 0x463fe4 (runtime.gcMarkDone.func1:834) 0x469449 (runtime.systemstack:509) 0x41ab9e (runtime.gcMarkDone:827) 0x41bfe4 (runtime.gcBgMarkWorker:1435) labels: map[]
            
            90: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            538: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            156: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            32: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            50: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            62: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            7: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x4510e3 (runtime.newstack:1044) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            6: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            9: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x440ea4 (runtime.gopreempt_m:3795) 0x45116a (runtime.newstack:1070) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46d081 (runtime.futex:557) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            4: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46cc16 (runtime.nanotime1:239) labels: map[]
            
            1: 0x469545 (runtime.morestack_noctxt:600) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x440eb5 (runtime.gopreempt_m:3796) 0x45116a (runtime.newstack:1070) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x446664 (runtime.pidlegetSpinning:6165) 0x43e4e4 (runtime.wakep:2731) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x411a94 (runtime.mapaccess1_fast64:29) 0x548a8f (runtime/pprof.(*profMap).lookup:41) 0x550c07 (runtime/pprof.(*profileBuilder).addCPUData:338) 0x54d2c4 (runtime/pprof.profileWriter:811) labels: map[]
            
            1: 0x46c700 (runtime.asyncPreempt:8) 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43ea0b (runtime.execute:2836) 0x4407bb (runtime.schedule:3639) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
        pprof_test.go:628: found 7151 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 4m41.461315s user + 35.227014s system = 5m16.688329s vs 1m11.73s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -77.3%) want nil
        pprof_test.go:494: retrying with 40s duration
        pprof_test.go:557: total 13951 CPU profile samples collected:
            10248: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1787: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            107: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46d057 (runtime.madvise:544) 0x4171f5 (runtime.sysUnusedOS:63) 0x4235ee (runtime.sysUnused:62 runtime.(*pageAlloc).scavengeOne:780) 0x4231ae (runtime.(*pageAlloc).scavenge.func1:683) 0x469449 (runtime.systemstack:509) 0x423104 (runtime.(*pageAlloc).scavenge:682) 0x463c87 (runtime.(*scavengerState).init.func2:395) 0x422e6f (runtime.(*scavengerState).run:602) 0x422fe7 (runtime.bgscavenge:656) labels: map[]
            
            1063: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            197: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            14: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43c349 (runtime.stopTheWorldWithSema:1369) 0x4640b7 (runtime.gcMarkDone.func2:872) 0x469449 (runtime.systemstack:509) 0x41ac39 (runtime.gcMarkDone:872) 0x41bfe4 (runtime.gcBgMarkWorker:1435) labels: map[]
            
            51: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            320: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x40beb7 (runtime.lock2:61) 0x440bca (runtime.lockWithRank:24 runtime.lock:48 runtime.goschedImpl:3763) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            96: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            19: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46d081 (runtime.futex:557) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x438714 (runtime.asyncPreempt2:307) 0x46c7da (runtime.asyncPreempt:53) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            6: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43eb9a (runtime.findRunnable:2890) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            3: 0x47fb44 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            3: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            8: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            3: 0x55a32a (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            4: 0x46c700 (runtime.asyncPreempt:8) 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46c700 (runtime.asyncPreempt:8) 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x44083b (runtime.checkTimers:3670) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x447eed (runtime.(*profBuf).read:512) 0x4656ca (runtime/pprof.readProfile:234) 0x54d28e (runtime/pprof.profileWriter:810) labels: map[]
            
            4: 0x46cc16 (runtime.nanotime1:239) labels: map[]
            
            1: 0x46cc00 (runtime.nanotime1:223) labels: map[]
            
            1: 0x46cc2f (runtime.nanotime1:245) labels: map[]
            
            1: 0x40c0a7 (runtime.unlock2:129) 0x440c1b (runtime.unlockWithRank:34 runtime.unlock:112 runtime.goschedImpl:3765) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x446664 (runtime.pidlegetSpinning:6165) 0x43e4e4 (runtime.wakep:2731) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x450da8 (runtime.newstack:962) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46c7da (runtime.asyncPreempt:53) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x4510e3 (runtime.newstack:1044) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
        pprof_test.go:628: found 13911 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 9m11.324968s user + 1m19.955264s system = 10m31.280232s vs 2m19.51s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -77.9%) want nil
        pprof_test.go:494: retrying with 1m20s duration
        pprof_test.go:557: total 27686 CPU profile samples collected:
            20666: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            3376: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46d083 (runtime.futex:558) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            332: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2114: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43ce24 (runtime.forEachP:1824) 0x463fe4 (runtime.gcMarkDone.func1:834) 0x469449 (runtime.systemstack:509) 0x41ab9e (runtime.gcMarkDone:827) 0x41bfe4 (runtime.gcBgMarkWorker:1435) labels: map[]
            
            110: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            570: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            9: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            23: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            198: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            37: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            182: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            6: 0x46c700 (runtime.asyncPreempt:8) 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            3: 0x4510e3 (runtime.newstack:1044) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x438714 (runtime.asyncPreempt2:307) 0x46c7da (runtime.asyncPreempt:53) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            5: 0x46d081 (runtime.futex:557) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            5: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x40c0a7 (runtime.unlock2:129) 0x440c1b (runtime.unlockWithRank:34 runtime.unlock:112 runtime.goschedImpl:3765) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            13: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x447fbc (runtime.(*profBuf).read:536) 0x4656ca (runtime/pprof.readProfile:234) 0x54d28e (runtime/pprof.profileWriter:810) labels: map[]
            
            1: 0x55a3c4 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x55a334 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x446664 (runtime.pidlegetSpinning:6165) 0x43e4e4 (runtime.wakep:2731) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x411b58 (runtime.mapaccess1_fast64:45) 0x548a8f (runtime/pprof.(*profMap).lookup:41) 0x550c07 (runtime/pprof.(*profileBuilder).addCPUData:338) 0x54d2c4 (runtime/pprof.profileWriter:811) labels: map[]
            
            1: 0x458a1e (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x440ab2 (runtime.park_m:3741) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x55a32a (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43bae1 (runtime.casgstatus:1045) 0x440b9b (runtime.goschedImpl:3761) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x46c700 (runtime.asyncPreempt:8) 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43ea0b (runtime.execute:2836) 0x4407bb (runtime.schedule:3639) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x458a1a (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x469545 (runtime.morestack_noctxt:600) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            7: 0x47fb44 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x446186 (runtime.globrunqget:6024) 0x43edd3 (runtime.findRunnable:2949) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x43bb70 (runtime.casgstatus:1062) 0x440b9b (runtime.goschedImpl:3761) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x46b1e7 (runtime.memhash64:1560) 0x411aa3 (runtime.mapaccess1_fast64:29) 0x548a8f (runtime/pprof.(*profMap).lookup:41) 0x550c07 (runtime/pprof.(*profileBuilder).addCPUData:338) 0x54d2c4 (runtime/pprof.profileWriter:811) labels: map[]
            
            1: 0x450ea6 (runtime.newstack:1023) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43ebb9 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x440b6b (runtime.goschedImpl:3755) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            2: 0x46cc16 (runtime.nanotime1:239) labels: map[]
            
            1: 0x43eb9a (runtime.findRunnable:2890) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x46d081 (runtime.futex:557) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x440b3e (runtime.park_m:3752) 0x4693cd (runtime.mcall:458) labels: map[]
            
        pprof_test.go:628: found 27625 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 18m32.427318s user + 2m33.162633s system = 21m5.589951s vs 4m36.86s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -78.1%) want nil
        pprof_test.go:494: retrying with 2m40s duration
        pprof_test.go:557: total 55652 CPU profile samples collected:
            1: 0x414336 (runtime.spanOf:705 runtime.findObject:340) 0x4200cb (runtime.scanobject:1365) 0x41f999 (runtime.gcDrain:1133) 0x41c204 (runtime.gcDrainMarkWorkerDedicated:1027 runtime.gcBgMarkWorker.func2:1376) 0x469449 (runtime.systemstack:509) 0x41be91 (runtime.gcBgMarkWorker:1363) labels: map[]
            
            41102: 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            7223: 0x46c700 (runtime.asyncPreempt:8) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x423e67 (runtime.(*scavengeIndex).find:1089) 0x4230a4 (runtime.(*pageAlloc).scavenge:678) 0x463c87 (runtime.(*scavengerState).init.func2:395) 0x422e6f (runtime.(*scavengerState).run:602) 0x422fe7 (runtime.bgscavenge:656) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43cce4 (runtime.forEachP:1778) 0x463fe4 (runtime.gcMarkDone.func1:834) 0x469449 (runtime.systemstack:509) 0x41ab9e (runtime.gcMarkDone:827) 0x41e686 (runtime.gcAssistAlloc:484) 0x40dd13 (runtime.deductAssistCredit:1285) 0x40d528 (runtime.mallocgc:1000) 0x40de04 (runtime.newobject:1322) 0x55092a (runtime/pprof.newProfileBuilder:261) 0x54d264 (runtime/pprof.profileWriter:806) labels: map[]
            
            13: 0x46d081 (runtime.futex:557) 0x43394f (runtime.futexsleep:69) 0x40c226 (runtime.notesleep:160) 0x43ddcb (runtime.mPark:1633 runtime.stopm:2522) 0x43f6bb (runtime.findRunnable:3235) 0x440630 (runtime.schedule:3589) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            2: 0x46d083 (runtime.futex:558) 0x433a0f (runtime.futexwakeup:82) 0x40c124 (runtime.notewakeup:145) 0x43e088 (runtime.startm:2635) 0x43e56b (runtime.wakep:2746) 0x44025d (runtime.resetspinning:3473) 0x44068e (runtime.schedule:3607) 0x44152d (runtime.goexit0:3932) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x46cb56 (runtime.tgkill:177) 0x434746 (runtime.signalM:559) 0x445659 (runtime.preemptM:385 runtime.preemptone:5804) 0x4455ae (runtime.preemptall:5766) 0x43ce24 (runtime.forEachP:1824) 0x463fe4 (runtime.gcMarkDone.func1:834) 0x469449 (runtime.systemstack:509) 0x41ab9e (runtime.gcMarkDone:827) 0x41e686 (runtime.gcAssistAlloc:484) 0x40dd13 (runtime.deductAssistCredit:1285) 0x40d528 (runtime.mallocgc:1000) 0x40de04 (runtime.newobject:1322) 0x55092a (runtime/pprof.newProfileBuilder:261) 0x54d264 (runtime/pprof.profileWriter:806) labels: map[]
            
            1174: 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            235: 0x46c700 (runtime.asyncPreempt:8) 0x55a3db (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            708: 0x46c700 (runtime.asyncPreempt:8) 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            18: 0x46d057 (runtime.madvise:544) 0x4171f5 (runtime.sysUnusedOS:63) 0x4235ee (runtime.sysUnused:62 runtime.(*pageAlloc).scavengeOne:780) 0x4231ae (runtime.(*pageAlloc).scavenge.func1:683) 0x469449 (runtime.systemstack:509) 0x423104 (runtime.(*pageAlloc).scavenge:682) 0x463c87 (runtime.(*scavengerState).init.func2:395) 0x422e6f (runtime.(*scavengerState).run:602) 0x422fe7 (runtime.bgscavenge:656) labels: map[]
            
            4144: 0x55a3e3 (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            13: 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            407: 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            326: 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43871e (runtime.asyncPreempt2:309) 0x46c7da (runtime.asyncPreempt:53) 0x55a3d3 (runtime/pprof.cpuHog0:61 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x4510e3 (runtime.newstack:1044) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            33: 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            33: 0x458a0c (runtime.nanotime:19) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            74: 0x46c700 (runtime.asyncPreempt:8) 0x55a3df (runtime/pprof.cpuHog0:64 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x446664 (runtime.pidlegetSpinning:6165) 0x43e4e4 (runtime.wakep:2731) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            59: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c7 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            8: 0x46cc16 (runtime.nanotime1:239) labels: map[]
            
            7: 0x46c700 (runtime.asyncPreempt:8) 0x55a3ce (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            8: 0x55a32a (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46cc00 (runtime.nanotime1:223) labels: map[]
            
            3: 0x55a334 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x40bee1 (runtime.lock2:62) 0x43e4dc (runtime.lockWithRank:24 runtime.lock:48 runtime.wakep:2730) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x46afa9 (runtime.procyield:780) 0x40bf2c (runtime.lock2:88) 0x440bca (runtime.lockWithRank:24 runtime.lock:48 runtime.goschedImpl:3763) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x450e86 (runtime.canPreemptM:287 runtime.newstack:1023) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            2: 0x44083b (runtime.checkTimers:3670) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x469545 (runtime.morestack_noctxt:600) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x40a28d (runtime.(*timeHistogram).record:135) 0x43bd86 (runtime.casgstatus:1136) 0x43ea7a (runtime.execute:2847) 0x4407bb (runtime.schedule:3639) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            12: 0x47fb44 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x465680 (runtime/pprof.readProfile:226) 0x54d28e (runtime/pprof.profileWriter:810) labels: map[]
            
            2: 0x447fbc (runtime.(*profBuf).read:536) 0x4656ca (runtime/pprof.readProfile:234) 0x54d28e (runtime/pprof.profileWriter:810) labels: map[]
            
            1: 0x47fb63 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x40c0a7 (runtime.unlock2:129) 0x440c1b (runtime.unlockWithRank:34 runtime.unlock:112 runtime.goschedImpl:3765) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x46c700 (runtime.asyncPreempt:8) 0x55a3c2 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43ed59 (runtime.runqget:6331 runtime.findRunnable:2942) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x458a00 (runtime.nanotime:18) 0x47fb67 (time.Since:932) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x46c700 (runtime.asyncPreempt:8) 0x548e09 (runtime/pprof.(*profMap).lookup:46) 0x550c07 (runtime/pprof.(*profileBuilder).addCPUData:338) 0x54d2c4 (runtime/pprof.profileWriter:811) labels: map[]
            
            2: 0x43f4f3 (runtime.runqget:6337 runtime.findRunnable:2942) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x450ea6 (runtime.newstack:1023) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x439f44 (runtime.gopark:383) 0x468434 (time.Sleep:195) 0x54d289 (runtime/pprof.profileWriter:809) labels: map[]
            
            1: 0x446124 (runtime.globrunqget:6006) 0x43edd3 (runtime.findRunnable:2949) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            2: 0x46c700 (runtime.asyncPreempt:8) 0x55a32f (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            3: 0x55a3c2 (runtime/pprof.cpuHog0:60 runtime/pprof.cpuHog1:55) 0x55a32e (runtime/pprof.cpuHogger:41) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x40be84 (runtime.lock2:51) 0x440bca (runtime.lockWithRank:24 runtime.lock:48 runtime.goschedImpl:3763) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x548ab8 (runtime/pprof.(*profMap).lookup:42) 0x550c07 (runtime/pprof.(*profileBuilder).addCPUData:338) 0x54d2c4 (runtime/pprof.profileWriter:811) labels: map[]
            
            1: 0x43e4c6 (runtime.wakep:2730) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x4405ff (runtime.schedule:3585) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x40beb7 (runtime.lock2:61) 0x440bca (runtime.lockWithRank:24 runtime.lock:48 runtime.goschedImpl:3763) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x43bdc7 (runtime.casgstatus:1087) 0x440b9b (runtime.goschedImpl:3761) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x46c700 (runtime.asyncPreempt:8) 0x55a334 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x44083b (runtime.checkTimers:3670) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x456f24 (runtime.dodeltimer0:413) 0x458084 (runtime.runOneTimer:868) 0x457f19 (runtime.runtimer:792) 0x44093a (runtime.checkTimers:3700) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x43ed59 (runtime.runqget:6331 runtime.findRunnable:2942) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x43bae1 (runtime.casgstatus:1045) 0x440b9b (runtime.goschedImpl:3761) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x440b84 (runtime.goschedImpl:3757) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x47fbe7 (time.Since:929) 0x55a365 (runtime/pprof.cpuHogger:40) 0x55bece (runtime/pprof.TestCPUProfileMultithreadMagnitude.func3.2.1.1:232) labels: map[]
            
            1: 0x43eb9a (runtime.findRunnable:2890) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x4693cd (runtime.mcall:458) labels: map[]
            
            1: 0x440872 (runtime.nanotime:19 runtime.checkTimers:3681) 0x43ebb3 (runtime.findRunnable:2898) 0x440630 (runtime.schedule:3589) 0x440c2e (runtime.goschedImpl:3771) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
            1: 0x40be84 (runtime.lock2:51) 0x43e4dc (runtime.lockWithRank:24 runtime.lock:48 runtime.wakep:2730) 0x440c29 (runtime.goschedImpl:3768) 0x440eee (runtime.gopreempt_m:3799) 0x45116a (runtime.newstack:1070) 0x46952e (runtime.morestack:593) labels: map[]
            
        pprof_test.go:628: found 55497 samples in expected function runtime/pprof.cpuHog1
        pprof_test.go:214: compare 36m56.60984s user + 5m11.787409s system = 42m8.397249s vs 9m16.52s
        pprof_test.go:216: compare got CPU usage reports are too different (limit -10.0%, got -78.0%) want nil
    pprof_test.go:123: Failure of this test may indicate that your system suffers from a known Linux kernel bug fixed on newer kernels. See https://golang.org/issue/49065.
FAIL
FAIL	runtime/pprof	381.962s
</details>