github.com/lzhfromustc/gofuzz@v0.0.0-20211116160056-151b3108bbd1/runtime/pprof/pprof_test.go (about) 1 // Copyright 2011 The Go Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style 3 // license that can be found in the LICENSE file. 4 5 // +build !js 6 7 package pprof 8 9 import ( 10 "bytes" 11 "context" 12 "fmt" 13 "internal/profile" 14 "internal/testenv" 15 "io" 16 "math/big" 17 "os" 18 "os/exec" 19 "regexp" 20 "runtime" 21 "strings" 22 "sync" 23 "sync/atomic" 24 "testing" 25 "time" 26 ) 27 28 func cpuHogger(f func(x int) int, y *int, dur time.Duration) { 29 // We only need to get one 100 Hz clock tick, so we've got 30 // a large safety buffer. 31 // But do at least 500 iterations (which should take about 100ms), 32 // otherwise TestCPUProfileMultithreaded can fail if only one 33 // thread is scheduled during the testing period. 34 t0 := time.Now() 35 accum := *y 36 for i := 0; i < 500 || time.Since(t0) < dur; i++ { 37 accum = f(accum) 38 } 39 *y = accum 40 } 41 42 var ( 43 salt1 = 0 44 salt2 = 0 45 ) 46 47 // The actual CPU hogging function. 48 // Must not call other functions nor access heap/globals in the loop, 49 // otherwise under race detector the samples will be in the race runtime. 50 func cpuHog1(x int) int { 51 return cpuHog0(x, 1e5) 52 } 53 54 func cpuHog0(x, n int) int { 55 foo := x 56 for i := 0; i < n; i++ { 57 if foo > 0 { 58 foo *= foo 59 } else { 60 foo *= foo + 1 61 } 62 } 63 return foo 64 } 65 66 func cpuHog2(x int) int { 67 foo := x 68 for i := 0; i < 1e5; i++ { 69 if foo > 0 { 70 foo *= foo 71 } else { 72 foo *= foo + 2 73 } 74 } 75 return foo 76 } 77 78 // Return a list of functions that we don't want to ever appear in CPU 79 // profiles. For gccgo, that list includes the sigprof handler itself. 80 func avoidFunctions() []string { 81 if runtime.Compiler == "gccgo" { 82 return []string{"runtime.sigprof"} 83 } 84 return nil 85 } 86 87 func TestCPUProfile(t *testing.T) { 88 testCPUProfile(t, stackContains, []string{"runtime/pprof.cpuHog1"}, avoidFunctions(), func(dur time.Duration) { 89 cpuHogger(cpuHog1, &salt1, dur) 90 }) 91 } 92 93 func TestCPUProfileMultithreaded(t *testing.T) { 94 defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(2)) 95 testCPUProfile(t, stackContains, []string{"runtime/pprof.cpuHog1", "runtime/pprof.cpuHog2"}, avoidFunctions(), func(dur time.Duration) { 96 c := make(chan int) 97 go func() { 98 cpuHogger(cpuHog1, &salt1, dur) 99 c <- 1 100 }() 101 cpuHogger(cpuHog2, &salt2, dur) 102 <-c 103 }) 104 } 105 106 // containsInlinedCall reports whether the function body for the function f is 107 // known to contain an inlined function call within the first maxBytes bytes. 108 func containsInlinedCall(f interface{}, maxBytes int) bool { 109 _, found := findInlinedCall(f, maxBytes) 110 return found 111 } 112 113 // findInlinedCall returns the PC of an inlined function call within 114 // the function body for the function f if any. 115 func findInlinedCall(f interface{}, maxBytes int) (pc uint64, found bool) { 116 fFunc := runtime.FuncForPC(uintptr(funcPC(f))) 117 if fFunc == nil || fFunc.Entry() == 0 { 118 panic("failed to locate function entry") 119 } 120 121 for offset := 0; offset < maxBytes; offset++ { 122 innerPC := fFunc.Entry() + uintptr(offset) 123 inner := runtime.FuncForPC(innerPC) 124 if inner == nil { 125 // No function known for this PC value. 126 // It might simply be misaligned, so keep searching. 127 continue 128 } 129 if inner.Entry() != fFunc.Entry() { 130 // Scanned past f and didn't find any inlined functions. 131 break 132 } 133 if inner.Name() != fFunc.Name() { 134 // This PC has f as its entry-point, but is not f. Therefore, it must be a 135 // function inlined into f. 136 return uint64(innerPC), true 137 } 138 } 139 140 return 0, false 141 } 142 143 func TestCPUProfileInlining(t *testing.T) { 144 if !containsInlinedCall(inlinedCaller, 4<<10) { 145 t.Skip("Can't determine whether inlinedCallee was inlined into inlinedCaller.") 146 } 147 148 p := testCPUProfile(t, stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.inlinedCaller"}, avoidFunctions(), func(dur time.Duration) { 149 cpuHogger(inlinedCaller, &salt1, dur) 150 }) 151 152 // Check if inlined function locations are encoded correctly. The inlinedCalee and inlinedCaller should be in one location. 153 for _, loc := range p.Location { 154 hasInlinedCallerAfterInlinedCallee, hasInlinedCallee := false, false 155 for _, line := range loc.Line { 156 if line.Function.Name == "runtime/pprof.inlinedCallee" { 157 hasInlinedCallee = true 158 } 159 if hasInlinedCallee && line.Function.Name == "runtime/pprof.inlinedCaller" { 160 hasInlinedCallerAfterInlinedCallee = true 161 } 162 } 163 if hasInlinedCallee != hasInlinedCallerAfterInlinedCallee { 164 t.Fatalf("want inlinedCallee followed by inlinedCaller, got separate Location entries:\n%v", p) 165 } 166 } 167 } 168 169 func inlinedCaller(x int) int { 170 x = inlinedCallee(x, 1e5) 171 return x 172 } 173 174 func inlinedCallee(x, n int) int { 175 return cpuHog0(x, n) 176 } 177 178 //go:noinline 179 func dumpCallers(pcs []uintptr) { 180 if pcs == nil { 181 return 182 } 183 184 skip := 2 // Callers and dumpCallers 185 runtime.Callers(skip, pcs) 186 } 187 188 //go:noinline 189 func inlinedCallerDump(pcs []uintptr) { 190 inlinedCalleeDump(pcs) 191 } 192 193 func inlinedCalleeDump(pcs []uintptr) { 194 dumpCallers(pcs) 195 } 196 197 func TestCPUProfileRecursion(t *testing.T) { 198 p := testCPUProfile(t, stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.recursionCallee", "runtime/pprof.recursionCaller"}, avoidFunctions(), func(dur time.Duration) { 199 cpuHogger(recursionCaller, &salt1, dur) 200 }) 201 202 // check the Location encoding was not confused by recursive calls. 203 for i, loc := range p.Location { 204 recursionFunc := 0 205 for _, line := range loc.Line { 206 if name := line.Function.Name; name == "runtime/pprof.recursionCaller" || name == "runtime/pprof.recursionCallee" { 207 recursionFunc++ 208 } 209 } 210 if recursionFunc > 1 { 211 t.Fatalf("want at most one recursionCaller or recursionCallee in one Location, got a violating Location (index: %d):\n%v", i, p) 212 } 213 } 214 } 215 216 func recursionCaller(x int) int { 217 y := recursionCallee(3, x) 218 return y 219 } 220 221 func recursionCallee(n, x int) int { 222 if n == 0 { 223 return 1 224 } 225 y := inlinedCallee(x, 1e4) 226 return y * recursionCallee(n-1, x) 227 } 228 229 func recursionChainTop(x int, pcs []uintptr) { 230 if x < 0 { 231 return 232 } 233 recursionChainMiddle(x, pcs) 234 } 235 236 func recursionChainMiddle(x int, pcs []uintptr) { 237 recursionChainBottom(x, pcs) 238 } 239 240 func recursionChainBottom(x int, pcs []uintptr) { 241 // This will be called each time, we only care about the last. We 242 // can't make this conditional or this function won't be inlined. 243 dumpCallers(pcs) 244 245 recursionChainTop(x-1, pcs) 246 } 247 248 func parseProfile(t *testing.T, valBytes []byte, f func(uintptr, []*profile.Location, map[string][]string)) *profile.Profile { 249 p, err := profile.Parse(bytes.NewReader(valBytes)) 250 if err != nil { 251 t.Fatal(err) 252 } 253 for _, sample := range p.Sample { 254 count := uintptr(sample.Value[0]) 255 f(count, sample.Location, sample.Label) 256 } 257 return p 258 } 259 260 // testCPUProfile runs f under the CPU profiler, checking for some conditions specified by need, 261 // as interpreted by matches, and returns the parsed profile. 262 func testCPUProfile(t *testing.T, matches matchFunc, need []string, avoid []string, f func(dur time.Duration)) *profile.Profile { 263 switch runtime.GOOS { 264 case "darwin", "ios": 265 switch runtime.GOARCH { 266 case "arm64": 267 // nothing 268 default: 269 out, err := exec.Command("uname", "-a").CombinedOutput() 270 if err != nil { 271 t.Fatal(err) 272 } 273 vers := string(out) 274 t.Logf("uname -a: %v", vers) 275 } 276 case "plan9": 277 t.Skip("skipping on plan9") 278 } 279 280 broken := false 281 switch runtime.GOOS { 282 // See https://golang.org/issue/45170 for AIX. 283 case "darwin", "ios", "dragonfly", "netbsd", "illumos", "solaris", "aix": 284 broken = true 285 case "openbsd": 286 if runtime.GOARCH == "arm" || runtime.GOARCH == "arm64" { 287 broken = true 288 } 289 case "windows": 290 if runtime.GOARCH == "arm" { 291 broken = true // See https://golang.org/issues/42862 292 } 293 } 294 295 maxDuration := 5 * time.Second 296 if testing.Short() && broken { 297 // If it's expected to be broken, no point waiting around. 298 maxDuration /= 10 299 } 300 301 // If we're running a long test, start with a long duration 302 // for tests that try to make sure something *doesn't* happen. 303 duration := 5 * time.Second 304 if testing.Short() { 305 duration = 100 * time.Millisecond 306 } 307 308 // Profiling tests are inherently flaky, especially on a 309 // loaded system, such as when this test is running with 310 // several others under go test std. If a test fails in a way 311 // that could mean it just didn't run long enough, try with a 312 // longer duration. 313 for duration <= maxDuration { 314 var prof bytes.Buffer 315 if err := StartCPUProfile(&prof); err != nil { 316 t.Fatal(err) 317 } 318 f(duration) 319 StopCPUProfile() 320 321 if p, ok := profileOk(t, matches, need, avoid, prof, duration); ok { 322 return p 323 } 324 325 duration *= 2 326 if duration <= maxDuration { 327 t.Logf("retrying with %s duration", duration) 328 } 329 } 330 331 if broken { 332 t.Skipf("ignoring failure on %s/%s; see golang.org/issue/13841", runtime.GOOS, runtime.GOARCH) 333 } 334 335 // Ignore the failure if the tests are running in a QEMU-based emulator, 336 // QEMU is not perfect at emulating everything. 337 // IN_QEMU environmental variable is set by some of the Go builders. 338 // IN_QEMU=1 indicates that the tests are running in QEMU. See issue 9605. 339 if os.Getenv("IN_QEMU") == "1" { 340 t.Skip("ignore the failure in QEMU; see golang.org/issue/9605") 341 } 342 t.FailNow() 343 return nil 344 } 345 346 func contains(slice []string, s string) bool { 347 for i := range slice { 348 if slice[i] == s { 349 return true 350 } 351 } 352 return false 353 } 354 355 // stackContains matches if a function named spec appears anywhere in the stack trace. 356 func stackContains(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool { 357 for _, loc := range stk { 358 for _, line := range loc.Line { 359 if strings.Contains(line.Function.Name, spec) { 360 return true 361 } 362 } 363 } 364 return false 365 } 366 367 type matchFunc func(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool 368 369 func profileOk(t *testing.T, matches matchFunc, need []string, avoid []string, prof bytes.Buffer, duration time.Duration) (_ *profile.Profile, ok bool) { 370 ok = true 371 372 // Check that profile is well formed, contains 'need', and does not contain 373 // anything from 'avoid'. 374 have := make([]uintptr, len(need)) 375 avoidSamples := make([]uintptr, len(avoid)) 376 var samples uintptr 377 var buf bytes.Buffer 378 p := parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, labels map[string][]string) { 379 fmt.Fprintf(&buf, "%d:", count) 380 fprintStack(&buf, stk) 381 samples += count 382 for i, spec := range need { 383 if matches(spec, count, stk, labels) { 384 have[i] += count 385 } 386 } 387 for i, name := range avoid { 388 for _, loc := range stk { 389 for _, line := range loc.Line { 390 if strings.Contains(line.Function.Name, name) { 391 avoidSamples[i] += count 392 } 393 } 394 } 395 } 396 fmt.Fprintf(&buf, "\n") 397 }) 398 t.Logf("total %d CPU profile samples collected:\n%s", samples, buf.String()) 399 400 if samples < 10 && runtime.GOOS == "windows" { 401 // On some windows machines we end up with 402 // not enough samples due to coarse timer 403 // resolution. Let it go. 404 t.Log("too few samples on Windows (golang.org/issue/10842)") 405 return p, false 406 } 407 408 // Check that we got a reasonable number of samples. 409 // We used to always require at least ideal/4 samples, 410 // but that is too hard to guarantee on a loaded system. 411 // Now we accept 10 or more samples, which we take to be 412 // enough to show that at least some profiling is occurring. 413 if ideal := uintptr(duration * 100 / time.Second); samples == 0 || (samples < ideal/4 && samples < 10) { 414 t.Logf("too few samples; got %d, want at least %d, ideally %d", samples, ideal/4, ideal) 415 ok = false 416 } 417 418 for i, name := range avoid { 419 bad := avoidSamples[i] 420 if bad != 0 { 421 t.Logf("found %d samples in avoid-function %s\n", bad, name) 422 ok = false 423 } 424 } 425 426 if len(need) == 0 { 427 return p, ok 428 } 429 430 var total uintptr 431 for i, name := range need { 432 total += have[i] 433 t.Logf("%s: %d\n", name, have[i]) 434 } 435 if total == 0 { 436 t.Logf("no samples in expected functions") 437 ok = false 438 } 439 // We'd like to check a reasonable minimum, like 440 // total / len(have) / smallconstant, but this test is 441 // pretty flaky (see bug 7095). So we'll just test to 442 // make sure we got at least one sample. 443 min := uintptr(1) 444 for i, name := range need { 445 if have[i] < min { 446 t.Logf("%s has %d samples out of %d, want at least %d, ideally %d", name, have[i], total, min, total/uintptr(len(have))) 447 ok = false 448 } 449 } 450 return p, ok 451 } 452 453 // Fork can hang if preempted with signals frequently enough (see issue 5517). 454 // Ensure that we do not do this. 455 func TestCPUProfileWithFork(t *testing.T) { 456 testenv.MustHaveExec(t) 457 458 heap := 1 << 30 459 if runtime.GOOS == "android" { 460 // Use smaller size for Android to avoid crash. 461 heap = 100 << 20 462 } 463 if runtime.GOOS == "windows" && runtime.GOARCH == "arm" { 464 // Use smaller heap for Windows/ARM to avoid crash. 465 heap = 100 << 20 466 } 467 if testing.Short() { 468 heap = 100 << 20 469 } 470 // This makes fork slower. 471 garbage := make([]byte, heap) 472 // Need to touch the slice, otherwise it won't be paged in. 473 done := make(chan bool) 474 go func() { 475 for i := range garbage { 476 garbage[i] = 42 477 } 478 done <- true 479 }() 480 <-done 481 482 var prof bytes.Buffer 483 if err := StartCPUProfile(&prof); err != nil { 484 t.Fatal(err) 485 } 486 defer StopCPUProfile() 487 488 for i := 0; i < 10; i++ { 489 exec.Command(os.Args[0], "-h").CombinedOutput() 490 } 491 } 492 493 // Test that profiler does not observe runtime.gogo as "user" goroutine execution. 494 // If it did, it would see inconsistent state and would either record an incorrect stack 495 // or crash because the stack was malformed. 496 func TestGoroutineSwitch(t *testing.T) { 497 if runtime.Compiler == "gccgo" { 498 t.Skip("not applicable for gccgo") 499 } 500 // How much to try. These defaults take about 1 seconds 501 // on a 2012 MacBook Pro. The ones in short mode take 502 // about 0.1 seconds. 503 tries := 10 504 count := 1000000 505 if testing.Short() { 506 tries = 1 507 } 508 for try := 0; try < tries; try++ { 509 var prof bytes.Buffer 510 if err := StartCPUProfile(&prof); err != nil { 511 t.Fatal(err) 512 } 513 for i := 0; i < count; i++ { 514 runtime.Gosched() 515 } 516 StopCPUProfile() 517 518 // Read profile to look for entries for runtime.gogo with an attempt at a traceback. 519 // The special entry 520 parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, _ map[string][]string) { 521 // An entry with two frames with 'System' in its top frame 522 // exists to record a PC without a traceback. Those are okay. 523 if len(stk) == 2 { 524 name := stk[1].Line[0].Function.Name 525 if name == "runtime._System" || name == "runtime._ExternalCode" || name == "runtime._GC" { 526 return 527 } 528 } 529 530 // Otherwise, should not see runtime.gogo. 531 // The place we'd see it would be the inner most frame. 532 name := stk[0].Line[0].Function.Name 533 if name == "runtime.gogo" { 534 var buf bytes.Buffer 535 fprintStack(&buf, stk) 536 t.Fatalf("found profile entry for runtime.gogo:\n%s", buf.String()) 537 } 538 }) 539 } 540 } 541 542 func fprintStack(w io.Writer, stk []*profile.Location) { 543 for _, loc := range stk { 544 fmt.Fprintf(w, " %#x", loc.Address) 545 fmt.Fprintf(w, " (") 546 for i, line := range loc.Line { 547 if i > 0 { 548 fmt.Fprintf(w, " ") 549 } 550 fmt.Fprintf(w, "%s:%d", line.Function.Name, line.Line) 551 } 552 fmt.Fprintf(w, ")") 553 } 554 fmt.Fprintf(w, "\n") 555 } 556 557 // Test that profiling of division operations is okay, especially on ARM. See issue 6681. 558 func TestMathBigDivide(t *testing.T) { 559 testCPUProfile(t, nil, nil, nil, func(duration time.Duration) { 560 t := time.After(duration) 561 pi := new(big.Int) 562 for { 563 for i := 0; i < 100; i++ { 564 n := big.NewInt(2646693125139304345) 565 d := big.NewInt(842468587426513207) 566 pi.Div(n, d) 567 } 568 select { 569 case <-t: 570 return 571 default: 572 } 573 } 574 }) 575 } 576 577 // stackContainsAll matches if all functions in spec (comma-separated) appear somewhere in the stack trace. 578 func stackContainsAll(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool { 579 for _, f := range strings.Split(spec, ",") { 580 if !stackContains(f, count, stk, labels) { 581 return false 582 } 583 } 584 return true 585 } 586 587 func TestMorestack(t *testing.T) { 588 testCPUProfile(t, stackContainsAll, []string{"runtime.newstack,runtime/pprof.growstack"}, avoidFunctions(), func(duration time.Duration) { 589 t := time.After(duration) 590 c := make(chan bool) 591 for { 592 go func() { 593 growstack1() 594 c <- true 595 }() 596 select { 597 case <-t: 598 return 599 case <-c: 600 } 601 } 602 }) 603 } 604 605 //go:noinline 606 func growstack1() { 607 growstack() 608 } 609 610 //go:noinline 611 func growstack() { 612 var buf [8 << 10]byte 613 use(buf) 614 } 615 616 //go:noinline 617 func use(x [8 << 10]byte) {} 618 619 func TestBlockProfile(t *testing.T) { 620 type TestCase struct { 621 name string 622 f func() 623 stk []string 624 re string 625 } 626 tests := [...]TestCase{ 627 { 628 name: "chan recv", 629 f: blockChanRecv, 630 stk: []string{ 631 "runtime.chanrecv1", 632 "runtime/pprof.blockChanRecv", 633 "runtime/pprof.TestBlockProfile", 634 }, 635 re: ` 636 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 637 # 0x[0-9a-f]+ runtime\.chanrecv1\+0x[0-9a-f]+ .*/src/runtime/chan.go:[0-9]+ 638 # 0x[0-9a-f]+ runtime/pprof\.blockChanRecv\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 639 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 640 `}, 641 { 642 name: "chan send", 643 f: blockChanSend, 644 stk: []string{ 645 "runtime.chansend1", 646 "runtime/pprof.blockChanSend", 647 "runtime/pprof.TestBlockProfile", 648 }, 649 re: ` 650 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 651 # 0x[0-9a-f]+ runtime\.chansend1\+0x[0-9a-f]+ .*/src/runtime/chan.go:[0-9]+ 652 # 0x[0-9a-f]+ runtime/pprof\.blockChanSend\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 653 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 654 `}, 655 { 656 name: "chan close", 657 f: blockChanClose, 658 stk: []string{ 659 "runtime.chanrecv1", 660 "runtime/pprof.blockChanClose", 661 "runtime/pprof.TestBlockProfile", 662 }, 663 re: ` 664 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 665 # 0x[0-9a-f]+ runtime\.chanrecv1\+0x[0-9a-f]+ .*/src/runtime/chan.go:[0-9]+ 666 # 0x[0-9a-f]+ runtime/pprof\.blockChanClose\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 667 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 668 `}, 669 { 670 name: "select recv async", 671 f: blockSelectRecvAsync, 672 stk: []string{ 673 "runtime.selectgo", 674 "runtime/pprof.blockSelectRecvAsync", 675 "runtime/pprof.TestBlockProfile", 676 }, 677 re: ` 678 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 679 # 0x[0-9a-f]+ runtime\.selectgo\+0x[0-9a-f]+ .*/src/runtime/select.go:[0-9]+ 680 # 0x[0-9a-f]+ runtime/pprof\.blockSelectRecvAsync\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 681 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 682 `}, 683 { 684 name: "select send sync", 685 f: blockSelectSendSync, 686 stk: []string{ 687 "runtime.selectgo", 688 "runtime/pprof.blockSelectSendSync", 689 "runtime/pprof.TestBlockProfile", 690 }, 691 re: ` 692 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 693 # 0x[0-9a-f]+ runtime\.selectgo\+0x[0-9a-f]+ .*/src/runtime/select.go:[0-9]+ 694 # 0x[0-9a-f]+ runtime/pprof\.blockSelectSendSync\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 695 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 696 `}, 697 { 698 name: "mutex", 699 f: blockMutex, 700 stk: []string{ 701 "sync.(*Mutex).Lock", 702 "runtime/pprof.blockMutex", 703 "runtime/pprof.TestBlockProfile", 704 }, 705 re: ` 706 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 707 # 0x[0-9a-f]+ sync\.\(\*Mutex\)\.Lock\+0x[0-9a-f]+ .*/src/sync/mutex\.go:[0-9]+ 708 # 0x[0-9a-f]+ runtime/pprof\.blockMutex\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 709 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 710 `}, 711 { 712 name: "cond", 713 f: blockCond, 714 stk: []string{ 715 "sync.(*Cond).Wait", 716 "runtime/pprof.blockCond", 717 "runtime/pprof.TestBlockProfile", 718 }, 719 re: ` 720 [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+ 721 # 0x[0-9a-f]+ sync\.\(\*Cond\)\.Wait\+0x[0-9a-f]+ .*/src/sync/cond\.go:[0-9]+ 722 # 0x[0-9a-f]+ runtime/pprof\.blockCond\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 723 # 0x[0-9a-f]+ runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+ .*/src/runtime/pprof/pprof_test.go:[0-9]+ 724 `}, 725 } 726 727 // Generate block profile 728 runtime.SetBlockProfileRate(1) 729 defer runtime.SetBlockProfileRate(0) 730 for _, test := range tests { 731 test.f() 732 } 733 734 t.Run("debug=1", func(t *testing.T) { 735 var w bytes.Buffer 736 Lookup("block").WriteTo(&w, 1) 737 prof := w.String() 738 739 if !strings.HasPrefix(prof, "--- contention:\ncycles/second=") { 740 t.Fatalf("Bad profile header:\n%v", prof) 741 } 742 743 if strings.HasSuffix(prof, "#\t0x0\n\n") { 744 t.Errorf("Useless 0 suffix:\n%v", prof) 745 } 746 747 for _, test := range tests { 748 if !regexp.MustCompile(strings.ReplaceAll(test.re, "\t", "\t+")).MatchString(prof) { 749 t.Errorf("Bad %v entry, expect:\n%v\ngot:\n%v", test.name, test.re, prof) 750 } 751 } 752 }) 753 754 t.Run("proto", func(t *testing.T) { 755 // proto format 756 var w bytes.Buffer 757 Lookup("block").WriteTo(&w, 0) 758 p, err := profile.Parse(&w) 759 if err != nil { 760 t.Fatalf("failed to parse profile: %v", err) 761 } 762 t.Logf("parsed proto: %s", p) 763 if err := p.CheckValid(); err != nil { 764 t.Fatalf("invalid profile: %v", err) 765 } 766 767 stks := stacks(p) 768 for _, test := range tests { 769 if !containsStack(stks, test.stk) { 770 t.Errorf("No matching stack entry for %v, want %+v", test.name, test.stk) 771 } 772 } 773 }) 774 775 } 776 777 func stacks(p *profile.Profile) (res [][]string) { 778 for _, s := range p.Sample { 779 var stk []string 780 for _, l := range s.Location { 781 for _, line := range l.Line { 782 stk = append(stk, line.Function.Name) 783 } 784 } 785 res = append(res, stk) 786 } 787 return res 788 } 789 790 func containsStack(got [][]string, want []string) bool { 791 for _, stk := range got { 792 if len(stk) < len(want) { 793 continue 794 } 795 for i, f := range want { 796 if f != stk[i] { 797 break 798 } 799 if i == len(want)-1 { 800 return true 801 } 802 } 803 } 804 return false 805 } 806 807 const blockDelay = 10 * time.Millisecond 808 809 func blockChanRecv() { 810 c := make(chan bool) 811 go func() { 812 time.Sleep(blockDelay) 813 c <- true 814 }() 815 <-c 816 } 817 818 func blockChanSend() { 819 c := make(chan bool) 820 go func() { 821 time.Sleep(blockDelay) 822 <-c 823 }() 824 c <- true 825 } 826 827 func blockChanClose() { 828 c := make(chan bool) 829 go func() { 830 time.Sleep(blockDelay) 831 close(c) 832 }() 833 <-c 834 } 835 836 func blockSelectRecvAsync() { 837 const numTries = 3 838 c := make(chan bool, 1) 839 c2 := make(chan bool, 1) 840 go func() { 841 for i := 0; i < numTries; i++ { 842 time.Sleep(blockDelay) 843 c <- true 844 } 845 }() 846 for i := 0; i < numTries; i++ { 847 select { 848 case <-c: 849 case <-c2: 850 } 851 } 852 } 853 854 func blockSelectSendSync() { 855 c := make(chan bool) 856 c2 := make(chan bool) 857 go func() { 858 time.Sleep(blockDelay) 859 <-c 860 }() 861 select { 862 case c <- true: 863 case c2 <- true: 864 } 865 } 866 867 func blockMutex() { 868 var mu sync.Mutex 869 mu.Lock() 870 go func() { 871 time.Sleep(blockDelay) 872 mu.Unlock() 873 }() 874 // Note: Unlock releases mu before recording the mutex event, 875 // so it's theoretically possible for this to proceed and 876 // capture the profile before the event is recorded. As long 877 // as this is blocked before the unlock happens, it's okay. 878 mu.Lock() 879 } 880 881 func blockCond() { 882 var mu sync.Mutex 883 c := sync.NewCond(&mu) 884 mu.Lock() 885 go func() { 886 time.Sleep(blockDelay) 887 mu.Lock() 888 c.Signal() 889 mu.Unlock() 890 }() 891 c.Wait() 892 mu.Unlock() 893 } 894 895 func TestMutexProfile(t *testing.T) { 896 // Generate mutex profile 897 898 old := runtime.SetMutexProfileFraction(1) 899 defer runtime.SetMutexProfileFraction(old) 900 if old != 0 { 901 t.Fatalf("need MutexProfileRate 0, got %d", old) 902 } 903 904 blockMutex() 905 906 t.Run("debug=1", func(t *testing.T) { 907 var w bytes.Buffer 908 Lookup("mutex").WriteTo(&w, 1) 909 prof := w.String() 910 t.Logf("received profile: %v", prof) 911 912 if !strings.HasPrefix(prof, "--- mutex:\ncycles/second=") { 913 t.Errorf("Bad profile header:\n%v", prof) 914 } 915 prof = strings.Trim(prof, "\n") 916 lines := strings.Split(prof, "\n") 917 if len(lines) != 6 { 918 t.Errorf("expected 6 lines, got %d %q\n%s", len(lines), prof, prof) 919 } 920 if len(lines) < 6 { 921 return 922 } 923 // checking that the line is like "35258904 1 @ 0x48288d 0x47cd28 0x458931" 924 r2 := `^\d+ \d+ @(?: 0x[[:xdigit:]]+)+` 925 //r2 := "^[0-9]+ 1 @ 0x[0-9a-f x]+$" 926 if ok, err := regexp.MatchString(r2, lines[3]); err != nil || !ok { 927 t.Errorf("%q didn't match %q", lines[3], r2) 928 } 929 r3 := "^#.*runtime/pprof.blockMutex.*$" 930 if ok, err := regexp.MatchString(r3, lines[5]); err != nil || !ok { 931 t.Errorf("%q didn't match %q", lines[5], r3) 932 } 933 t.Logf(prof) 934 }) 935 t.Run("proto", func(t *testing.T) { 936 // proto format 937 var w bytes.Buffer 938 Lookup("mutex").WriteTo(&w, 0) 939 p, err := profile.Parse(&w) 940 if err != nil { 941 t.Fatalf("failed to parse profile: %v", err) 942 } 943 t.Logf("parsed proto: %s", p) 944 if err := p.CheckValid(); err != nil { 945 t.Fatalf("invalid profile: %v", err) 946 } 947 948 stks := stacks(p) 949 for _, want := range [][]string{ 950 {"sync.(*Mutex).Unlock", "runtime/pprof.blockMutex.func1"}, 951 } { 952 if !containsStack(stks, want) { 953 t.Errorf("No matching stack entry for %+v", want) 954 } 955 } 956 }) 957 } 958 959 func func1(c chan int) { <-c } 960 func func2(c chan int) { <-c } 961 func func3(c chan int) { <-c } 962 func func4(c chan int) { <-c } 963 964 func TestGoroutineCounts(t *testing.T) { 965 // Setting GOMAXPROCS to 1 ensures we can force all goroutines to the 966 // desired blocking point. 967 defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(1)) 968 969 c := make(chan int) 970 for i := 0; i < 100; i++ { 971 switch { 972 case i%10 == 0: 973 go func1(c) 974 case i%2 == 0: 975 go func2(c) 976 default: 977 go func3(c) 978 } 979 // Let goroutines block on channel 980 for j := 0; j < 5; j++ { 981 runtime.Gosched() 982 } 983 } 984 ctx := context.Background() 985 986 // ... and again, with labels this time (just with fewer iterations to keep 987 // sorting deterministic). 988 Do(ctx, Labels("label", "value"), func(context.Context) { 989 for i := 0; i < 89; i++ { 990 switch { 991 case i%10 == 0: 992 go func1(c) 993 case i%2 == 0: 994 go func2(c) 995 default: 996 go func3(c) 997 } 998 // Let goroutines block on channel 999 for j := 0; j < 5; j++ { 1000 runtime.Gosched() 1001 } 1002 } 1003 }) 1004 1005 var w bytes.Buffer 1006 goroutineProf := Lookup("goroutine") 1007 1008 // Check debug profile 1009 goroutineProf.WriteTo(&w, 1) 1010 prof := w.String() 1011 1012 labels := labelMap{"label": "value"} 1013 labelStr := "\n# labels: " + labels.String() 1014 if !containsInOrder(prof, "\n50 @ ", "\n44 @", labelStr, 1015 "\n40 @", "\n36 @", labelStr, "\n10 @", "\n9 @", labelStr, "\n1 @") { 1016 t.Errorf("expected sorted goroutine counts with Labels:\n%s", prof) 1017 } 1018 1019 // Check proto profile 1020 w.Reset() 1021 goroutineProf.WriteTo(&w, 0) 1022 p, err := profile.Parse(&w) 1023 if err != nil { 1024 t.Errorf("error parsing protobuf profile: %v", err) 1025 } 1026 if err := p.CheckValid(); err != nil { 1027 t.Errorf("protobuf profile is invalid: %v", err) 1028 } 1029 expectedLabels := map[int64]map[string]string{ 1030 50: map[string]string{}, 1031 44: map[string]string{"label": "value"}, 1032 40: map[string]string{}, 1033 36: map[string]string{"label": "value"}, 1034 10: map[string]string{}, 1035 9: map[string]string{"label": "value"}, 1036 1: map[string]string{}, 1037 } 1038 if !containsCountsLabels(p, expectedLabels) { 1039 t.Errorf("expected count profile to contain goroutines with counts and labels %v, got %v", 1040 expectedLabels, p) 1041 } 1042 1043 close(c) 1044 1045 time.Sleep(10 * time.Millisecond) // let goroutines exit 1046 } 1047 1048 func containsInOrder(s string, all ...string) bool { 1049 for _, t := range all { 1050 i := strings.Index(s, t) 1051 if i < 0 { 1052 return false 1053 } 1054 s = s[i+len(t):] 1055 } 1056 return true 1057 } 1058 1059 func containsCountsLabels(prof *profile.Profile, countLabels map[int64]map[string]string) bool { 1060 m := make(map[int64]int) 1061 type nkey struct { 1062 count int64 1063 key, val string 1064 } 1065 n := make(map[nkey]int) 1066 for c, kv := range countLabels { 1067 m[c]++ 1068 for k, v := range kv { 1069 n[nkey{ 1070 count: c, 1071 key: k, 1072 val: v, 1073 }]++ 1074 1075 } 1076 } 1077 for _, s := range prof.Sample { 1078 // The count is the single value in the sample 1079 if len(s.Value) != 1 { 1080 return false 1081 } 1082 m[s.Value[0]]-- 1083 for k, vs := range s.Label { 1084 for _, v := range vs { 1085 n[nkey{ 1086 count: s.Value[0], 1087 key: k, 1088 val: v, 1089 }]-- 1090 } 1091 } 1092 } 1093 for _, n := range m { 1094 if n > 0 { 1095 return false 1096 } 1097 } 1098 for _, ncnt := range n { 1099 if ncnt != 0 { 1100 return false 1101 } 1102 } 1103 return true 1104 } 1105 1106 var emptyCallStackTestRun int64 1107 1108 // Issue 18836. 1109 func TestEmptyCallStack(t *testing.T) { 1110 name := fmt.Sprintf("test18836_%d", emptyCallStackTestRun) 1111 emptyCallStackTestRun++ 1112 1113 t.Parallel() 1114 var buf bytes.Buffer 1115 p := NewProfile(name) 1116 1117 p.Add("foo", 47674) 1118 p.WriteTo(&buf, 1) 1119 p.Remove("foo") 1120 got := buf.String() 1121 prefix := name + " profile: total 1\n" 1122 if !strings.HasPrefix(got, prefix) { 1123 t.Fatalf("got:\n\t%q\nwant prefix:\n\t%q\n", got, prefix) 1124 } 1125 lostevent := "lostProfileEvent" 1126 if !strings.Contains(got, lostevent) { 1127 t.Fatalf("got:\n\t%q\ndoes not contain:\n\t%q\n", got, lostevent) 1128 } 1129 } 1130 1131 // stackContainsLabeled takes a spec like funcname;key=value and matches if the stack has that key 1132 // and value and has funcname somewhere in the stack. 1133 func stackContainsLabeled(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool { 1134 semi := strings.Index(spec, ";") 1135 if semi == -1 { 1136 panic("no semicolon in key/value spec") 1137 } 1138 kv := strings.SplitN(spec[semi+1:], "=", 2) 1139 if len(kv) != 2 { 1140 panic("missing = in key/value spec") 1141 } 1142 if !contains(labels[kv[0]], kv[1]) { 1143 return false 1144 } 1145 return stackContains(spec[:semi], count, stk, labels) 1146 } 1147 1148 func TestCPUProfileLabel(t *testing.T) { 1149 testCPUProfile(t, stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, avoidFunctions(), func(dur time.Duration) { 1150 Do(context.Background(), Labels("key", "value"), func(context.Context) { 1151 cpuHogger(cpuHog1, &salt1, dur) 1152 }) 1153 }) 1154 } 1155 1156 func TestLabelRace(t *testing.T) { 1157 // Test the race detector annotations for synchronization 1158 // between settings labels and consuming them from the 1159 // profile. 1160 testCPUProfile(t, stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, nil, func(dur time.Duration) { 1161 start := time.Now() 1162 var wg sync.WaitGroup 1163 for time.Since(start) < dur { 1164 var salts [10]int 1165 for i := 0; i < 10; i++ { 1166 wg.Add(1) 1167 go func(j int) { 1168 Do(context.Background(), Labels("key", "value"), func(context.Context) { 1169 cpuHogger(cpuHog1, &salts[j], time.Millisecond) 1170 }) 1171 wg.Done() 1172 }(i) 1173 } 1174 wg.Wait() 1175 } 1176 }) 1177 } 1178 1179 // Check that there is no deadlock when the program receives SIGPROF while in 1180 // 64bit atomics' critical section. Used to happen on mips{,le}. See #20146. 1181 func TestAtomicLoadStore64(t *testing.T) { 1182 f, err := os.CreateTemp("", "profatomic") 1183 if err != nil { 1184 t.Fatalf("TempFile: %v", err) 1185 } 1186 defer os.Remove(f.Name()) 1187 defer f.Close() 1188 1189 if err := StartCPUProfile(f); err != nil { 1190 t.Fatal(err) 1191 } 1192 defer StopCPUProfile() 1193 1194 var flag uint64 1195 done := make(chan bool, 1) 1196 1197 go func() { 1198 for atomic.LoadUint64(&flag) == 0 { 1199 runtime.Gosched() 1200 } 1201 done <- true 1202 }() 1203 time.Sleep(50 * time.Millisecond) 1204 atomic.StoreUint64(&flag, 1) 1205 <-done 1206 } 1207 1208 func TestTracebackAll(t *testing.T) { 1209 // With gccgo, if a profiling signal arrives at the wrong time 1210 // during traceback, it may crash or hang. See issue #29448. 1211 f, err := os.CreateTemp("", "proftraceback") 1212 if err != nil { 1213 t.Fatalf("TempFile: %v", err) 1214 } 1215 defer os.Remove(f.Name()) 1216 defer f.Close() 1217 1218 if err := StartCPUProfile(f); err != nil { 1219 t.Fatal(err) 1220 } 1221 defer StopCPUProfile() 1222 1223 ch := make(chan int) 1224 defer close(ch) 1225 1226 count := 10 1227 for i := 0; i < count; i++ { 1228 go func() { 1229 <-ch // block 1230 }() 1231 } 1232 1233 N := 10000 1234 if testing.Short() { 1235 N = 500 1236 } 1237 buf := make([]byte, 10*1024) 1238 for i := 0; i < N; i++ { 1239 runtime.Stack(buf, true) 1240 } 1241 } 1242 1243 // TestTryAdd tests the cases that are hard to test with real program execution. 1244 // 1245 // For example, the current go compilers may not always inline functions 1246 // involved in recursion but that may not be true in the future compilers. This 1247 // tests such cases by using fake call sequences and forcing the profile build 1248 // utilizing translateCPUProfile defined in proto_test.go 1249 func TestTryAdd(t *testing.T) { 1250 if _, found := findInlinedCall(inlinedCallerDump, 4<<10); !found { 1251 t.Skip("Can't determine whether anything was inlined into inlinedCallerDump.") 1252 } 1253 1254 // inlinedCallerDump 1255 // inlinedCalleeDump 1256 pcs := make([]uintptr, 2) 1257 inlinedCallerDump(pcs) 1258 inlinedCallerStack := make([]uint64, 2) 1259 for i := range pcs { 1260 inlinedCallerStack[i] = uint64(pcs[i]) 1261 } 1262 1263 if _, found := findInlinedCall(recursionChainBottom, 4<<10); !found { 1264 t.Skip("Can't determine whether anything was inlined into recursionChainBottom.") 1265 } 1266 1267 // recursionChainTop 1268 // recursionChainMiddle 1269 // recursionChainBottom 1270 // recursionChainTop 1271 // recursionChainMiddle 1272 // recursionChainBottom 1273 pcs = make([]uintptr, 6) 1274 recursionChainTop(1, pcs) 1275 recursionStack := make([]uint64, len(pcs)) 1276 for i := range pcs { 1277 recursionStack[i] = uint64(pcs[i]) 1278 } 1279 1280 period := int64(2000 * 1000) // 1/500*1e9 nanosec. 1281 1282 testCases := []struct { 1283 name string 1284 input []uint64 // following the input format assumed by profileBuilder.addCPUData. 1285 wantLocs [][]string // ordered location entries with function names. 1286 wantSamples []*profile.Sample // ordered samples, we care only about Value and the profile location IDs. 1287 }{{ 1288 // Sanity test for a normal, complete stack trace. 1289 name: "full_stack_trace", 1290 input: []uint64{ 1291 3, 0, 500, // hz = 500. Must match the period. 1292 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1], 1293 }, 1294 wantLocs: [][]string{ 1295 {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}, 1296 }, 1297 wantSamples: []*profile.Sample{ 1298 {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}}, 1299 }, 1300 }, { 1301 name: "bug35538", 1302 input: []uint64{ 1303 3, 0, 500, // hz = 500. Must match the period. 1304 // Fake frame: tryAdd will have inlinedCallerDump 1305 // (stack[1]) on the deck when it encounters the next 1306 // inline function. It should accept this. 1307 7, 0, 10, inlinedCallerStack[0], inlinedCallerStack[1], inlinedCallerStack[0], inlinedCallerStack[1], 1308 5, 0, 20, inlinedCallerStack[0], inlinedCallerStack[1], 1309 }, 1310 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, 1311 wantSamples: []*profile.Sample{ 1312 {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}}, 1313 {Value: []int64{20, 20 * period}, Location: []*profile.Location{{ID: 1}}}, 1314 }, 1315 }, { 1316 name: "bug38096", 1317 input: []uint64{ 1318 3, 0, 500, // hz = 500. Must match the period. 1319 // count (data[2]) == 0 && len(stk) == 1 is an overflow 1320 // entry. The "stk" entry is actually the count. 1321 4, 0, 0, 4242, 1322 }, 1323 wantLocs: [][]string{{"runtime/pprof.lostProfileEvent"}}, 1324 wantSamples: []*profile.Sample{ 1325 {Value: []int64{4242, 4242 * period}, Location: []*profile.Location{{ID: 1}}}, 1326 }, 1327 }, { 1328 // If a function is directly called recursively then it must 1329 // not be inlined in the caller. 1330 // 1331 // N.B. We're generating an impossible profile here, with a 1332 // recursive inlineCalleeDump call. This is simulating a non-Go 1333 // function that looks like an inlined Go function other than 1334 // its recursive property. See pcDeck.tryAdd. 1335 name: "directly_recursive_func_is_not_inlined", 1336 input: []uint64{ 1337 3, 0, 500, // hz = 500. Must match the period. 1338 5, 0, 30, inlinedCallerStack[0], inlinedCallerStack[0], 1339 4, 0, 40, inlinedCallerStack[0], 1340 }, 1341 // inlinedCallerDump shows up here because 1342 // runtime_expandFinalInlineFrame adds it to the stack frame. 1343 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump"}, {"runtime/pprof.inlinedCallerDump"}}, 1344 wantSamples: []*profile.Sample{ 1345 {Value: []int64{30, 30 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}, {ID: 2}}}, 1346 {Value: []int64{40, 40 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}}}, 1347 }, 1348 }, { 1349 name: "recursion_chain_inline", 1350 input: []uint64{ 1351 3, 0, 500, // hz = 500. Must match the period. 1352 9, 0, 10, recursionStack[0], recursionStack[1], recursionStack[2], recursionStack[3], recursionStack[4], recursionStack[5], 1353 }, 1354 wantLocs: [][]string{ 1355 {"runtime/pprof.recursionChainBottom"}, 1356 { 1357 "runtime/pprof.recursionChainMiddle", 1358 "runtime/pprof.recursionChainTop", 1359 "runtime/pprof.recursionChainBottom", 1360 }, 1361 { 1362 "runtime/pprof.recursionChainMiddle", 1363 "runtime/pprof.recursionChainTop", 1364 "runtime/pprof.TestTryAdd", // inlined into the test. 1365 }, 1366 }, 1367 wantSamples: []*profile.Sample{ 1368 {Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}, {ID: 3}}}, 1369 }, 1370 }, { 1371 name: "truncated_stack_trace_later", 1372 input: []uint64{ 1373 3, 0, 500, // hz = 500. Must match the period. 1374 5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1], 1375 4, 0, 60, inlinedCallerStack[0], 1376 }, 1377 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, 1378 wantSamples: []*profile.Sample{ 1379 {Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}}, 1380 {Value: []int64{60, 60 * period}, Location: []*profile.Location{{ID: 1}}}, 1381 }, 1382 }, { 1383 name: "truncated_stack_trace_first", 1384 input: []uint64{ 1385 3, 0, 500, // hz = 500. Must match the period. 1386 4, 0, 70, inlinedCallerStack[0], 1387 5, 0, 80, inlinedCallerStack[0], inlinedCallerStack[1], 1388 }, 1389 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, 1390 wantSamples: []*profile.Sample{ 1391 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}}, 1392 {Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 1}}}, 1393 }, 1394 }, { 1395 // We can recover the inlined caller from a truncated stack. 1396 name: "truncated_stack_trace_only", 1397 input: []uint64{ 1398 3, 0, 500, // hz = 500. Must match the period. 1399 4, 0, 70, inlinedCallerStack[0], 1400 }, 1401 wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}}, 1402 wantSamples: []*profile.Sample{ 1403 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}}, 1404 }, 1405 }, { 1406 // The same location is used for duplicated stacks. 1407 name: "truncated_stack_trace_twice", 1408 input: []uint64{ 1409 3, 0, 500, // hz = 500. Must match the period. 1410 4, 0, 70, inlinedCallerStack[0], 1411 // Fake frame: add a fake call to 1412 // inlinedCallerDump to prevent this sample 1413 // from getting merged into above. 1414 5, 0, 80, inlinedCallerStack[1], inlinedCallerStack[0], 1415 }, 1416 wantLocs: [][]string{ 1417 {"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}, 1418 {"runtime/pprof.inlinedCallerDump"}, 1419 }, 1420 wantSamples: []*profile.Sample{ 1421 {Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}}, 1422 {Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 2}, {ID: 1}}}, 1423 }, 1424 }} 1425 1426 for _, tc := range testCases { 1427 t.Run(tc.name, func(t *testing.T) { 1428 p, err := translateCPUProfile(tc.input) 1429 if err != nil { 1430 t.Fatalf("translating profile: %v", err) 1431 } 1432 t.Logf("Profile: %v\n", p) 1433 1434 // One location entry with all inlined functions. 1435 var gotLoc [][]string 1436 for _, loc := range p.Location { 1437 var names []string 1438 for _, line := range loc.Line { 1439 names = append(names, line.Function.Name) 1440 } 1441 gotLoc = append(gotLoc, names) 1442 } 1443 if got, want := fmtJSON(gotLoc), fmtJSON(tc.wantLocs); got != want { 1444 t.Errorf("Got Location = %+v\n\twant %+v", got, want) 1445 } 1446 // All samples should point to one location. 1447 var gotSamples []*profile.Sample 1448 for _, sample := range p.Sample { 1449 var locs []*profile.Location 1450 for _, loc := range sample.Location { 1451 locs = append(locs, &profile.Location{ID: loc.ID}) 1452 } 1453 gotSamples = append(gotSamples, &profile.Sample{Value: sample.Value, Location: locs}) 1454 } 1455 if got, want := fmtJSON(gotSamples), fmtJSON(tc.wantSamples); got != want { 1456 t.Errorf("Got Samples = %+v\n\twant %+v", got, want) 1457 } 1458 }) 1459 } 1460 }