runtime/pprof: TestCPUProfileInlining failing on linux-amd64-noopt builder #35463
Description
runtime/pprof is consistently failing on the linux-amd64-noopt builder as of CL 204636.
The transition from passing to failing was masked by #35376.
Details
--- FAIL: TestCPUProfileInlining (0.30s)
pprof_test.go:315: total 17 CPU profile samples collected:
1: 0x447155 (runtime.(*randomOrder).start:5343) 0x43ef84 (runtime.findrunnable:2179) 0x4400dd (runtime.schedule:2548) 0x440677 (runtime.park_m:2688) 0x46a4aa (runtime.mcall:318)
1: 0x62a059 (runtime/pprof.cpuHog0:57) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
4: 0x62a07c (runtime/pprof.cpuHog0:61) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
4: 0x62a077 (runtime/pprof.cpuHog0:61) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
1: 0x62a02b (runtime/pprof.cpuHog0:57) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
4: 0x62a066 (runtime/pprof.cpuHog0:61) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
1: 0x62a064 (runtime/pprof.cpuHog0:57) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
1: 0x62a038 (runtime/pprof.cpuHog0:58) 0x62a9dd (runtime/pprof.inlinedCallee:135) 0x62a97c (runtime/pprof.inlinedCaller:130) 0x629f1e (runtime/pprof.cpuHogger:38) 0x63a2a2 (runtime/pprof.TestCPUProfileInlining.func1:109) 0x62b681 (runtime/pprof.testCPUProfile:235) 0x62a5d7 (runtime/pprof.TestCPUProfileInlining:108) 0x53b79b (testing.tRunner:954)
pprof_test.go:350: runtime/pprof.inlinedCallee: 16
pprof_test.go:350: runtime/pprof.inlinedCaller: 16
pprof_test.go:124: want inlinedCallee followed by inlinedCaller, got separate Location entries:
PeriodType: cpu nanoseconds
Period: 10000000
Time: 2019-11-08 03:16:14.08747387 +0000 UTC
Duration: 301.48664ms
Samples:
samples/count cpu/nanoseconds
1 10000000: 1 2 3 4 5
1 10000000: 6 7 8 9 10 11 12 13
4 40000000: 14 7 8 9 10 11 12 13
4 40000000: 15 7 8 9 10 11 12 13
1 10000000: 16 7 8 9 10 11 12 13
4 40000000: 17 7 8 9 10 11 12 13
1 10000000: 18 7 8 9 10 11 12 13
1 10000000: 19 7 8 9 10 11 12 13
Locations
1: 0x447155 M=1 runtime.(*randomOrder).start /workdir/go/src/runtime/proc.go:5343 s=0
2: 0x43ef84 M=1 runtime.findrunnable /workdir/go/src/runtime/proc.go:2179 s=0
3: 0x4400dd M=1 runtime.schedule /workdir/go/src/runtime/proc.go:2548 s=0
4: 0x440677 M=1 runtime.park_m /workdir/go/src/runtime/proc.go:2688 s=0
5: 0x46a4aa M=1 runtime.mcall /workdir/go/src/runtime/asm_amd64.s:318 s=0
6: 0x62a059 M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:57 s=0
7: 0x62a9dd M=1 runtime/pprof.inlinedCallee /workdir/go/src/runtime/pprof/pprof_test.go:135 s=0
8: 0x62a97c M=1 runtime/pprof.inlinedCaller /workdir/go/src/runtime/pprof/pprof_test.go:130 s=0
9: 0x629f1e M=1 runtime/pprof.cpuHogger /workdir/go/src/runtime/pprof/pprof_test.go:38 s=0
10: 0x63a2a2 M=1 runtime/pprof.TestCPUProfileInlining.func1 /workdir/go/src/runtime/pprof/pprof_test.go:109 s=0
11: 0x62b681 M=1 runtime/pprof.testCPUProfile /workdir/go/src/runtime/pprof/pprof_test.go:235 s=0
12: 0x62a5d7 M=1 runtime/pprof.TestCPUProfileInlining /workdir/go/src/runtime/pprof/pprof_test.go:108 s=0
13: 0x53b79b M=1 testing.tRunner /workdir/go/src/testing/testing.go:954 s=0
14: 0x62a07c M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:61 s=0
15: 0x62a077 M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:61 s=0
16: 0x62a02b M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:57 s=0
17: 0x62a066 M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:61 s=0
18: 0x62a064 M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:57 s=0
19: 0x62a038 M=1 runtime/pprof.cpuHog0 /workdir/go/src/runtime/pprof/pprof_test.go:58 s=0
Mappings
1: 0x400000/0x644000/0x0 /workdir/tmp/go-build259862701/b053/pprof.test [FN]
2: 0x7ffcafdfa000/0x7ffcafdfc000/0x0 [vdso]
3: 0xffffffffff600000/0xffffffffff601000/0x0 [vsyscall]
FAIL
FAIL runtime/pprof 4.063s