1
2
3
4
5
6
7 package pprof
8
9 import (
10 "bytes"
11 "context"
12 "fmt"
13 "internal/abi"
14 "internal/profile"
15 "internal/syscall/unix"
16 "internal/testenv"
17 "io"
18 "math"
19 "math/big"
20 "os"
21 "regexp"
22 "runtime"
23 "runtime/debug"
24 "strings"
25 "sync"
26 "sync/atomic"
27 "testing"
28 "time"
29 _ "unsafe"
30 )
31
32 func cpuHogger(f func(x int) int, y *int, dur time.Duration) {
33
34
35
36
37
38 t0 := time.Now()
39 accum := *y
40 for i := 0; i < 500 || time.Since(t0) < dur; i++ {
41 accum = f(accum)
42 }
43 *y = accum
44 }
45
46 var (
47 salt1 = 0
48 salt2 = 0
49 )
50
51
52
53
54 func cpuHog1(x int) int {
55 return cpuHog0(x, 1e5)
56 }
57
58 func cpuHog0(x, n int) int {
59 foo := x
60 for i := 0; i < n; i++ {
61 if foo > 0 {
62 foo *= foo
63 } else {
64 foo *= foo + 1
65 }
66 }
67 return foo
68 }
69
70 func cpuHog2(x int) int {
71 foo := x
72 for i := 0; i < 1e5; i++ {
73 if foo > 0 {
74 foo *= foo
75 } else {
76 foo *= foo + 2
77 }
78 }
79 return foo
80 }
81
82
83
84 func avoidFunctions() []string {
85 if runtime.Compiler == "gccgo" {
86 return []string{"runtime.sigprof"}
87 }
88 return nil
89 }
90
91 func TestCPUProfile(t *testing.T) {
92 matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1"}, avoidFunctions())
93 testCPUProfile(t, matches, func(dur time.Duration) {
94 cpuHogger(cpuHog1, &salt1, dur)
95 })
96 }
97
98 func TestCPUProfileMultithreaded(t *testing.T) {
99 defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(2))
100 matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1", "runtime/pprof.cpuHog2"}, avoidFunctions())
101 testCPUProfile(t, matches, func(dur time.Duration) {
102 c := make(chan int)
103 go func() {
104 cpuHogger(cpuHog1, &salt1, dur)
105 c <- 1
106 }()
107 cpuHogger(cpuHog2, &salt2, dur)
108 <-c
109 })
110 }
111
112 func TestCPUProfileMultithreadMagnitude(t *testing.T) {
113 if runtime.GOOS != "linux" {
114 t.Skip("issue 35057 is only confirmed on Linux")
115 }
116
117
118
119 major, minor := unix.KernelVersion()
120 t.Logf("Running on Linux %d.%d", major, minor)
121 defer func() {
122 if t.Failed() {
123 t.Logf("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.")
124 }
125 }()
126
127
128
129
130 if testenv.Builder() != "" && (runtime.GOARCH == "386" || runtime.GOARCH == "amd64") {
131 have59 := major > 5 || (major == 5 && minor >= 9)
132 have516 := major > 5 || (major == 5 && minor >= 16)
133 if have59 && !have516 {
134 testenv.SkipFlaky(t, 49065)
135 }
136 }
137
138
139
140
141
142
143
144
145
146
147
148
149 maxDiff := 0.10
150 if testing.Short() {
151 maxDiff = 0.40
152 }
153
154 compare := func(a, b time.Duration, maxDiff float64) error {
155 if a <= 0 || b <= 0 {
156 return fmt.Errorf("Expected both time reports to be positive")
157 }
158
159 if a < b {
160 a, b = b, a
161 }
162
163 diff := float64(a-b) / float64(a)
164 if diff > maxDiff {
165 return fmt.Errorf("CPU usage reports are too different (limit -%.1f%%, got -%.1f%%)", maxDiff*100, diff*100)
166 }
167
168 return nil
169 }
170
171 for _, tc := range []struct {
172 name string
173 workers int
174 }{
175 {
176 name: "serial",
177 workers: 1,
178 },
179 {
180 name: "parallel",
181 workers: runtime.GOMAXPROCS(0),
182 },
183 } {
184
185 t.Run(tc.name, func(t *testing.T) {
186 t.Logf("Running with %d workers", tc.workers)
187
188 var userTime, systemTime time.Duration
189 matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1"}, avoidFunctions())
190 acceptProfile := func(t *testing.T, p *profile.Profile) bool {
191 if !matches(t, p) {
192 return false
193 }
194
195 ok := true
196 for i, unit := range []string{"count", "nanoseconds"} {
197 if have, want := p.SampleType[i].Unit, unit; have != want {
198 t.Logf("pN SampleType[%d]; %q != %q", i, have, want)
199 ok = false
200 }
201 }
202
203
204
205
206
207
208 var value time.Duration
209 for _, sample := range p.Sample {
210 value += time.Duration(sample.Value[1]) * time.Nanosecond
211 }
212
213 totalTime := userTime + systemTime
214 t.Logf("compare %s user + %s system = %s vs %s", userTime, systemTime, totalTime, value)
215 if err := compare(totalTime, value, maxDiff); err != nil {
216 t.Logf("compare got %v want nil", err)
217 ok = false
218 }
219
220 return ok
221 }
222
223 testCPUProfile(t, acceptProfile, func(dur time.Duration) {
224 userTime, systemTime = diffCPUTime(t, func() {
225 var wg sync.WaitGroup
226 var once sync.Once
227 for i := 0; i < tc.workers; i++ {
228 wg.Add(1)
229 go func() {
230 defer wg.Done()
231 var salt = 0
232 cpuHogger(cpuHog1, &salt, dur)
233 once.Do(func() { salt1 = salt })
234 }()
235 }
236 wg.Wait()
237 })
238 })
239 })
240 }
241 }
242
243
244
245 func containsInlinedCall(f any, maxBytes int) bool {
246 _, found := findInlinedCall(f, maxBytes)
247 return found
248 }
249
250
251
252 func findInlinedCall(f any, maxBytes int) (pc uint64, found bool) {
253 fFunc := runtime.FuncForPC(uintptr(abi.FuncPCABIInternal(f)))
254 if fFunc == nil || fFunc.Entry() == 0 {
255 panic("failed to locate function entry")
256 }
257
258 for offset := 0; offset < maxBytes; offset++ {
259 innerPC := fFunc.Entry() + uintptr(offset)
260 inner := runtime.FuncForPC(innerPC)
261 if inner == nil {
262
263
264 continue
265 }
266 if inner.Entry() != fFunc.Entry() {
267
268 break
269 }
270 if inner.Name() != fFunc.Name() {
271
272
273 return uint64(innerPC), true
274 }
275 }
276
277 return 0, false
278 }
279
280 func TestCPUProfileInlining(t *testing.T) {
281 if !containsInlinedCall(inlinedCaller, 4<<10) {
282 t.Skip("Can't determine whether inlinedCallee was inlined into inlinedCaller.")
283 }
284
285 matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.inlinedCaller"}, avoidFunctions())
286 p := testCPUProfile(t, matches, func(dur time.Duration) {
287 cpuHogger(inlinedCaller, &salt1, dur)
288 })
289
290
291 for _, loc := range p.Location {
292 hasInlinedCallerAfterInlinedCallee, hasInlinedCallee := false, false
293 for _, line := range loc.Line {
294 if line.Function.Name == "runtime/pprof.inlinedCallee" {
295 hasInlinedCallee = true
296 }
297 if hasInlinedCallee && line.Function.Name == "runtime/pprof.inlinedCaller" {
298 hasInlinedCallerAfterInlinedCallee = true
299 }
300 }
301 if hasInlinedCallee != hasInlinedCallerAfterInlinedCallee {
302 t.Fatalf("want inlinedCallee followed by inlinedCaller, got separate Location entries:\n%v", p)
303 }
304 }
305 }
306
307 func inlinedCaller(x int) int {
308 x = inlinedCallee(x, 1e5)
309 return x
310 }
311
312 func inlinedCallee(x, n int) int {
313 return cpuHog0(x, n)
314 }
315
316
317 func dumpCallers(pcs []uintptr) {
318 if pcs == nil {
319 return
320 }
321
322 skip := 2
323 runtime.Callers(skip, pcs)
324 }
325
326
327 func inlinedCallerDump(pcs []uintptr) {
328 inlinedCalleeDump(pcs)
329 }
330
331 func inlinedCalleeDump(pcs []uintptr) {
332 dumpCallers(pcs)
333 }
334
335 type inlineWrapperInterface interface {
336 dump(stack []uintptr)
337 }
338
339 type inlineWrapper struct {
340 }
341
342 func (h inlineWrapper) dump(pcs []uintptr) {
343 dumpCallers(pcs)
344 }
345
346 func inlinedWrapperCallerDump(pcs []uintptr) {
347 var h inlineWrapperInterface
348 h = &inlineWrapper{}
349 h.dump(pcs)
350 }
351
352 func TestCPUProfileRecursion(t *testing.T) {
353 matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.recursionCallee", "runtime/pprof.recursionCaller"}, avoidFunctions())
354 p := testCPUProfile(t, matches, func(dur time.Duration) {
355 cpuHogger(recursionCaller, &salt1, dur)
356 })
357
358
359 for i, loc := range p.Location {
360 recursionFunc := 0
361 for _, line := range loc.Line {
362 if name := line.Function.Name; name == "runtime/pprof.recursionCaller" || name == "runtime/pprof.recursionCallee" {
363 recursionFunc++
364 }
365 }
366 if recursionFunc > 1 {
367 t.Fatalf("want at most one recursionCaller or recursionCallee in one Location, got a violating Location (index: %d):\n%v", i, p)
368 }
369 }
370 }
371
372 func recursionCaller(x int) int {
373 y := recursionCallee(3, x)
374 return y
375 }
376
377 func recursionCallee(n, x int) int {
378 if n == 0 {
379 return 1
380 }
381 y := inlinedCallee(x, 1e4)
382 return y * recursionCallee(n-1, x)
383 }
384
385 func recursionChainTop(x int, pcs []uintptr) {
386 if x < 0 {
387 return
388 }
389 recursionChainMiddle(x, pcs)
390 }
391
392 func recursionChainMiddle(x int, pcs []uintptr) {
393 recursionChainBottom(x, pcs)
394 }
395
396 func recursionChainBottom(x int, pcs []uintptr) {
397
398
399 dumpCallers(pcs)
400
401 recursionChainTop(x-1, pcs)
402 }
403
404 func parseProfile(t *testing.T, valBytes []byte, f func(uintptr, []*profile.Location, map[string][]string)) *profile.Profile {
405 p, err := profile.Parse(bytes.NewReader(valBytes))
406 if err != nil {
407 t.Fatal(err)
408 }
409 for _, sample := range p.Sample {
410 count := uintptr(sample.Value[0])
411 f(count, sample.Location, sample.Label)
412 }
413 return p
414 }
415
416 func cpuProfilingBroken() bool {
417 switch runtime.GOOS {
418 case "plan9":
419
420 return true
421 case "aix":
422
423 return true
424 case "ios", "dragonfly", "netbsd", "illumos", "solaris":
425
426 return true
427 case "openbsd":
428 if runtime.GOARCH == "arm" || runtime.GOARCH == "arm64" {
429
430 return true
431 }
432 }
433
434 return false
435 }
436
437
438
439 func testCPUProfile(t *testing.T, matches profileMatchFunc, f func(dur time.Duration)) *profile.Profile {
440 switch runtime.GOOS {
441 case "darwin":
442 out, err := testenv.Command(t, "uname", "-a").CombinedOutput()
443 if err != nil {
444 t.Fatal(err)
445 }
446 vers := string(out)
447 t.Logf("uname -a: %v", vers)
448 case "plan9":
449 t.Skip("skipping on plan9")
450 case "wasip1":
451 t.Skip("skipping on wasip1")
452 }
453
454 broken := cpuProfilingBroken()
455
456 deadline, ok := t.Deadline()
457 if broken || !ok {
458 if broken && testing.Short() {
459
460 deadline = time.Now().Add(1 * time.Second)
461 } else {
462 deadline = time.Now().Add(10 * time.Second)
463 }
464 }
465
466
467
468 duration := 5 * time.Second
469 if testing.Short() {
470 duration = 100 * time.Millisecond
471 }
472
473
474
475
476
477
478 for {
479 var prof bytes.Buffer
480 if err := StartCPUProfile(&prof); err != nil {
481 t.Fatal(err)
482 }
483 f(duration)
484 StopCPUProfile()
485
486 if p, ok := profileOk(t, matches, prof, duration); ok {
487 return p
488 }
489
490 duration *= 2
491 if time.Until(deadline) < duration {
492 break
493 }
494 t.Logf("retrying with %s duration", duration)
495 }
496
497 if broken {
498 t.Skipf("ignoring failure on %s/%s; see golang.org/issue/13841", runtime.GOOS, runtime.GOARCH)
499 }
500
501
502
503
504
505 if os.Getenv("IN_QEMU") == "1" {
506 t.Skip("ignore the failure in QEMU; see golang.org/issue/9605")
507 }
508 t.FailNow()
509 return nil
510 }
511
512 var diffCPUTimeImpl func(f func()) (user, system time.Duration)
513
514 func diffCPUTime(t *testing.T, f func()) (user, system time.Duration) {
515 if fn := diffCPUTimeImpl; fn != nil {
516 return fn(f)
517 }
518 t.Fatalf("cannot measure CPU time on GOOS=%s GOARCH=%s", runtime.GOOS, runtime.GOARCH)
519 return 0, 0
520 }
521
522 func contains(slice []string, s string) bool {
523 for i := range slice {
524 if slice[i] == s {
525 return true
526 }
527 }
528 return false
529 }
530
531
532 func stackContains(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
533 for _, loc := range stk {
534 for _, line := range loc.Line {
535 if strings.Contains(line.Function.Name, spec) {
536 return true
537 }
538 }
539 }
540 return false
541 }
542
543 type sampleMatchFunc func(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool
544
545 func profileOk(t *testing.T, matches profileMatchFunc, prof bytes.Buffer, duration time.Duration) (_ *profile.Profile, ok bool) {
546 ok = true
547
548 var samples uintptr
549 var buf strings.Builder
550 p := parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, labels map[string][]string) {
551 fmt.Fprintf(&buf, "%d:", count)
552 fprintStack(&buf, stk)
553 fmt.Fprintf(&buf, " labels: %v\n", labels)
554 samples += count
555 fmt.Fprintf(&buf, "\n")
556 })
557 t.Logf("total %d CPU profile samples collected:\n%s", samples, buf.String())
558
559 if samples < 10 && runtime.GOOS == "windows" {
560
561
562
563 t.Log("too few samples on Windows (golang.org/issue/10842)")
564 return p, false
565 }
566
567
568
569
570
571
572 if ideal := uintptr(duration * 100 / time.Second); samples == 0 || (samples < ideal/4 && samples < 10) {
573 t.Logf("too few samples; got %d, want at least %d, ideally %d", samples, ideal/4, ideal)
574 ok = false
575 }
576
577 if matches != nil && !matches(t, p) {
578 ok = false
579 }
580
581 return p, ok
582 }
583
584 type profileMatchFunc func(*testing.T, *profile.Profile) bool
585
586 func matchAndAvoidStacks(matches sampleMatchFunc, need []string, avoid []string) profileMatchFunc {
587 return func(t *testing.T, p *profile.Profile) (ok bool) {
588 ok = true
589
590
591
592 have := make([]uintptr, len(need))
593 avoidSamples := make([]uintptr, len(avoid))
594
595 for _, sample := range p.Sample {
596 count := uintptr(sample.Value[0])
597 for i, spec := range need {
598 if matches(spec, count, sample.Location, sample.Label) {
599 have[i] += count
600 }
601 }
602 for i, name := range avoid {
603 for _, loc := range sample.Location {
604 for _, line := range loc.Line {
605 if strings.Contains(line.Function.Name, name) {
606 avoidSamples[i] += count
607 }
608 }
609 }
610 }
611 }
612
613 for i, name := range avoid {
614 bad := avoidSamples[i]
615 if bad != 0 {
616 t.Logf("found %d samples in avoid-function %s\n", bad, name)
617 ok = false
618 }
619 }
620
621 if len(need) == 0 {
622 return
623 }
624
625 var total uintptr
626 for i, name := range need {
627 total += have[i]
628 t.Logf("found %d samples in expected function %s\n", have[i], name)
629 }
630 if total == 0 {
631 t.Logf("no samples in expected functions")
632 ok = false
633 }
634
635
636
637
638
639 min := uintptr(1)
640 for i, name := range need {
641 if have[i] < min {
642 t.Logf("%s has %d samples out of %d, want at least %d, ideally %d", name, have[i], total, min, total/uintptr(len(have)))
643 ok = false
644 }
645 }
646 return
647 }
648 }
649
650
651
652 func TestCPUProfileWithFork(t *testing.T) {
653 testenv.MustHaveExec(t)
654
655 exe, err := os.Executable()
656 if err != nil {
657 t.Fatal(err)
658 }
659
660 heap := 1 << 30
661 if runtime.GOOS == "android" {
662
663 heap = 100 << 20
664 }
665 if runtime.GOOS == "windows" && runtime.GOARCH == "arm" {
666
667 heap = 100 << 20
668 }
669 if testing.Short() {
670 heap = 100 << 20
671 }
672
673 garbage := make([]byte, heap)
674
675 done := make(chan bool)
676 go func() {
677 for i := range garbage {
678 garbage[i] = 42
679 }
680 done <- true
681 }()
682 <-done
683
684 var prof bytes.Buffer
685 if err := StartCPUProfile(&prof); err != nil {
686 t.Fatal(err)
687 }
688 defer StopCPUProfile()
689
690 for i := 0; i < 10; i++ {
691 testenv.Command(t, exe, "-h").CombinedOutput()
692 }
693 }
694
695
696
697
698 func TestGoroutineSwitch(t *testing.T) {
699 if runtime.Compiler == "gccgo" {
700 t.Skip("not applicable for gccgo")
701 }
702
703
704
705 tries := 10
706 count := 1000000
707 if testing.Short() {
708 tries = 1
709 }
710 for try := 0; try < tries; try++ {
711 var prof bytes.Buffer
712 if err := StartCPUProfile(&prof); err != nil {
713 t.Fatal(err)
714 }
715 for i := 0; i < count; i++ {
716 runtime.Gosched()
717 }
718 StopCPUProfile()
719
720
721
722
723
724 parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, _ map[string][]string) {
725
726
727 if len(stk) == 2 {
728 name := stk[1].Line[0].Function.Name
729 if name == "runtime._System" || name == "runtime._ExternalCode" || name == "runtime._GC" {
730 return
731 }
732 }
733
734
735
736 if len(stk) == 1 {
737 return
738 }
739
740
741
742 name := stk[0].Line[0].Function.Name
743 if name == "gogo" {
744 var buf strings.Builder
745 fprintStack(&buf, stk)
746 t.Fatalf("found profile entry for gogo:\n%s", buf.String())
747 }
748 })
749 }
750 }
751
752 func fprintStack(w io.Writer, stk []*profile.Location) {
753 if len(stk) == 0 {
754 fmt.Fprintf(w, " (stack empty)")
755 }
756 for _, loc := range stk {
757 fmt.Fprintf(w, " %#x", loc.Address)
758 fmt.Fprintf(w, " (")
759 for i, line := range loc.Line {
760 if i > 0 {
761 fmt.Fprintf(w, " ")
762 }
763 fmt.Fprintf(w, "%s:%d", line.Function.Name, line.Line)
764 }
765 fmt.Fprintf(w, ")")
766 }
767 }
768
769
770 func TestMathBigDivide(t *testing.T) {
771 testCPUProfile(t, nil, func(duration time.Duration) {
772 t := time.After(duration)
773 pi := new(big.Int)
774 for {
775 for i := 0; i < 100; i++ {
776 n := big.NewInt(2646693125139304345)
777 d := big.NewInt(842468587426513207)
778 pi.Div(n, d)
779 }
780 select {
781 case <-t:
782 return
783 default:
784 }
785 }
786 })
787 }
788
789
790 func stackContainsAll(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
791 for _, f := range strings.Split(spec, ",") {
792 if !stackContains(f, count, stk, labels) {
793 return false
794 }
795 }
796 return true
797 }
798
799 func TestMorestack(t *testing.T) {
800 matches := matchAndAvoidStacks(stackContainsAll, []string{"runtime.newstack,runtime/pprof.growstack"}, avoidFunctions())
801 testCPUProfile(t, matches, func(duration time.Duration) {
802 t := time.After(duration)
803 c := make(chan bool)
804 for {
805 go func() {
806 growstack1()
807 c <- true
808 }()
809 select {
810 case <-t:
811 return
812 case <-c:
813 }
814 }
815 })
816 }
817
818
819 func growstack1() {
820 growstack(10)
821 }
822
823
824 func growstack(n int) {
825 var buf [8 << 18]byte
826 use(buf)
827 if n > 0 {
828 growstack(n - 1)
829 }
830 }
831
832
833 func use(x [8 << 18]byte) {}
834
835 func TestBlockProfile(t *testing.T) {
836 type TestCase struct {
837 name string
838 f func(*testing.T)
839 stk []string
840 re string
841 }
842 tests := [...]TestCase{
843 {
844 name: "chan recv",
845 f: blockChanRecv,
846 stk: []string{
847 "runtime.chanrecv1",
848 "runtime/pprof.blockChanRecv",
849 "runtime/pprof.TestBlockProfile",
850 },
851 re: `
852 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
853 # 0x[0-9a-f]+ runtime\.chanrecv1\+0x[0-9a-f]+ .*runtime/chan.go:[0-9]+
854 # 0x[0-9a-f]+ runtime/pprof\.blockChanRecv\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
855 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
856 `},
857 {
858 name: "chan send",
859 f: blockChanSend,
860 stk: []string{
861 "runtime.chansend1",
862 "runtime/pprof.blockChanSend",
863 "runtime/pprof.TestBlockProfile",
864 },
865 re: `
866 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
867 # 0x[0-9a-f]+ runtime\.chansend1\+0x[0-9a-f]+ .*runtime/chan.go:[0-9]+
868 # 0x[0-9a-f]+ runtime/pprof\.blockChanSend\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
869 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
870 `},
871 {
872 name: "chan close",
873 f: blockChanClose,
874 stk: []string{
875 "runtime.chanrecv1",
876 "runtime/pprof.blockChanClose",
877 "runtime/pprof.TestBlockProfile",
878 },
879 re: `
880 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
881 # 0x[0-9a-f]+ runtime\.chanrecv1\+0x[0-9a-f]+ .*runtime/chan.go:[0-9]+
882 # 0x[0-9a-f]+ runtime/pprof\.blockChanClose\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
883 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
884 `},
885 {
886 name: "select recv async",
887 f: blockSelectRecvAsync,
888 stk: []string{
889 "runtime.selectgo",
890 "runtime/pprof.blockSelectRecvAsync",
891 "runtime/pprof.TestBlockProfile",
892 },
893 re: `
894 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
895 # 0x[0-9a-f]+ runtime\.selectgo\+0x[0-9a-f]+ .*runtime/select.go:[0-9]+
896 # 0x[0-9a-f]+ runtime/pprof\.blockSelectRecvAsync\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
897 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
898 `},
899 {
900 name: "select send sync",
901 f: blockSelectSendSync,
902 stk: []string{
903 "runtime.selectgo",
904 "runtime/pprof.blockSelectSendSync",
905 "runtime/pprof.TestBlockProfile",
906 },
907 re: `
908 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
909 # 0x[0-9a-f]+ runtime\.selectgo\+0x[0-9a-f]+ .*runtime/select.go:[0-9]+
910 # 0x[0-9a-f]+ runtime/pprof\.blockSelectSendSync\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
911 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
912 `},
913 {
914 name: "mutex",
915 f: blockMutex,
916 stk: []string{
917 "sync.(*Mutex).Lock",
918 "runtime/pprof.blockMutex",
919 "runtime/pprof.TestBlockProfile",
920 },
921 re: `
922 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
923 # 0x[0-9a-f]+ sync\.\(\*Mutex\)\.Lock\+0x[0-9a-f]+ .*sync/mutex\.go:[0-9]+
924 # 0x[0-9a-f]+ runtime/pprof\.blockMutex\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
925 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
926 `},
927 {
928 name: "cond",
929 f: blockCond,
930 stk: []string{
931 "sync.(*Cond).Wait",
932 "runtime/pprof.blockCond",
933 "runtime/pprof.TestBlockProfile",
934 },
935 re: `
936 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
937 # 0x[0-9a-f]+ sync\.\(\*Cond\)\.Wait\+0x[0-9a-f]+ .*sync/cond\.go:[0-9]+
938 # 0x[0-9a-f]+ runtime/pprof\.blockCond\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
939 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*runtime/pprof/pprof_test.go:[0-9]+
940 `},
941 }
942
943
944 runtime.SetBlockProfileRate(1)
945 defer runtime.SetBlockProfileRate(0)
946 for _, test := range tests {
947 test.f(t)
948 }
949
950 t.Run("debug=1", func(t *testing.T) {
951 var w strings.Builder
952 Lookup("block").WriteTo(&w, 1)
953 prof := w.String()
954
955 if !strings.HasPrefix(prof, "--- contention:\ncycles/second=") {
956 t.Fatalf("Bad profile header:\n%v", prof)
957 }
958
959 if strings.HasSuffix(prof, "#\t0x0\n\n") {
960 t.Errorf("Useless 0 suffix:\n%v", prof)
961 }
962
963 for _, test := range tests {
964 if !regexp.MustCompile(strings.ReplaceAll(test.re, "\t", "\t+")).MatchString(prof) {
965 t.Errorf("Bad %v entry, expect:\n%v\ngot:\n%v", test.name, test.re, prof)
966 }
967 }
968 })
969
970 t.Run("proto", func(t *testing.T) {
971
972 var w bytes.Buffer
973 Lookup("block").WriteTo(&w, 0)
974 p, err := profile.Parse(&w)
975 if err != nil {
976 t.Fatalf("failed to parse profile: %v", err)
977 }
978 t.Logf("parsed proto: %s", p)
979 if err := p.CheckValid(); err != nil {
980 t.Fatalf("invalid profile: %v", err)
981 }
982
983 stks := stacks(p)
984 for _, test := range tests {
985 if !containsStack(stks, test.stk) {
986 t.Errorf("No matching stack entry for %v, want %+v", test.name, test.stk)
987 }
988 }
989 })
990
991 }
992
993 func stacks(p *profile.Profile) (res [][]string) {
994 for _, s := range p.Sample {
995 var stk []string
996 for _, l := range s.Location {
997 for _, line := range l.Line {
998 stk = append(stk, line.Function.Name)
999 }
1000 }
1001 res = append(res, stk)
1002 }
1003 return res
1004 }
1005
1006 func containsStack(got [][]string, want []string) bool {
1007 for _, stk := range got {
1008 if len(stk) < len(want) {
1009 continue
1010 }
1011 for i, f := range want {
1012 if f != stk[i] {
1013 break
1014 }
1015 if i == len(want)-1 {
1016 return true
1017 }
1018 }
1019 }
1020 return false
1021 }
1022
1023
1024
1025
1026 func awaitBlockedGoroutine(t *testing.T, state, fName string, count int) {
1027 re := fmt.Sprintf(`(?m)^goroutine \d+ \[%s\]:\n(?:.+\n\t.+\n)*runtime/pprof\.%s`, regexp.QuoteMeta(state), fName)
1028 r := regexp.MustCompile(re)
1029
1030 if deadline, ok := t.Deadline(); ok {
1031 if d := time.Until(deadline); d > 1*time.Second {
1032 timer := time.AfterFunc(d-1*time.Second, func() {
1033 debug.SetTraceback("all")
1034 panic(fmt.Sprintf("timed out waiting for %#q", re))
1035 })
1036 defer timer.Stop()
1037 }
1038 }
1039
1040 buf := make([]byte, 64<<10)
1041 for {
1042 runtime.Gosched()
1043 n := runtime.Stack(buf, true)
1044 if n == len(buf) {
1045
1046
1047 buf = make([]byte, 2*len(buf))
1048 continue
1049 }
1050 if len(r.FindAll(buf[:n], -1)) >= count {
1051 return
1052 }
1053 }
1054 }
1055
1056 func blockChanRecv(t *testing.T) {
1057 c := make(chan bool)
1058 go func() {
1059 awaitBlockedGoroutine(t, "chan receive", "blockChanRecv", 1)
1060 c <- true
1061 }()
1062 <-c
1063 }
1064
1065 func blockChanSend(t *testing.T) {
1066 c := make(chan bool)
1067 go func() {
1068 awaitBlockedGoroutine(t, "chan send", "blockChanSend", 1)
1069 <-c
1070 }()
1071 c <- true
1072 }
1073
1074 func blockChanClose(t *testing.T) {
1075 c := make(chan bool)
1076 go func() {
1077 awaitBlockedGoroutine(t, "chan receive", "blockChanClose", 1)
1078 close(c)
1079 }()
1080 <-c
1081 }
1082
1083 func blockSelectRecvAsync(t *testing.T) {
1084 const numTries = 3
1085 c := make(chan bool, 1)
1086 c2 := make(chan bool, 1)
1087 go func() {
1088 for i := 0; i < numTries; i++ {
1089 awaitBlockedGoroutine(t, "select", "blockSelectRecvAsync", 1)
1090 c <- true
1091 }
1092 }()
1093 for i := 0; i < numTries; i++ {
1094 select {
1095 case <-c:
1096 case <-c2:
1097 }
1098 }
1099 }
1100
1101 func blockSelectSendSync(t *testing.T) {
1102 c := make(chan bool)
1103 c2 := make(chan bool)
1104 go func() {
1105 awaitBlockedGoroutine(t, "select", "blockSelectSendSync", 1)
1106 <-c
1107 }()
1108 select {
1109 case c <- true:
1110 case c2 <- true:
1111 }
1112 }
1113
1114 func blockMutex(t *testing.T) {
1115 var mu sync.Mutex
1116 mu.Lock()
1117 go func() {
1118 awaitBlockedGoroutine(t, "sync.Mutex.Lock", "blockMutex", 1)
1119 mu.Unlock()
1120 }()
1121
1122
1123
1124
1125 mu.Lock()
1126 }
1127
1128 func blockMutexN(t *testing.T, n int, d time.Duration) {
1129 var wg sync.WaitGroup
1130 var mu sync.Mutex
1131 mu.Lock()
1132 go func() {
1133 awaitBlockedGoroutine(t, "sync.Mutex.Lock", "blockMutex", n)
1134 time.Sleep(d)
1135 mu.Unlock()
1136 }()
1137
1138
1139
1140
1141 for i := 0; i < n; i++ {
1142 wg.Add(1)
1143 go func() {
1144 defer wg.Done()
1145 mu.Lock()
1146 mu.Unlock()
1147 }()
1148 }
1149 wg.Wait()
1150 }
1151
1152 func blockCond(t *testing.T) {
1153 var mu sync.Mutex
1154 c := sync.NewCond(&mu)
1155 mu.Lock()
1156 go func() {
1157 awaitBlockedGoroutine(t, "sync.Cond.Wait", "blockCond", 1)
1158 mu.Lock()
1159 c.Signal()
1160 mu.Unlock()
1161 }()
1162 c.Wait()
1163 mu.Unlock()
1164 }
1165
1166
1167 func TestBlockProfileBias(t *testing.T) {
1168 rate := int(1000)
1169 runtime.SetBlockProfileRate(rate)
1170 defer runtime.SetBlockProfileRate(0)
1171
1172
1173 blockFrequentShort(rate)
1174 blockInfrequentLong(rate)
1175
1176 var w bytes.Buffer
1177 Lookup("block").WriteTo(&w, 0)
1178 p, err := profile.Parse(&w)
1179 if err != nil {
1180 t.Fatalf("failed to parse profile: %v", err)
1181 }
1182 t.Logf("parsed proto: %s", p)
1183
1184 il := float64(-1)
1185 fs := float64(-1)
1186 for _, s := range p.Sample {
1187 for _, l := range s.Location {
1188 for _, line := range l.Line {
1189 if len(s.Value) < 2 {
1190 t.Fatal("block profile has less than 2 sample types")
1191 }
1192
1193 if line.Function.Name == "runtime/pprof.blockInfrequentLong" {
1194 il = float64(s.Value[1])
1195 } else if line.Function.Name == "runtime/pprof.blockFrequentShort" {
1196 fs = float64(s.Value[1])
1197 }
1198 }
1199 }
1200 }
1201 if il == -1 || fs == -1 {
1202 t.Fatal("block profile is missing expected functions")
1203 }
1204
1205
1206 const threshold = 0.2
1207 if bias := (il - fs) / il; math.Abs(bias) > threshold {
1208 t.Fatalf("bias: abs(%f) > %f", bias, threshold)
1209 } else {
1210 t.Logf("bias: abs(%f) < %f", bias, threshold)
1211 }
1212 }
1213
1214
1215
1216 func blockFrequentShort(rate int) {
1217 for i := 0; i < 100000; i++ {
1218 blockevent(int64(rate/10), 1)
1219 }
1220 }
1221
1222
1223
1224 func blockInfrequentLong(rate int) {
1225 for i := 0; i < 10000; i++ {
1226 blockevent(int64(rate), 1)
1227 }
1228 }
1229
1230
1231
1232
1233 func blockevent(cycles int64, skip int)
1234
1235 func TestMutexProfile(t *testing.T) {
1236
1237
1238 old := runtime.SetMutexProfileFraction(1)
1239 defer runtime.SetMutexProfileFraction(old)
1240 if old != 0 {
1241 t.Fatalf("need MutexProfileRate 0, got %d", old)
1242 }
1243
1244 const (
1245 N = 100
1246 D = 100 * time.Millisecond
1247 )
1248 start := time.Now()
1249 blockMutexN(t, N, D)
1250 blockMutexNTime := time.Since(start)
1251
1252 t.Run("debug=1", func(t *testing.T) {
1253 var w strings.Builder
1254 Lookup("mutex").WriteTo(&w, 1)
1255 prof := w.String()
1256 t.Logf("received profile: %v", prof)
1257
1258 if !strings.HasPrefix(prof, "--- mutex:\ncycles/second=") {
1259 t.Errorf("Bad profile header:\n%v", prof)
1260 }
1261 prof = strings.Trim(prof, "\n")
1262 lines := strings.Split(prof, "\n")
1263 if len(lines) < 6 {
1264 t.Fatalf("expected >=6 lines, got %d %q\n%s", len(lines), prof, prof)
1265 }
1266
1267 r2 := `^\d+ \d+ @(?: 0x[[:xdigit:]]+)+`
1268 if ok, err := regexp.MatchString(r2, lines[3]); err != nil || !ok {
1269 t.Errorf("%q didn't match %q", lines[3], r2)
1270 }
1271 r3 := "^#.*runtime/pprof.blockMutex.*$"
1272 if ok, err := regexp.MatchString(r3, lines[5]); err != nil || !ok {
1273 t.Errorf("%q didn't match %q", lines[5], r3)
1274 }
1275 t.Logf(prof)
1276 })
1277 t.Run("proto", func(t *testing.T) {
1278
1279 var w bytes.Buffer
1280 Lookup("mutex").WriteTo(&w, 0)
1281 p, err := profile.Parse(&w)
1282 if err != nil {
1283 t.Fatalf("failed to parse profile: %v", err)
1284 }
1285 t.Logf("parsed proto: %s", p)
1286 if err := p.CheckValid(); err != nil {
1287 t.Fatalf("invalid profile: %v", err)
1288 }
1289
1290 stks := stacks(p)
1291 for _, want := range [][]string{
1292 {"sync.(*Mutex).Unlock", "runtime/pprof.blockMutexN.func1"},
1293 } {
1294 if !containsStack(stks, want) {
1295 t.Errorf("No matching stack entry for %+v", want)
1296 }
1297 }
1298
1299 i := 0
1300 for ; i < len(p.SampleType); i++ {
1301 if p.SampleType[i].Unit == "nanoseconds" {
1302 break
1303 }
1304 }
1305 if i >= len(p.SampleType) {
1306 t.Fatalf("profile did not contain nanoseconds sample")
1307 }
1308 total := int64(0)
1309 for _, s := range p.Sample {
1310 total += s.Value[i]
1311 }
1312
1313
1314
1315
1316
1317
1318
1319
1320 d := time.Duration(total)
1321 lo := time.Duration(N * D * 9 / 10)
1322 hi := time.Duration(N) * blockMutexNTime * 11 / 10
1323 if d < lo || d > hi {
1324 for _, s := range p.Sample {
1325 t.Logf("sample: %s", time.Duration(s.Value[i]))
1326 }
1327 t.Fatalf("profile samples total %v, want within range [%v, %v] (target: %v)", d, lo, hi, N*D)
1328 }
1329 })
1330 }
1331
1332 func TestMutexProfileRateAdjust(t *testing.T) {
1333 old := runtime.SetMutexProfileFraction(1)
1334 defer runtime.SetMutexProfileFraction(old)
1335 if old != 0 {
1336 t.Fatalf("need MutexProfileRate 0, got %d", old)
1337 }
1338
1339 readProfile := func() (contentions int64, delay int64) {
1340 var w bytes.Buffer
1341 Lookup("mutex").WriteTo(&w, 0)
1342 p, err := profile.Parse(&w)
1343 if err != nil {
1344 t.Fatalf("failed to parse profile: %v", err)
1345 }
1346 t.Logf("parsed proto: %s", p)
1347 if err := p.CheckValid(); err != nil {
1348 t.Fatalf("invalid profile: %v", err)
1349 }
1350
1351 for _, s := range p.Sample {
1352 for _, l := range s.Location {
1353 for _, line := range l.Line {
1354 if line.Function.Name == "runtime/pprof.blockMutex.func1" {
1355 contentions += s.Value[0]
1356 delay += s.Value[1]
1357 }
1358 }
1359 }
1360 }
1361 return
1362 }
1363
1364 blockMutex(t)
1365 contentions, delay := readProfile()
1366 if contentions == 0 || delay == 0 {
1367 t.Fatal("did not see expected function in profile")
1368 }
1369 runtime.SetMutexProfileFraction(0)
1370 newContentions, newDelay := readProfile()
1371 if newContentions != contentions || newDelay != delay {
1372 t.Fatalf("sample value changed: got [%d, %d], want [%d, %d]", newContentions, newDelay, contentions, delay)
1373 }
1374 }
1375
1376 func func1(c chan int) { <-c }
1377 func func2(c chan int) { <-c }
1378 func func3(c chan int) { <-c }
1379 func func4(c chan int) { <-c }
1380
1381 func TestGoroutineCounts(t *testing.T) {
1382
1383
1384 defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(1))
1385
1386 c := make(chan int)
1387 for i := 0; i < 100; i++ {
1388 switch {
1389 case i%10 == 0:
1390 go func1(c)
1391 case i%2 == 0:
1392 go func2(c)
1393 default:
1394 go func3(c)
1395 }
1396
1397 for j := 0; j < 5; j++ {
1398 runtime.Gosched()
1399 }
1400 }
1401 ctx := context.Background()
1402
1403
1404
1405 Do(ctx, Labels("label", "value"), func(context.Context) {
1406 for i := 0; i < 89; i++ {
1407 switch {
1408 case i%10 == 0:
1409 go func1(c)
1410 case i%2 == 0:
1411 go func2(c)
1412 default:
1413 go func3(c)
1414 }
1415
1416 for j := 0; j < 5; j++ {
1417 runtime.Gosched()
1418 }
1419 }
1420 })
1421
1422 SetGoroutineLabels(WithLabels(context.Background(), Labels("self-label", "self-value")))
1423 defer SetGoroutineLabels(context.Background())
1424
1425 garbage := new(*int)
1426 fingReady := make(chan struct{})
1427 runtime.SetFinalizer(garbage, func(v **int) {
1428 Do(context.Background(), Labels("fing-label", "fing-value"), func(ctx context.Context) {
1429 close(fingReady)
1430 <-c
1431 })
1432 })
1433 garbage = nil
1434 for i := 0; i < 2; i++ {
1435 runtime.GC()
1436 }
1437 <-fingReady
1438
1439 var w bytes.Buffer
1440 goroutineProf := Lookup("goroutine")
1441
1442
1443 goroutineProf.WriteTo(&w, 1)
1444 prof := w.String()
1445
1446 labels := labelMap{"label": "value"}
1447 labelStr := "\n# labels: " + labels.String()
1448 selfLabel := labelMap{"self-label": "self-value"}
1449 selfLabelStr := "\n# labels: " + selfLabel.String()
1450 fingLabel := labelMap{"fing-label": "fing-value"}
1451 fingLabelStr := "\n# labels: " + fingLabel.String()
1452 orderedPrefix := []string{
1453 "\n50 @ ",
1454 "\n44 @", labelStr,
1455 "\n40 @",
1456 "\n36 @", labelStr,
1457 "\n10 @",
1458 "\n9 @", labelStr,
1459 "\n1 @"}
1460 if !containsInOrder(prof, append(orderedPrefix, selfLabelStr)...) {
1461 t.Errorf("expected sorted goroutine counts with Labels:\n%s", prof)
1462 }
1463 if !containsInOrder(prof, append(orderedPrefix, fingLabelStr)...) {
1464 t.Errorf("expected sorted goroutine counts with Labels:\n%s", prof)
1465 }
1466
1467
1468 w.Reset()
1469 goroutineProf.WriteTo(&w, 0)
1470 p, err := profile.Parse(&w)
1471 if err != nil {
1472 t.Errorf("error parsing protobuf profile: %v", err)
1473 }
1474 if err := p.CheckValid(); err != nil {
1475 t.Errorf("protobuf profile is invalid: %v", err)
1476 }
1477 expectedLabels := map[int64]map[string]string{
1478 50: {},
1479 44: {"label": "value"},
1480 40: {},
1481 36: {"label": "value"},
1482 10: {},
1483 9: {"label": "value"},
1484 1: {"self-label": "self-value", "fing-label": "fing-value"},
1485 }
1486 if !containsCountsLabels(p, expectedLabels) {
1487 t.Errorf("expected count profile to contain goroutines with counts and labels %v, got %v",
1488 expectedLabels, p)
1489 }
1490
1491 close(c)
1492
1493 time.Sleep(10 * time.Millisecond)
1494 }
1495
1496 func containsInOrder(s string, all ...string) bool {
1497 for _, t := range all {
1498 var ok bool
1499 if _, s, ok = strings.Cut(s, t); !ok {
1500 return false
1501 }
1502 }
1503 return true
1504 }
1505
1506 func containsCountsLabels(prof *profile.Profile, countLabels map[int64]map[string]string) bool {
1507 m := make(map[int64]int)
1508 type nkey struct {
1509 count int64
1510 key, val string
1511 }
1512 n := make(map[nkey]int)
1513 for c, kv := range countLabels {
1514 m[c]++
1515 for k, v := range kv {
1516 n[nkey{
1517 count: c,
1518 key: k,
1519 val: v,
1520 }]++
1521
1522 }
1523 }
1524 for _, s := range prof.Sample {
1525
1526 if len(s.Value) != 1 {
1527 return false
1528 }
1529 m[s.Value[0]]--
1530 for k, vs := range s.Label {
1531 for _, v := range vs {
1532 n[nkey{
1533 count: s.Value[0],
1534 key: k,
1535 val: v,
1536 }]--
1537 }
1538 }
1539 }
1540 for _, n := range m {
1541 if n > 0 {
1542 return false
1543 }
1544 }
1545 for _, ncnt := range n {
1546 if ncnt != 0 {
1547 return false
1548 }
1549 }
1550 return true
1551 }
1552
1553 func TestGoroutineProfileConcurrency(t *testing.T) {
1554 testenv.MustHaveParallelism(t)
1555
1556 goroutineProf := Lookup("goroutine")
1557
1558 profilerCalls := func(s string) int {
1559 return strings.Count(s, "\truntime/pprof.runtime_goroutineProfileWithLabels+")
1560 }
1561
1562 includesFinalizer := func(s string) bool {
1563 return strings.Contains(s, "runtime.runfinq")
1564 }
1565
1566
1567
1568 t.Run("overlapping profile requests", func(t *testing.T) {
1569 ctx := context.Background()
1570 ctx, cancel := context.WithTimeout(ctx, 10*time.Second)
1571 defer cancel()
1572
1573 var wg sync.WaitGroup
1574 for i := 0; i < 2; i++ {
1575 wg.Add(1)
1576 Do(ctx, Labels("i", fmt.Sprint(i)), func(context.Context) {
1577 go func() {
1578 defer wg.Done()
1579 for ctx.Err() == nil {
1580 var w strings.Builder
1581 goroutineProf.WriteTo(&w, 1)
1582 prof := w.String()
1583 count := profilerCalls(prof)
1584 if count >= 2 {
1585 t.Logf("prof %d\n%s", count, prof)
1586 cancel()
1587 }
1588 }
1589 }()
1590 })
1591 }
1592 wg.Wait()
1593 })
1594
1595
1596
1597 t.Run("finalizer not present", func(t *testing.T) {
1598 var w strings.Builder
1599 goroutineProf.WriteTo(&w, 1)
1600 prof := w.String()
1601 if includesFinalizer(prof) {
1602 t.Errorf("profile includes finalizer (but finalizer should be marked as system):\n%s", prof)
1603 }
1604 })
1605
1606
1607 t.Run("finalizer present", func(t *testing.T) {
1608
1609
1610
1611 type T *byte
1612 obj := new(T)
1613 ch1, ch2 := make(chan int), make(chan int)
1614 defer close(ch2)
1615 runtime.SetFinalizer(obj, func(_ interface{}) {
1616 close(ch1)
1617 <-ch2
1618 })
1619 obj = nil
1620 for i := 10; i >= 0; i-- {
1621 select {
1622 case <-ch1:
1623 default:
1624 if i == 0 {
1625 t.Fatalf("finalizer did not run")
1626 }
1627 runtime.GC()
1628 }
1629 }
1630 var w strings.Builder
1631 goroutineProf.WriteTo(&w, 1)
1632 prof := w.String()
1633 if !includesFinalizer(prof) {
1634 t.Errorf("profile does not include finalizer (and it should be marked as user):\n%s", prof)
1635 }
1636 })
1637
1638
1639 testLaunches := func(t *testing.T) {
1640 var done sync.WaitGroup
1641 defer done.Wait()
1642
1643 ctx := context.Background()
1644 ctx, cancel := context.WithCancel(ctx)
1645 defer cancel()
1646
1647 ch := make(chan int)
1648 defer close(ch)
1649
1650 var ready sync.WaitGroup
1651
1652
1653
1654
1655 ready.Add(1)
1656 done.Add(1)
1657 go func() {
1658 defer done.Done()
1659 for i := 0; ctx.Err() == nil; i++ {
1660
1661
1662 SetGoroutineLabels(WithLabels(ctx, Labels(t.Name()+"-loop-i", fmt.Sprint(i))))
1663 done.Add(1)
1664 go func() {
1665 <-ch
1666 done.Done()
1667 }()
1668 for j := 0; j < i; j++ {
1669
1670
1671
1672
1673
1674
1675 runtime.Gosched()
1676 }
1677 if i == 0 {
1678 ready.Done()
1679 }
1680 }
1681 }()
1682
1683
1684
1685
1686 ready.Add(1)
1687 var churn func(i int)
1688 churn = func(i int) {
1689 SetGoroutineLabels(WithLabels(ctx, Labels(t.Name()+"-churn-i", fmt.Sprint(i))))
1690 if i == 0 {
1691 ready.Done()
1692 } else if i%16 == 0 {
1693
1694
1695 runtime.Gosched()
1696 }
1697 if ctx.Err() == nil {
1698 go churn(i + 1)
1699 }
1700 }
1701 go func() {
1702 churn(0)
1703 }()
1704
1705 ready.Wait()
1706
1707 var w [3]bytes.Buffer
1708 for i := range w {
1709 goroutineProf.WriteTo(&w[i], 0)
1710 }
1711 for i := range w {
1712 p, err := profile.Parse(bytes.NewReader(w[i].Bytes()))
1713 if err != nil {
1714 t.Errorf("error parsing protobuf profile: %v", err)
1715 }
1716
1717
1718
1719 counts := make(map[string]int)
1720 for _, s := range p.Sample {
1721 label := s.Label[t.Name()+"-loop-i"]
1722 if len(label) > 0 {
1723 counts[label[0]]++
1724 }
1725 }
1726 for j, max := 0, len(counts)-1; j <= max; j++ {
1727 n := counts[fmt.Sprint(j)]
1728 if n == 1 || (n == 2 && j == max) {
1729 continue
1730 }
1731 t.Errorf("profile #%d's goroutines with label loop-i:%d; %d != 1 (or 2 for the last entry, %d)",
1732 i+1, j, n, max)
1733 t.Logf("counts %v", counts)
1734 break
1735 }
1736 }
1737 }
1738
1739 runs := 100
1740 if testing.Short() {
1741 runs = 5
1742 }
1743 for i := 0; i < runs; i++ {
1744
1745 t.Run("goroutine launches", testLaunches)
1746 }
1747 }
1748
1749 func BenchmarkGoroutine(b *testing.B) {
1750 withIdle := func(n int, fn func(b *testing.B)) func(b *testing.B) {
1751 return func(b *testing.B) {
1752 c := make(chan int)
1753 var ready, done sync.WaitGroup
1754 defer func() {
1755 close(c)
1756 done.Wait()
1757 }()
1758
1759 for i := 0; i < n; i++ {
1760 ready.Add(1)
1761 done.Add(1)
1762 go func() {
1763 ready.Done()
1764 <-c
1765 done.Done()
1766 }()
1767 }
1768
1769 ready.Wait()
1770 for i := 0; i < 5; i++ {
1771 runtime.Gosched()
1772 }
1773
1774 fn(b)
1775 }
1776 }
1777
1778 withChurn := func(fn func(b *testing.B)) func(b *testing.B) {
1779 return func(b *testing.B) {
1780 ctx := context.Background()
1781 ctx, cancel := context.WithCancel(ctx)
1782 defer cancel()
1783
1784 var ready sync.WaitGroup
1785 ready.Add(1)
1786 var count int64
1787 var churn func(i int)
1788 churn = func(i int) {
1789 SetGoroutineLabels(WithLabels(ctx, Labels("churn-i", fmt.Sprint(i))))
1790 atomic.AddInt64(&count, 1)
1791 if i == 0 {
1792 ready.Done()
1793 }
1794 if ctx.Err() == nil {
1795 go churn(i + 1)
1796 }
1797 }
1798 go func() {
1799 churn(0)
1800 }()
1801 ready.Wait()
1802
1803 fn(b)
1804 b.ReportMetric(float64(atomic.LoadInt64(&count))/float64(b.N), "concurrent_launches/op")
1805 }
1806 }
1807
1808 benchWriteTo := func(b *testing.B) {
1809 goroutineProf := Lookup("goroutine")
1810 b.ResetTimer()
1811 for i := 0; i < b.N; i++ {
1812 goroutineProf.WriteTo(io.Discard, 0)
1813 }
1814 b.StopTimer()
1815 }
1816
1817 benchGoroutineProfile := func(b *testing.B) {
1818 p := make([]runtime.StackRecord, 10000)
1819 b.ResetTimer()
1820 for i := 0; i < b.N; i++ {
1821 runtime.GoroutineProfile(p)
1822 }
1823 b.StopTimer()
1824 }
1825
1826
1827
1828
1829 for _, n := range []int{50, 500, 5000} {
1830 b.Run(fmt.Sprintf("Profile.WriteTo idle %d", n), withIdle(n, benchWriteTo))
1831 b.Run(fmt.Sprintf("Profile.WriteTo churn %d", n), withIdle(n, withChurn(benchWriteTo)))
1832 b.Run(fmt.Sprintf("runtime.GoroutineProfile churn %d", n), withIdle(n, withChurn(benchGoroutineProfile)))
1833 }
1834 }
1835
1836 var emptyCallStackTestRun int64
1837
1838
1839 func TestEmptyCallStack(t *testing.T) {
1840 name := fmt.Sprintf("test18836_%d", emptyCallStackTestRun)
1841 emptyCallStackTestRun++
1842
1843 t.Parallel()
1844 var buf strings.Builder
1845 p := NewProfile(name)
1846
1847 p.Add("foo", 47674)
1848 p.WriteTo(&buf, 1)
1849 p.Remove("foo")
1850 got := buf.String()
1851 prefix := name + " profile: total 1\n"
1852 if !strings.HasPrefix(got, prefix) {
1853 t.Fatalf("got:\n\t%q\nwant prefix:\n\t%q\n", got, prefix)
1854 }
1855 lostevent := "lostProfileEvent"
1856 if !strings.Contains(got, lostevent) {
1857 t.Fatalf("got:\n\t%q\ndoes not contain:\n\t%q\n", got, lostevent)
1858 }
1859 }
1860
1861
1862
1863 func stackContainsLabeled(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
1864 base, kv, ok := strings.Cut(spec, ";")
1865 if !ok {
1866 panic("no semicolon in key/value spec")
1867 }
1868 k, v, ok := strings.Cut(kv, "=")
1869 if !ok {
1870 panic("missing = in key/value spec")
1871 }
1872 if !contains(labels[k], v) {
1873 return false
1874 }
1875 return stackContains(base, count, stk, labels)
1876 }
1877
1878 func TestCPUProfileLabel(t *testing.T) {
1879 matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, avoidFunctions())
1880 testCPUProfile(t, matches, func(dur time.Duration) {
1881 Do(context.Background(), Labels("key", "value"), func(context.Context) {
1882 cpuHogger(cpuHog1, &salt1, dur)
1883 })
1884 })
1885 }
1886
1887 func TestLabelRace(t *testing.T) {
1888 testenv.MustHaveParallelism(t)
1889
1890
1891
1892 matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, nil)
1893 testCPUProfile(t, matches, func(dur time.Duration) {
1894 start := time.Now()
1895 var wg sync.WaitGroup
1896 for time.Since(start) < dur {
1897 var salts [10]int
1898 for i := 0; i < 10; i++ {
1899 wg.Add(1)
1900 go func(j int) {
1901 Do(context.Background(), Labels("key", "value"), func(context.Context) {
1902 cpuHogger(cpuHog1, &salts[j], time.Millisecond)
1903 })
1904 wg.Done()
1905 }(i)
1906 }
1907 wg.Wait()
1908 }
1909 })
1910 }
1911
1912 func TestGoroutineProfileLabelRace(t *testing.T) {
1913 testenv.MustHaveParallelism(t)
1914
1915
1916
1917
1918 t.Run("reset", func(t *testing.T) {
1919 ctx := context.Background()
1920 ctx, cancel := context.WithCancel(ctx)
1921 defer cancel()
1922
1923 go func() {
1924 goroutineProf := Lookup("goroutine")
1925 for ctx.Err() == nil {
1926 var w strings.Builder
1927 goroutineProf.WriteTo(&w, 1)
1928 prof := w.String()
1929 if strings.Contains(prof, "loop-i") {
1930 cancel()
1931 }
1932 }
1933 }()
1934
1935 for i := 0; ctx.Err() == nil; i++ {
1936 Do(ctx, Labels("loop-i", fmt.Sprint(i)), func(ctx context.Context) {
1937 })
1938 }
1939 })
1940
1941 t.Run("churn", func(t *testing.T) {
1942 ctx := context.Background()
1943 ctx, cancel := context.WithCancel(ctx)
1944 defer cancel()
1945
1946 var ready sync.WaitGroup
1947 ready.Add(1)
1948 var churn func(i int)
1949 churn = func(i int) {
1950 SetGoroutineLabels(WithLabels(ctx, Labels("churn-i", fmt.Sprint(i))))
1951 if i == 0 {
1952 ready.Done()
1953 }
1954 if ctx.Err() == nil {
1955 go churn(i + 1)
1956 }
1957 }
1958 go func() {
1959 churn(0)
1960 }()
1961 ready.Wait()
1962
1963 goroutineProf := Lookup("goroutine")
1964 for i := 0; i < 10; i++ {
1965 goroutineProf.WriteTo(io.Discard, 1)
1966 }
1967 })
1968 }
1969
1970
1971
1972 func TestLabelSystemstack(t *testing.T) {
1973
1974
1975 gogc := debug.SetGCPercent(100)
1976 debug.SetGCPercent(gogc)
1977
1978 matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime.systemstack;key=value"}, avoidFunctions())
1979 p := testCPUProfile(t, matches, func(dur time.Duration) {
1980 Do(context.Background(), Labels("key", "value"), func(ctx context.Context) {
1981 parallelLabelHog(ctx, dur, gogc)
1982 })
1983 })
1984
1985
1986
1987
1988 for _, s := range p.Sample {
1989 isLabeled := s.Label != nil && contains(s.Label["key"], "value")
1990 var (
1991 mayBeLabeled bool
1992 mustBeLabeled string
1993 mustNotBeLabeled string
1994 )
1995 for _, loc := range s.Location {
1996 for _, l := range loc.Line {
1997 switch l.Function.Name {
1998 case "runtime/pprof.labelHog", "runtime/pprof.parallelLabelHog", "runtime/pprof.parallelLabelHog.func1":
1999 mustBeLabeled = l.Function.Name
2000 case "runtime/pprof.Do":
2001
2002
2003
2004
2005 mayBeLabeled = true
2006 case "runtime.bgsweep", "runtime.bgscavenge", "runtime.forcegchelper", "runtime.gcBgMarkWorker", "runtime.runfinq", "runtime.sysmon":
2007
2008
2009
2010
2011 mustNotBeLabeled = l.Function.Name
2012 case "gogo", "gosave_systemstack_switch", "racecall":
2013
2014
2015
2016
2017
2018
2019 mayBeLabeled = true
2020 }
2021
2022 if strings.HasPrefix(l.Function.Name, "runtime.") {
2023
2024
2025
2026
2027
2028
2029 mayBeLabeled = true
2030 }
2031 }
2032 }
2033 errorStack := func(f string, args ...any) {
2034 var buf strings.Builder
2035 fprintStack(&buf, s.Location)
2036 t.Errorf("%s: %s", fmt.Sprintf(f, args...), buf.String())
2037 }
2038 if mustBeLabeled != "" && mustNotBeLabeled != "" {
2039 errorStack("sample contains both %s, which must be labeled, and %s, which must not be labeled", mustBeLabeled, mustNotBeLabeled)
2040 continue
2041 }
2042 if mustBeLabeled != "" || mustNotBeLabeled != "" {
2043
2044 mayBeLabeled = false
2045 }
2046 if mayBeLabeled {
2047
2048 continue
2049 }
2050 if mustBeLabeled != "" && !isLabeled {
2051 errorStack("sample must be labeled because of %s, but is not", mustBeLabeled)
2052 }
2053 if mustNotBeLabeled != "" && isLabeled {
2054 errorStack("sample must not be labeled because of %s, but is", mustNotBeLabeled)
2055 }
2056 }
2057 }
2058
2059
2060
2061 func labelHog(stop chan struct{}, gogc int) {
2062
2063
2064 runtime.GC()
2065
2066 for i := 0; ; i++ {
2067 select {
2068 case <-stop:
2069 return
2070 default:
2071 debug.SetGCPercent(gogc)
2072 }
2073 }
2074 }
2075
2076
2077 func parallelLabelHog(ctx context.Context, dur time.Duration, gogc int) {
2078 var wg sync.WaitGroup
2079 stop := make(chan struct{})
2080 for i := 0; i < runtime.GOMAXPROCS(0); i++ {
2081 wg.Add(1)
2082 go func() {
2083 defer wg.Done()
2084 labelHog(stop, gogc)
2085 }()
2086 }
2087
2088 time.Sleep(dur)
2089 close(stop)
2090 wg.Wait()
2091 }
2092
2093
2094
2095 func TestAtomicLoadStore64(t *testing.T) {
2096 f, err := os.CreateTemp("", "profatomic")
2097 if err != nil {
2098 t.Fatalf("TempFile: %v", err)
2099 }
2100 defer os.Remove(f.Name())
2101 defer f.Close()
2102
2103 if err := StartCPUProfile(f); err != nil {
2104 t.Fatal(err)
2105 }
2106 defer StopCPUProfile()
2107
2108 var flag uint64
2109 done := make(chan bool, 1)
2110
2111 go func() {
2112 for atomic.LoadUint64(&flag) == 0 {
2113 runtime.Gosched()
2114 }
2115 done <- true
2116 }()
2117 time.Sleep(50 * time.Millisecond)
2118 atomic.StoreUint64(&flag, 1)
2119 <-done
2120 }
2121
2122 func TestTracebackAll(t *testing.T) {
2123
2124
2125 f, err := os.CreateTemp("", "proftraceback")
2126 if err != nil {
2127 t.Fatalf("TempFile: %v", err)
2128 }
2129 defer os.Remove(f.Name())
2130 defer f.Close()
2131
2132 if err := StartCPUProfile(f); err != nil {
2133 t.Fatal(err)
2134 }
2135 defer StopCPUProfile()
2136
2137 ch := make(chan int)
2138 defer close(ch)
2139
2140 count := 10
2141 for i := 0; i < count; i++ {
2142 go func() {
2143 <-ch
2144 }()
2145 }
2146
2147 N := 10000
2148 if testing.Short() {
2149 N = 500
2150 }
2151 buf := make([]byte, 10*1024)
2152 for i := 0; i < N; i++ {
2153 runtime.Stack(buf, true)
2154 }
2155 }
2156
2157
2158
2159
2160
2161
2162
2163 func TestTryAdd(t *testing.T) {
2164 if _, found := findInlinedCall(inlinedCallerDump, 4<<10); !found {
2165 t.Skip("Can't determine whether anything was inlined into inlinedCallerDump.")
2166 }
2167
2168
2169
2170 pcs := make([]uintptr, 2)
2171 inlinedCallerDump(pcs)
2172 inlinedCallerStack := make([]uint64, 2)
2173 for i := range pcs {
2174 inlinedCallerStack[i] = uint64(pcs[i])
2175 }
2176 wrapperPCs := make([]uintptr, 1)
2177 inlinedWrapperCallerDump(wrapperPCs)
2178
2179 if _, found := findInlinedCall(recursionChainBottom, 4<<10); !found {
2180 t.Skip("Can't determine whether anything was inlined into recursionChainBottom.")
2181 }
2182
2183
2184
2185
2186
2187
2188
2189 pcs = make([]uintptr, 6)
2190 recursionChainTop(1, pcs)
2191 recursionStack := make([]uint64, len(pcs))
2192 for i := range pcs {
2193 recursionStack[i] = uint64(pcs[i])
2194 }
2195
2196 period := int64(2000 * 1000)
2197
2198 testCases := []struct {
2199 name string
2200 input []uint64
2201 count int
2202 wantLocs [][]string
2203 wantSamples []*profile.Sample
2204 }{{
2205
2206 name: "full_stack_trace",
2207 input: []uint64{
2208 3, 0, 500,
2209 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
2210 },
2211 count: 2,
2212 wantLocs: [][]string{
2213 {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
2214 },
2215 wantSamples: []*profile.Sample{
2216 {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
2217 },
2218 }, {
2219 name: "bug35538",
2220 input: []uint64{
2221 3, 0, 500,
2222
2223
2224
2225 7, 0, 10, inlinedCallerStack[0], inlinedCallerStack[1], inlinedCallerStack[0], inlinedCallerStack[1],
2226 5, 0, 20, inlinedCallerStack[0], inlinedCallerStack[1],
2227 },
2228 count: 3,
2229 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
2230 wantSamples: []*profile.Sample{
2231 {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}},
2232 {Value: []int64{20, 20 * period}, Location: []*profile.Location{{ID: 1}}},
2233 },
2234 }, {
2235 name: "bug38096",
2236 input: []uint64{
2237 3, 0, 500,
2238
2239
2240 4, 0, 0, 4242,
2241 },
2242 count: 2,
2243 wantLocs: [][]string{{"runtime/pprof.lostProfileEvent"}},
2244 wantSamples: []*profile.Sample{
2245 {Value: []int64{4242, 4242 * period}, Location: []*profile.Location{{ID: 1}}},
2246 },
2247 }, {
2248
2249
2250
2251
2252
2253
2254
2255 name: "directly_recursive_func_is_not_inlined",
2256 input: []uint64{
2257 3, 0, 500,
2258 5, 0, 30, inlinedCallerStack[0], inlinedCallerStack[0],
2259 4, 0, 40, inlinedCallerStack[0],
2260 },
2261 count: 3,
2262
2263
2264 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump"}, {"runtime/pprof.inlinedCallerDump"}},
2265 wantSamples: []*profile.Sample{
2266 {Value: []int64{30, 30 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}, {ID: 2}}},
2267 {Value: []int64{40, 40 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}}},
2268 },
2269 }, {
2270 name: "recursion_chain_inline",
2271 input: []uint64{
2272 3, 0, 500,
2273 9, 0, 10, recursionStack[0], recursionStack[1], recursionStack[2], recursionStack[3], recursionStack[4], recursionStack[5],
2274 },
2275 count: 2,
2276 wantLocs: [][]string{
2277 {"runtime/pprof.recursionChainBottom"},
2278 {
2279 "runtime/pprof.recursionChainMiddle",
2280 "runtime/pprof.recursionChainTop",
2281 "runtime/pprof.recursionChainBottom",
2282 },
2283 {
2284 "runtime/pprof.recursionChainMiddle",
2285 "runtime/pprof.recursionChainTop",
2286 "runtime/pprof.TestTryAdd",
2287 },
2288 },
2289 wantSamples: []*profile.Sample{
2290 {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}, {ID: 3}}},
2291 },
2292 }, {
2293 name: "truncated_stack_trace_later",
2294 input: []uint64{
2295 3, 0, 500,
2296 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
2297 4, 0, 60, inlinedCallerStack[0],
2298 },
2299 count: 3,
2300 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
2301 wantSamples: []*profile.Sample{
2302 {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
2303 {Value: []int64{60, 60 * period}, Location: []*profile.Location{{ID: 1}}},
2304 },
2305 }, {
2306 name: "truncated_stack_trace_first",
2307 input: []uint64{
2308 3, 0, 500,
2309 4, 0, 70, inlinedCallerStack[0],
2310 5, 0, 80, inlinedCallerStack[0], inlinedCallerStack[1],
2311 },
2312 count: 3,
2313 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
2314 wantSamples: []*profile.Sample{
2315 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
2316 {Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 1}}},
2317 },
2318 }, {
2319
2320 name: "truncated_stack_trace_only",
2321 input: []uint64{
2322 3, 0, 500,
2323 4, 0, 70, inlinedCallerStack[0],
2324 },
2325 count: 2,
2326 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
2327 wantSamples: []*profile.Sample{
2328 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
2329 },
2330 }, {
2331
2332 name: "truncated_stack_trace_twice",
2333 input: []uint64{
2334 3, 0, 500,
2335 4, 0, 70, inlinedCallerStack[0],
2336
2337
2338
2339 5, 0, 80, inlinedCallerStack[1], inlinedCallerStack[0],
2340 },
2341 count: 3,
2342 wantLocs: [][]string{
2343 {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
2344 {"runtime/pprof.inlinedCallerDump"},
2345 },
2346 wantSamples: []*profile.Sample{
2347 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
2348 {Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 2}, {ID: 1}}},
2349 },
2350 }, {
2351 name: "expand_wrapper_function",
2352 input: []uint64{
2353 3, 0, 500,
2354 4, 0, 50, uint64(wrapperPCs[0]),
2355 },
2356 count: 2,
2357 wantLocs: [][]string{{"runtime/pprof.inlineWrapper.dump"}},
2358 wantSamples: []*profile.Sample{
2359 {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
2360 },
2361 }}
2362
2363 for _, tc := range testCases {
2364 t.Run(tc.name, func(t *testing.T) {
2365 p, err := translateCPUProfile(tc.input, tc.count)
2366 if err != nil {
2367 t.Fatalf("translating profile: %v", err)
2368 }
2369 t.Logf("Profile: %v\n", p)
2370
2371
2372 var gotLoc [][]string
2373 for _, loc := range p.Location {
2374 var names []string
2375 for _, line := range loc.Line {
2376 names = append(names, line.Function.Name)
2377 }
2378 gotLoc = append(gotLoc, names)
2379 }
2380 if got, want := fmtJSON(gotLoc), fmtJSON(tc.wantLocs); got != want {
2381 t.Errorf("Got Location = %+v\n\twant %+v", got, want)
2382 }
2383
2384 var gotSamples []*profile.Sample
2385 for _, sample := range p.Sample {
2386 var locs []*profile.Location
2387 for _, loc := range sample.Location {
2388 locs = append(locs, &profile.Location{ID: loc.ID})
2389 }
2390 gotSamples = append(gotSamples, &profile.Sample{Value: sample.Value, Location: locs})
2391 }
2392 if got, want := fmtJSON(gotSamples), fmtJSON(tc.wantSamples); got != want {
2393 t.Errorf("Got Samples = %+v\n\twant %+v", got, want)
2394 }
2395 })
2396 }
2397 }
2398
2399 func TestTimeVDSO(t *testing.T) {
2400
2401
2402
2403 if runtime.GOOS == "android" {
2404
2405 testenv.SkipFlaky(t, 48655)
2406 }
2407
2408 matches := matchAndAvoidStacks(stackContains, []string{"time.now"}, avoidFunctions())
2409 p := testCPUProfile(t, matches, func(dur time.Duration) {
2410 t0 := time.Now()
2411 for {
2412 t := time.Now()
2413 if t.Sub(t0) >= dur {
2414 return
2415 }
2416 }
2417 })
2418
2419
2420 for _, sample := range p.Sample {
2421 var seenNow bool
2422 for _, loc := range sample.Location {
2423 for _, line := range loc.Line {
2424 if line.Function.Name == "time.now" {
2425 if seenNow {
2426 t.Fatalf("unexpected recursive time.now")
2427 }
2428 seenNow = true
2429 }
2430 }
2431 }
2432 }
2433 }
2434
View as plain text