Source file src/runtime/pprof/pprof_test.go

     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  //go:build !js
     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  	"iter"
    19  	"math"
    20  	"math/big"
    21  	"os"
    22  	"regexp"
    23  	"runtime"
    24  	"runtime/debug"
    25  	"slices"
    26  	"strconv"
    27  	"strings"
    28  	"sync"
    29  	"sync/atomic"
    30  	"testing"
    31  	"time"
    32  	_ "unsafe"
    33  )
    34  
    35  func cpuHogger(f func(x int) int, y *int, dur time.Duration) {
    36  	// We only need to get one 100 Hz clock tick, so we've got
    37  	// a large safety buffer.
    38  	// But do at least 500 iterations (which should take about 100ms),
    39  	// otherwise TestCPUProfileMultithreaded can fail if only one
    40  	// thread is scheduled during the testing period.
    41  	t0 := time.Now()
    42  	accum := *y
    43  	for i := 0; i < 500 || time.Since(t0) < dur; i++ {
    44  		accum = f(accum)
    45  	}
    46  	*y = accum
    47  }
    48  
    49  var (
    50  	salt1 = 0
    51  	salt2 = 0
    52  )
    53  
    54  // The actual CPU hogging function.
    55  // Must not call other functions nor access heap/globals in the loop,
    56  // otherwise under race detector the samples will be in the race runtime.
    57  func cpuHog1(x int) int {
    58  	return cpuHog0(x, 1e5)
    59  }
    60  
    61  func cpuHog0(x, n int) int {
    62  	foo := x
    63  	for i := 0; i < n; i++ {
    64  		if foo > 0 {
    65  			foo *= foo
    66  		} else {
    67  			foo *= foo + 1
    68  		}
    69  	}
    70  	return foo
    71  }
    72  
    73  func cpuHog2(x int) int {
    74  	foo := x
    75  	for i := 0; i < 1e5; i++ {
    76  		if foo > 0 {
    77  			foo *= foo
    78  		} else {
    79  			foo *= foo + 2
    80  		}
    81  	}
    82  	return foo
    83  }
    84  
    85  // Return a list of functions that we don't want to ever appear in CPU
    86  // profiles. For gccgo, that list includes the sigprof handler itself.
    87  func avoidFunctions() []string {
    88  	if runtime.Compiler == "gccgo" {
    89  		return []string{"runtime.sigprof"}
    90  	}
    91  	return nil
    92  }
    93  
    94  func TestCPUProfile(t *testing.T) {
    95  	matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1"}, avoidFunctions())
    96  	testCPUProfile(t, matches, func(dur time.Duration) {
    97  		cpuHogger(cpuHog1, &salt1, dur)
    98  	})
    99  }
   100  
   101  func TestCPUProfileMultithreaded(t *testing.T) {
   102  	defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(2))
   103  	matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1", "runtime/pprof.cpuHog2"}, avoidFunctions())
   104  	testCPUProfile(t, matches, func(dur time.Duration) {
   105  		c := make(chan int)
   106  		go func() {
   107  			cpuHogger(cpuHog1, &salt1, dur)
   108  			c <- 1
   109  		}()
   110  		cpuHogger(cpuHog2, &salt2, dur)
   111  		<-c
   112  	})
   113  }
   114  
   115  func TestCPUProfileMultithreadMagnitude(t *testing.T) {
   116  	if runtime.GOOS != "linux" {
   117  		t.Skip("issue 35057 is only confirmed on Linux")
   118  	}
   119  
   120  	defer func() {
   121  		if t.Failed() {
   122  			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.")
   123  		}
   124  	}()
   125  
   126  	// Disable on affected builders to avoid flakiness, but otherwise keep
   127  	// it enabled to potentially warn users that they are on a broken
   128  	// kernel.
   129  	if testenv.Builder() != "" && (runtime.GOARCH == "386" || runtime.GOARCH == "amd64") {
   130  		// Linux [5.9,5.16) has a kernel bug that can break CPU timers on newly
   131  		// created threads, breaking our CPU accounting.
   132  		if unix.KernelVersionGE(5, 9) && !unix.KernelVersionGE(5, 16) {
   133  			testenv.SkipFlaky(t, 49065)
   134  		}
   135  	}
   136  
   137  	// Run a workload in a single goroutine, then run copies of the same
   138  	// workload in several goroutines. For both the serial and parallel cases,
   139  	// the CPU time the process measures with its own profiler should match the
   140  	// total CPU usage that the OS reports.
   141  	//
   142  	// We could also check that increases in parallelism (GOMAXPROCS) lead to a
   143  	// linear increase in the CPU usage reported by both the OS and the
   144  	// profiler, but without a guarantee of exclusive access to CPU resources
   145  	// that is likely to be a flaky test.
   146  
   147  	// Require the smaller value to be within 10%, or 40% in short mode.
   148  	maxDiff := 0.10
   149  	if testing.Short() {
   150  		maxDiff = 0.40
   151  	}
   152  
   153  	compare := func(a, b time.Duration, maxDiff float64) error {
   154  		if a <= 0 || b <= 0 {
   155  			return fmt.Errorf("Expected both time reports to be positive")
   156  		}
   157  
   158  		if a < b {
   159  			a, b = b, a
   160  		}
   161  
   162  		diff := float64(a-b) / float64(a)
   163  		if diff > maxDiff {
   164  			return fmt.Errorf("CPU usage reports are too different (limit -%.1f%%, got -%.1f%%)", maxDiff*100, diff*100)
   165  		}
   166  
   167  		return nil
   168  	}
   169  
   170  	for _, tc := range []struct {
   171  		name    string
   172  		workers int
   173  	}{
   174  		{
   175  			name:    "serial",
   176  			workers: 1,
   177  		},
   178  		{
   179  			name:    "parallel",
   180  			workers: runtime.GOMAXPROCS(0),
   181  		},
   182  	} {
   183  		// check that the OS's perspective matches what the Go runtime measures.
   184  		t.Run(tc.name, func(t *testing.T) {
   185  			t.Logf("Running with %d workers", tc.workers)
   186  
   187  			var userTime, systemTime time.Duration
   188  			matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.cpuHog1"}, avoidFunctions())
   189  			acceptProfile := func(t *testing.T, p *profile.Profile) bool {
   190  				if !matches(t, p) {
   191  					return false
   192  				}
   193  
   194  				ok := true
   195  				for i, unit := range []string{"count", "nanoseconds"} {
   196  					if have, want := p.SampleType[i].Unit, unit; have != want {
   197  						t.Logf("pN SampleType[%d]; %q != %q", i, have, want)
   198  						ok = false
   199  					}
   200  				}
   201  
   202  				// cpuHog1 called below is the primary source of CPU
   203  				// load, but there may be some background work by the
   204  				// runtime. Since the OS rusage measurement will
   205  				// include all work done by the process, also compare
   206  				// against all samples in our profile.
   207  				var value time.Duration
   208  				for _, sample := range p.Sample {
   209  					value += time.Duration(sample.Value[1]) * time.Nanosecond
   210  				}
   211  
   212  				totalTime := userTime + systemTime
   213  				t.Logf("compare %s user + %s system = %s vs %s", userTime, systemTime, totalTime, value)
   214  				if err := compare(totalTime, value, maxDiff); err != nil {
   215  					t.Logf("compare got %v want nil", err)
   216  					ok = false
   217  				}
   218  
   219  				return ok
   220  			}
   221  
   222  			testCPUProfile(t, acceptProfile, func(dur time.Duration) {
   223  				userTime, systemTime = diffCPUTime(t, func() {
   224  					var wg sync.WaitGroup
   225  					var once sync.Once
   226  					for i := 0; i < tc.workers; i++ {
   227  						wg.Add(1)
   228  						go func() {
   229  							defer wg.Done()
   230  							var salt = 0
   231  							cpuHogger(cpuHog1, &salt, dur)
   232  							once.Do(func() { salt1 = salt })
   233  						}()
   234  					}
   235  					wg.Wait()
   236  				})
   237  			})
   238  		})
   239  	}
   240  }
   241  
   242  // containsInlinedCall reports whether the function body for the function f is
   243  // known to contain an inlined function call within the first maxBytes bytes.
   244  func containsInlinedCall(f any, maxBytes int) bool {
   245  	_, found := findInlinedCall(f, maxBytes)
   246  	return found
   247  }
   248  
   249  // findInlinedCall returns the PC of an inlined function call within
   250  // the function body for the function f if any.
   251  func findInlinedCall(f any, maxBytes int) (pc uint64, found bool) {
   252  	fFunc := runtime.FuncForPC(uintptr(abi.FuncPCABIInternal(f)))
   253  	if fFunc == nil || fFunc.Entry() == 0 {
   254  		panic("failed to locate function entry")
   255  	}
   256  
   257  	for offset := 0; offset < maxBytes; offset++ {
   258  		innerPC := fFunc.Entry() + uintptr(offset)
   259  		inner := runtime.FuncForPC(innerPC)
   260  		if inner == nil {
   261  			// No function known for this PC value.
   262  			// It might simply be misaligned, so keep searching.
   263  			continue
   264  		}
   265  		if inner.Entry() != fFunc.Entry() {
   266  			// Scanned past f and didn't find any inlined functions.
   267  			break
   268  		}
   269  		if inner.Name() != fFunc.Name() {
   270  			// This PC has f as its entry-point, but is not f. Therefore, it must be a
   271  			// function inlined into f.
   272  			return uint64(innerPC), true
   273  		}
   274  	}
   275  
   276  	return 0, false
   277  }
   278  
   279  func TestCPUProfileInlining(t *testing.T) {
   280  	if !containsInlinedCall(inlinedCaller, 4<<10) {
   281  		t.Skip("Can't determine whether inlinedCallee was inlined into inlinedCaller.")
   282  	}
   283  
   284  	matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.inlinedCaller"}, avoidFunctions())
   285  	p := testCPUProfile(t, matches, func(dur time.Duration) {
   286  		cpuHogger(inlinedCaller, &salt1, dur)
   287  	})
   288  
   289  	// Check if inlined function locations are encoded correctly. The inlinedCalee and inlinedCaller should be in one location.
   290  	for _, loc := range p.Location {
   291  		hasInlinedCallerAfterInlinedCallee, hasInlinedCallee := false, false
   292  		for _, line := range loc.Line {
   293  			if line.Function.Name == "runtime/pprof.inlinedCallee" {
   294  				hasInlinedCallee = true
   295  			}
   296  			if hasInlinedCallee && line.Function.Name == "runtime/pprof.inlinedCaller" {
   297  				hasInlinedCallerAfterInlinedCallee = true
   298  			}
   299  		}
   300  		if hasInlinedCallee != hasInlinedCallerAfterInlinedCallee {
   301  			t.Fatalf("want inlinedCallee followed by inlinedCaller, got separate Location entries:\n%v", p)
   302  		}
   303  	}
   304  }
   305  
   306  func inlinedCaller(x int) int {
   307  	x = inlinedCallee(x, 1e5)
   308  	return x
   309  }
   310  
   311  func inlinedCallee(x, n int) int {
   312  	return cpuHog0(x, n)
   313  }
   314  
   315  //go:noinline
   316  func dumpCallers(pcs []uintptr) {
   317  	if pcs == nil {
   318  		return
   319  	}
   320  
   321  	skip := 2 // Callers and dumpCallers
   322  	runtime.Callers(skip, pcs)
   323  }
   324  
   325  //go:noinline
   326  func inlinedCallerDump(pcs []uintptr) {
   327  	inlinedCalleeDump(pcs)
   328  }
   329  
   330  func inlinedCalleeDump(pcs []uintptr) {
   331  	dumpCallers(pcs)
   332  }
   333  
   334  type inlineWrapperInterface interface {
   335  	dump(stack []uintptr)
   336  }
   337  
   338  type inlineWrapper struct {
   339  }
   340  
   341  func (h inlineWrapper) dump(pcs []uintptr) {
   342  	dumpCallers(pcs)
   343  }
   344  
   345  func inlinedWrapperCallerDump(pcs []uintptr) {
   346  	var h inlineWrapperInterface
   347  
   348  	// Take the address of h, such that h.dump() call (below)
   349  	// does not get devirtualized by the compiler.
   350  	_ = &h
   351  
   352  	h = &inlineWrapper{}
   353  	h.dump(pcs)
   354  }
   355  
   356  func TestCPUProfileRecursion(t *testing.T) {
   357  	matches := matchAndAvoidStacks(stackContains, []string{"runtime/pprof.inlinedCallee", "runtime/pprof.recursionCallee", "runtime/pprof.recursionCaller"}, avoidFunctions())
   358  	p := testCPUProfile(t, matches, func(dur time.Duration) {
   359  		cpuHogger(recursionCaller, &salt1, dur)
   360  	})
   361  
   362  	// check the Location encoding was not confused by recursive calls.
   363  	for i, loc := range p.Location {
   364  		recursionFunc := 0
   365  		for _, line := range loc.Line {
   366  			if name := line.Function.Name; name == "runtime/pprof.recursionCaller" || name == "runtime/pprof.recursionCallee" {
   367  				recursionFunc++
   368  			}
   369  		}
   370  		if recursionFunc > 1 {
   371  			t.Fatalf("want at most one recursionCaller or recursionCallee in one Location, got a violating Location (index: %d):\n%v", i, p)
   372  		}
   373  	}
   374  }
   375  
   376  func recursionCaller(x int) int {
   377  	y := recursionCallee(3, x)
   378  	return y
   379  }
   380  
   381  func recursionCallee(n, x int) int {
   382  	if n == 0 {
   383  		return 1
   384  	}
   385  	y := inlinedCallee(x, 1e4)
   386  	return y * recursionCallee(n-1, x)
   387  }
   388  
   389  func recursionChainTop(x int, pcs []uintptr) {
   390  	if x < 0 {
   391  		return
   392  	}
   393  	recursionChainMiddle(x, pcs)
   394  }
   395  
   396  func recursionChainMiddle(x int, pcs []uintptr) {
   397  	recursionChainBottom(x, pcs)
   398  }
   399  
   400  func recursionChainBottom(x int, pcs []uintptr) {
   401  	// This will be called each time, we only care about the last. We
   402  	// can't make this conditional or this function won't be inlined.
   403  	dumpCallers(pcs)
   404  
   405  	recursionChainTop(x-1, pcs)
   406  }
   407  
   408  func parseProfile(t *testing.T, valBytes []byte, f func(uintptr, []*profile.Location, map[string][]string)) *profile.Profile {
   409  	p, err := profile.Parse(bytes.NewReader(valBytes))
   410  	if err != nil {
   411  		t.Fatal(err)
   412  	}
   413  	for _, sample := range p.Sample {
   414  		count := uintptr(sample.Value[0])
   415  		f(count, sample.Location, sample.Label)
   416  	}
   417  	return p
   418  }
   419  
   420  // testCPUProfile runs f under the CPU profiler, checking for some conditions specified by need,
   421  // as interpreted by matches, and returns the parsed profile.
   422  func testCPUProfile(t *testing.T, matches profileMatchFunc, f func(dur time.Duration)) *profile.Profile {
   423  	switch runtime.GOOS {
   424  	case "darwin":
   425  		out, err := testenv.Command(t, "uname", "-a").CombinedOutput()
   426  		if err != nil {
   427  			t.Fatal(err)
   428  		}
   429  		vers := string(out)
   430  		t.Logf("uname -a: %v", vers)
   431  	case "plan9":
   432  		t.Skip("skipping on plan9")
   433  	case "wasip1":
   434  		t.Skip("skipping on wasip1")
   435  	}
   436  
   437  	broken := testenv.CPUProfilingBroken()
   438  
   439  	deadline, ok := t.Deadline()
   440  	if broken || !ok {
   441  		if broken && testing.Short() {
   442  			// If it's expected to be broken, no point waiting around.
   443  			deadline = time.Now().Add(1 * time.Second)
   444  		} else {
   445  			deadline = time.Now().Add(10 * time.Second)
   446  		}
   447  	}
   448  
   449  	// If we're running a long test, start with a long duration
   450  	// for tests that try to make sure something *doesn't* happen.
   451  	duration := 5 * time.Second
   452  	if testing.Short() {
   453  		duration = 100 * time.Millisecond
   454  	}
   455  
   456  	// Profiling tests are inherently flaky, especially on a
   457  	// loaded system, such as when this test is running with
   458  	// several others under go test std. If a test fails in a way
   459  	// that could mean it just didn't run long enough, try with a
   460  	// longer duration.
   461  	for {
   462  		var prof bytes.Buffer
   463  		if err := StartCPUProfile(&prof); err != nil {
   464  			t.Fatal(err)
   465  		}
   466  		f(duration)
   467  		StopCPUProfile()
   468  
   469  		if p, ok := profileOk(t, matches, &prof, duration); ok {
   470  			return p
   471  		}
   472  
   473  		duration *= 2
   474  		if time.Until(deadline) < duration {
   475  			break
   476  		}
   477  		t.Logf("retrying with %s duration", duration)
   478  	}
   479  
   480  	if broken {
   481  		t.Skipf("ignoring failure on %s/%s; see golang.org/issue/13841", runtime.GOOS, runtime.GOARCH)
   482  	}
   483  
   484  	// Ignore the failure if the tests are running in a QEMU-based emulator,
   485  	// QEMU is not perfect at emulating everything.
   486  	// IN_QEMU environmental variable is set by some of the Go builders.
   487  	// IN_QEMU=1 indicates that the tests are running in QEMU. See issue 9605.
   488  	if os.Getenv("IN_QEMU") == "1" {
   489  		t.Skip("ignore the failure in QEMU; see golang.org/issue/9605")
   490  	}
   491  	t.FailNow()
   492  	return nil
   493  }
   494  
   495  var diffCPUTimeImpl func(f func()) (user, system time.Duration)
   496  
   497  func diffCPUTime(t *testing.T, f func()) (user, system time.Duration) {
   498  	if fn := diffCPUTimeImpl; fn != nil {
   499  		return fn(f)
   500  	}
   501  	t.Fatalf("cannot measure CPU time on GOOS=%s GOARCH=%s", runtime.GOOS, runtime.GOARCH)
   502  	return 0, 0
   503  }
   504  
   505  // stackContains matches if a function named spec appears anywhere in the stack trace.
   506  func stackContains(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
   507  	for _, loc := range stk {
   508  		for _, line := range loc.Line {
   509  			if strings.Contains(line.Function.Name, spec) {
   510  				return true
   511  			}
   512  		}
   513  	}
   514  	return false
   515  }
   516  
   517  type sampleMatchFunc func(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool
   518  
   519  func profileOk(t *testing.T, matches profileMatchFunc, prof *bytes.Buffer, duration time.Duration) (_ *profile.Profile, ok bool) {
   520  	ok = true
   521  
   522  	var samples uintptr
   523  	var buf strings.Builder
   524  	p := parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, labels map[string][]string) {
   525  		fmt.Fprintf(&buf, "%d:", count)
   526  		fprintStack(&buf, stk)
   527  		fmt.Fprintf(&buf, " labels: %v\n", labels)
   528  		samples += count
   529  		fmt.Fprintf(&buf, "\n")
   530  	})
   531  	t.Logf("total %d CPU profile samples collected:\n%s", samples, buf.String())
   532  
   533  	if samples < 10 && runtime.GOOS == "windows" {
   534  		// On some windows machines we end up with
   535  		// not enough samples due to coarse timer
   536  		// resolution. Let it go.
   537  		t.Log("too few samples on Windows (golang.org/issue/10842)")
   538  		return p, false
   539  	}
   540  
   541  	// Check that we got a reasonable number of samples.
   542  	// We used to always require at least ideal/4 samples,
   543  	// but that is too hard to guarantee on a loaded system.
   544  	// Now we accept 10 or more samples, which we take to be
   545  	// enough to show that at least some profiling is occurring.
   546  	if ideal := uintptr(duration * 100 / time.Second); samples == 0 || (samples < ideal/4 && samples < 10) {
   547  		t.Logf("too few samples; got %d, want at least %d, ideally %d", samples, ideal/4, ideal)
   548  		ok = false
   549  	}
   550  
   551  	if matches != nil && !matches(t, p) {
   552  		ok = false
   553  	}
   554  
   555  	return p, ok
   556  }
   557  
   558  type profileMatchFunc func(*testing.T, *profile.Profile) bool
   559  
   560  func matchAndAvoidStacks(matches sampleMatchFunc, need []string, avoid []string) profileMatchFunc {
   561  	return func(t *testing.T, p *profile.Profile) (ok bool) {
   562  		ok = true
   563  
   564  		// Check that profile is well formed, contains 'need', and does not contain
   565  		// anything from 'avoid'.
   566  		have := make([]uintptr, len(need))
   567  		avoidSamples := make([]uintptr, len(avoid))
   568  
   569  		for _, sample := range p.Sample {
   570  			count := uintptr(sample.Value[0])
   571  			for i, spec := range need {
   572  				if matches(spec, count, sample.Location, sample.Label) {
   573  					have[i] += count
   574  				}
   575  			}
   576  			for i, name := range avoid {
   577  				for _, loc := range sample.Location {
   578  					for _, line := range loc.Line {
   579  						if strings.Contains(line.Function.Name, name) {
   580  							avoidSamples[i] += count
   581  						}
   582  					}
   583  				}
   584  			}
   585  		}
   586  
   587  		for i, name := range avoid {
   588  			bad := avoidSamples[i]
   589  			if bad != 0 {
   590  				t.Logf("found %d samples in avoid-function %s\n", bad, name)
   591  				ok = false
   592  			}
   593  		}
   594  
   595  		if len(need) == 0 {
   596  			return
   597  		}
   598  
   599  		var total uintptr
   600  		for i, name := range need {
   601  			total += have[i]
   602  			t.Logf("found %d samples in expected function %s\n", have[i], name)
   603  		}
   604  		if total == 0 {
   605  			t.Logf("no samples in expected functions")
   606  			ok = false
   607  		}
   608  
   609  		// We'd like to check a reasonable minimum, like
   610  		// total / len(have) / smallconstant, but this test is
   611  		// pretty flaky (see bug 7095).  So we'll just test to
   612  		// make sure we got at least one sample.
   613  		min := uintptr(1)
   614  		for i, name := range need {
   615  			if have[i] < min {
   616  				t.Logf("%s has %d samples out of %d, want at least %d, ideally %d", name, have[i], total, min, total/uintptr(len(have)))
   617  				ok = false
   618  			}
   619  		}
   620  		return
   621  	}
   622  }
   623  
   624  // Fork can hang if preempted with signals frequently enough (see issue 5517).
   625  // Ensure that we do not do this.
   626  func TestCPUProfileWithFork(t *testing.T) {
   627  	testenv.MustHaveExec(t)
   628  
   629  	exe, err := os.Executable()
   630  	if err != nil {
   631  		t.Fatal(err)
   632  	}
   633  
   634  	heap := 1 << 30
   635  	if runtime.GOOS == "android" {
   636  		// Use smaller size for Android to avoid crash.
   637  		heap = 100 << 20
   638  	}
   639  	if testing.Short() {
   640  		heap = 100 << 20
   641  	}
   642  	// This makes fork slower.
   643  	garbage := make([]byte, heap)
   644  	// Need to touch the slice, otherwise it won't be paged in.
   645  	done := make(chan bool)
   646  	go func() {
   647  		for i := range garbage {
   648  			garbage[i] = 42
   649  		}
   650  		done <- true
   651  	}()
   652  	<-done
   653  
   654  	var prof bytes.Buffer
   655  	if err := StartCPUProfile(&prof); err != nil {
   656  		t.Fatal(err)
   657  	}
   658  	defer StopCPUProfile()
   659  
   660  	for i := 0; i < 10; i++ {
   661  		testenv.Command(t, exe, "-h").CombinedOutput()
   662  	}
   663  }
   664  
   665  // Test that profiler does not observe runtime.gogo as "user" goroutine execution.
   666  // If it did, it would see inconsistent state and would either record an incorrect stack
   667  // or crash because the stack was malformed.
   668  func TestGoroutineSwitch(t *testing.T) {
   669  	if runtime.Compiler == "gccgo" {
   670  		t.Skip("not applicable for gccgo")
   671  	}
   672  	// How much to try. These defaults take about 1 seconds
   673  	// on a 2012 MacBook Pro. The ones in short mode take
   674  	// about 0.1 seconds.
   675  	tries := 10
   676  	count := 1000000
   677  	if testing.Short() {
   678  		tries = 1
   679  	}
   680  	for try := 0; try < tries; try++ {
   681  		var prof bytes.Buffer
   682  		if err := StartCPUProfile(&prof); err != nil {
   683  			t.Fatal(err)
   684  		}
   685  		for i := 0; i < count; i++ {
   686  			runtime.Gosched()
   687  		}
   688  		StopCPUProfile()
   689  
   690  		// Read profile to look for entries for gogo with an attempt at a traceback.
   691  		// "runtime.gogo" is OK, because that's the part of the context switch
   692  		// before the actual switch begins. But we should not see "gogo",
   693  		// aka "gogo<>(SB)", which does the actual switch and is marked SPWRITE.
   694  		parseProfile(t, prof.Bytes(), func(count uintptr, stk []*profile.Location, _ map[string][]string) {
   695  			// An entry with two frames with 'System' in its top frame
   696  			// exists to record a PC without a traceback. Those are okay.
   697  			if len(stk) == 2 {
   698  				name := stk[1].Line[0].Function.Name
   699  				if name == "runtime._System" || name == "runtime._ExternalCode" || name == "runtime._GC" {
   700  					return
   701  				}
   702  			}
   703  
   704  			// An entry with just one frame is OK too:
   705  			// it knew to stop at gogo.
   706  			if len(stk) == 1 {
   707  				return
   708  			}
   709  
   710  			// Otherwise, should not see gogo.
   711  			// The place we'd see it would be the inner most frame.
   712  			name := stk[0].Line[0].Function.Name
   713  			if name == "gogo" {
   714  				var buf strings.Builder
   715  				fprintStack(&buf, stk)
   716  				t.Fatalf("found profile entry for gogo:\n%s", buf.String())
   717  			}
   718  		})
   719  	}
   720  }
   721  
   722  func fprintStack(w io.Writer, stk []*profile.Location) {
   723  	if len(stk) == 0 {
   724  		fmt.Fprintf(w, " (stack empty)")
   725  	}
   726  	for _, loc := range stk {
   727  		fmt.Fprintf(w, " %#x", loc.Address)
   728  		fmt.Fprintf(w, " (")
   729  		for i, line := range loc.Line {
   730  			if i > 0 {
   731  				fmt.Fprintf(w, " ")
   732  			}
   733  			fmt.Fprintf(w, "%s:%d", line.Function.Name, line.Line)
   734  		}
   735  		fmt.Fprintf(w, ")")
   736  	}
   737  }
   738  
   739  // Test that profiling of division operations is okay, especially on ARM. See issue 6681.
   740  func TestMathBigDivide(t *testing.T) {
   741  	testCPUProfile(t, nil, func(duration time.Duration) {
   742  		t := time.After(duration)
   743  		pi := new(big.Int)
   744  		for {
   745  			for i := 0; i < 100; i++ {
   746  				n := big.NewInt(2646693125139304345)
   747  				d := big.NewInt(842468587426513207)
   748  				pi.Div(n, d)
   749  			}
   750  			select {
   751  			case <-t:
   752  				return
   753  			default:
   754  			}
   755  		}
   756  	})
   757  }
   758  
   759  // stackContainsAll matches if all functions in spec (comma-separated) appear somewhere in the stack trace.
   760  func stackContainsAll(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
   761  	for _, f := range strings.Split(spec, ",") {
   762  		if !stackContains(f, count, stk, labels) {
   763  			return false
   764  		}
   765  	}
   766  	return true
   767  }
   768  
   769  func TestMorestack(t *testing.T) {
   770  	matches := matchAndAvoidStacks(stackContainsAll, []string{"runtime.newstack,runtime/pprof.growstack"}, avoidFunctions())
   771  	testCPUProfile(t, matches, func(duration time.Duration) {
   772  		t := time.After(duration)
   773  		c := make(chan bool)
   774  		for {
   775  			go func() {
   776  				growstack1()
   777  				// NOTE(vsaioc): This goroutine may leak without this select.
   778  				select {
   779  				case c <- true:
   780  				case <-time.After(duration):
   781  				}
   782  			}()
   783  			select {
   784  			case <-t:
   785  				return
   786  			case <-c:
   787  			}
   788  		}
   789  	})
   790  }
   791  
   792  //go:noinline
   793  func growstack1() {
   794  	growstack(10)
   795  }
   796  
   797  //go:noinline
   798  func growstack(n int) {
   799  	var buf [8 << 18]byte
   800  	use(buf)
   801  	if n > 0 {
   802  		growstack(n - 1)
   803  	}
   804  }
   805  
   806  //go:noinline
   807  func use(x [8 << 18]byte) {}
   808  
   809  func TestBlockProfile(t *testing.T) {
   810  	type TestCase struct {
   811  		name string
   812  		f    func(*testing.T)
   813  		stk  []string
   814  		re   string
   815  	}
   816  	tests := [...]TestCase{
   817  		{
   818  			name: "chan recv",
   819  			f:    blockChanRecv,
   820  			stk: []string{
   821  				"runtime.chanrecv1",
   822  				"runtime/pprof.blockChanRecv",
   823  				"runtime/pprof.TestBlockProfile",
   824  			},
   825  			re: `
   826  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   827  #	0x[0-9a-f]+	runtime\.chanrecv1\+0x[0-9a-f]+	.*runtime/chan.go:[0-9]+
   828  #	0x[0-9a-f]+	runtime/pprof\.blockChanRecv\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   829  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   830  `},
   831  		{
   832  			name: "chan send",
   833  			f:    blockChanSend,
   834  			stk: []string{
   835  				"runtime.chansend1",
   836  				"runtime/pprof.blockChanSend",
   837  				"runtime/pprof.TestBlockProfile",
   838  			},
   839  			re: `
   840  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   841  #	0x[0-9a-f]+	runtime\.chansend1\+0x[0-9a-f]+	.*runtime/chan.go:[0-9]+
   842  #	0x[0-9a-f]+	runtime/pprof\.blockChanSend\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   843  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   844  `},
   845  		{
   846  			name: "chan close",
   847  			f:    blockChanClose,
   848  			stk: []string{
   849  				"runtime.chanrecv1",
   850  				"runtime/pprof.blockChanClose",
   851  				"runtime/pprof.TestBlockProfile",
   852  			},
   853  			re: `
   854  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   855  #	0x[0-9a-f]+	runtime\.chanrecv1\+0x[0-9a-f]+	.*runtime/chan.go:[0-9]+
   856  #	0x[0-9a-f]+	runtime/pprof\.blockChanClose\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   857  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   858  `},
   859  		{
   860  			name: "select recv async",
   861  			f:    blockSelectRecvAsync,
   862  			stk: []string{
   863  				"runtime.selectgo",
   864  				"runtime/pprof.blockSelectRecvAsync",
   865  				"runtime/pprof.TestBlockProfile",
   866  			},
   867  			re: `
   868  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   869  #	0x[0-9a-f]+	runtime\.selectgo\+0x[0-9a-f]+	.*runtime/select.go:[0-9]+
   870  #	0x[0-9a-f]+	runtime/pprof\.blockSelectRecvAsync\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   871  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   872  `},
   873  		{
   874  			name: "select send sync",
   875  			f:    blockSelectSendSync,
   876  			stk: []string{
   877  				"runtime.selectgo",
   878  				"runtime/pprof.blockSelectSendSync",
   879  				"runtime/pprof.TestBlockProfile",
   880  			},
   881  			re: `
   882  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   883  #	0x[0-9a-f]+	runtime\.selectgo\+0x[0-9a-f]+	.*runtime/select.go:[0-9]+
   884  #	0x[0-9a-f]+	runtime/pprof\.blockSelectSendSync\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   885  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   886  `},
   887  		{
   888  			name: "mutex",
   889  			f:    blockMutex,
   890  			stk: []string{
   891  				"sync.(*Mutex).Lock",
   892  				"runtime/pprof.blockMutex",
   893  				"runtime/pprof.TestBlockProfile",
   894  			},
   895  			re: `
   896  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   897  #	0x[0-9a-f]+	sync\.\(\*Mutex\)\.Lock\+0x[0-9a-f]+	.*sync/mutex\.go:[0-9]+
   898  #	0x[0-9a-f]+	runtime/pprof\.blockMutex\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   899  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   900  `},
   901  		{
   902  			name: "cond",
   903  			f:    blockCond,
   904  			stk: []string{
   905  				"sync.(*Cond).Wait",
   906  				"runtime/pprof.blockCond",
   907  				"runtime/pprof.TestBlockProfile",
   908  			},
   909  			re: `
   910  [0-9]+ [0-9]+ @( 0x[[:xdigit:]]+)+
   911  #	0x[0-9a-f]+	sync\.\(\*Cond\)\.Wait\+0x[0-9a-f]+	.*sync/cond\.go:[0-9]+
   912  #	0x[0-9a-f]+	runtime/pprof\.blockCond\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   913  #	0x[0-9a-f]+	runtime/pprof\.TestBlockProfile\+0x[0-9a-f]+	.*runtime/pprof/pprof_test.go:[0-9]+
   914  `},
   915  	}
   916  
   917  	// Generate block profile
   918  	runtime.SetBlockProfileRate(1)
   919  	defer runtime.SetBlockProfileRate(0)
   920  	for _, test := range tests {
   921  		test.f(t)
   922  	}
   923  
   924  	t.Run("debug=1", func(t *testing.T) {
   925  		var w strings.Builder
   926  		Lookup("block").WriteTo(&w, 1)
   927  		prof := w.String()
   928  
   929  		if !strings.HasPrefix(prof, "--- contention:\ncycles/second=") {
   930  			t.Fatalf("Bad profile header:\n%v", prof)
   931  		}
   932  
   933  		if strings.HasSuffix(prof, "#\t0x0\n\n") {
   934  			t.Errorf("Useless 0 suffix:\n%v", prof)
   935  		}
   936  
   937  		for _, test := range tests {
   938  			if !regexp.MustCompile(strings.ReplaceAll(test.re, "\t", "\t+")).MatchString(prof) {
   939  				t.Errorf("Bad %v entry, expect:\n%v\ngot:\n%v", test.name, test.re, prof)
   940  			}
   941  		}
   942  	})
   943  
   944  	t.Run("proto", func(t *testing.T) {
   945  		// proto format
   946  		var w bytes.Buffer
   947  		Lookup("block").WriteTo(&w, 0)
   948  		p, err := profile.Parse(&w)
   949  		if err != nil {
   950  			t.Fatalf("failed to parse profile: %v", err)
   951  		}
   952  		t.Logf("parsed proto: %s", p)
   953  		if err := p.CheckValid(); err != nil {
   954  			t.Fatalf("invalid profile: %v", err)
   955  		}
   956  
   957  		stks := profileStacks(p)
   958  		for _, test := range tests {
   959  			if !containsStack(stks, test.stk) {
   960  				t.Errorf("No matching stack entry for %v, want %+v", test.name, test.stk)
   961  			}
   962  		}
   963  	})
   964  
   965  }
   966  
   967  func profileStacks(p *profile.Profile) (res [][]string) {
   968  	for _, s := range p.Sample {
   969  		var stk []string
   970  		for _, l := range s.Location {
   971  			for _, line := range l.Line {
   972  				stk = append(stk, line.Function.Name)
   973  			}
   974  		}
   975  		res = append(res, stk)
   976  	}
   977  	return res
   978  }
   979  
   980  func blockRecordStacks(records []runtime.BlockProfileRecord) (res [][]string) {
   981  	for _, record := range records {
   982  		frames := runtime.CallersFrames(record.Stack())
   983  		var stk []string
   984  		for {
   985  			frame, more := frames.Next()
   986  			stk = append(stk, frame.Function)
   987  			if !more {
   988  				break
   989  			}
   990  		}
   991  		res = append(res, stk)
   992  	}
   993  	return res
   994  }
   995  
   996  func containsStack(got [][]string, want []string) bool {
   997  	for _, stk := range got {
   998  		if len(stk) < len(want) {
   999  			continue
  1000  		}
  1001  		for i, f := range want {
  1002  			if f != stk[i] {
  1003  				break
  1004  			}
  1005  			if i == len(want)-1 {
  1006  				return true
  1007  			}
  1008  		}
  1009  	}
  1010  	return false
  1011  }
  1012  
  1013  // awaitBlockedGoroutine spins on runtime.Gosched until a runtime stack dump
  1014  // shows a goroutine in the given state with a stack frame in
  1015  // runtime/pprof.<fName>.
  1016  func awaitBlockedGoroutine(t *testing.T, state, fName string, count int) {
  1017  	re := fmt.Sprintf(`(?m)^goroutine \d+ \[%s\]:\n(?:.+\n\t.+\n)*runtime/pprof\.%s`, regexp.QuoteMeta(state), fName)
  1018  	r := regexp.MustCompile(re)
  1019  
  1020  	if deadline, ok := t.Deadline(); ok {
  1021  		if d := time.Until(deadline); d > 1*time.Second {
  1022  			timer := time.AfterFunc(d-1*time.Second, func() {
  1023  				debug.SetTraceback("all")
  1024  				panic(fmt.Sprintf("timed out waiting for %#q", re))
  1025  			})
  1026  			defer timer.Stop()
  1027  		}
  1028  	}
  1029  
  1030  	buf := make([]byte, 64<<10)
  1031  	for {
  1032  		runtime.Gosched()
  1033  		n := runtime.Stack(buf, true)
  1034  		if n == len(buf) {
  1035  			// Buffer wasn't large enough for a full goroutine dump.
  1036  			// Resize it and try again.
  1037  			buf = make([]byte, 2*len(buf))
  1038  			continue
  1039  		}
  1040  		if len(r.FindAll(buf[:n], -1)) >= count {
  1041  			return
  1042  		}
  1043  	}
  1044  }
  1045  
  1046  func blockChanRecv(t *testing.T) {
  1047  	c := make(chan bool)
  1048  	go func() {
  1049  		awaitBlockedGoroutine(t, "chan receive", "blockChanRecv", 1)
  1050  		c <- true
  1051  	}()
  1052  	<-c
  1053  }
  1054  
  1055  func blockChanSend(t *testing.T) {
  1056  	c := make(chan bool)
  1057  	go func() {
  1058  		awaitBlockedGoroutine(t, "chan send", "blockChanSend", 1)
  1059  		<-c
  1060  	}()
  1061  	c <- true
  1062  }
  1063  
  1064  func blockChanClose(t *testing.T) {
  1065  	c := make(chan bool)
  1066  	go func() {
  1067  		awaitBlockedGoroutine(t, "chan receive", "blockChanClose", 1)
  1068  		close(c)
  1069  	}()
  1070  	<-c
  1071  }
  1072  
  1073  func blockSelectRecvAsync(t *testing.T) {
  1074  	const numTries = 3
  1075  	c := make(chan bool, 1)
  1076  	c2 := make(chan bool, 1)
  1077  	go func() {
  1078  		for i := 0; i < numTries; i++ {
  1079  			awaitBlockedGoroutine(t, "select", "blockSelectRecvAsync", 1)
  1080  			c <- true
  1081  		}
  1082  	}()
  1083  	for i := 0; i < numTries; i++ {
  1084  		select {
  1085  		case <-c:
  1086  		case <-c2:
  1087  		}
  1088  	}
  1089  }
  1090  
  1091  func blockSelectSendSync(t *testing.T) {
  1092  	c := make(chan bool)
  1093  	c2 := make(chan bool)
  1094  	go func() {
  1095  		awaitBlockedGoroutine(t, "select", "blockSelectSendSync", 1)
  1096  		<-c
  1097  	}()
  1098  	select {
  1099  	case c <- true:
  1100  	case c2 <- true:
  1101  	}
  1102  }
  1103  
  1104  func blockMutex(t *testing.T) {
  1105  	var mu sync.Mutex
  1106  	mu.Lock()
  1107  	go func() {
  1108  		awaitBlockedGoroutine(t, "sync.Mutex.Lock", "blockMutex", 1)
  1109  		mu.Unlock()
  1110  	}()
  1111  	// Note: Unlock releases mu before recording the mutex event,
  1112  	// so it's theoretically possible for this to proceed and
  1113  	// capture the profile before the event is recorded. As long
  1114  	// as this is blocked before the unlock happens, it's okay.
  1115  	mu.Lock()
  1116  }
  1117  
  1118  func blockMutexN(t *testing.T, n int, d time.Duration) {
  1119  	var wg sync.WaitGroup
  1120  	var mu sync.Mutex
  1121  	mu.Lock()
  1122  	go func() {
  1123  		awaitBlockedGoroutine(t, "sync.Mutex.Lock", "blockMutex", n)
  1124  		time.Sleep(d)
  1125  		mu.Unlock()
  1126  	}()
  1127  	// Note: Unlock releases mu before recording the mutex event,
  1128  	// so it's theoretically possible for this to proceed and
  1129  	// capture the profile before the event is recorded. As long
  1130  	// as this is blocked before the unlock happens, it's okay.
  1131  	for i := 0; i < n; i++ {
  1132  		wg.Add(1)
  1133  		go func() {
  1134  			defer wg.Done()
  1135  			mu.Lock()
  1136  			mu.Unlock()
  1137  		}()
  1138  	}
  1139  	wg.Wait()
  1140  }
  1141  
  1142  func blockCond(t *testing.T) {
  1143  	var mu sync.Mutex
  1144  	c := sync.NewCond(&mu)
  1145  	mu.Lock()
  1146  	go func() {
  1147  		awaitBlockedGoroutine(t, "sync.Cond.Wait", "blockCond", 1)
  1148  		mu.Lock()
  1149  		c.Signal()
  1150  		mu.Unlock()
  1151  	}()
  1152  	c.Wait()
  1153  	mu.Unlock()
  1154  }
  1155  
  1156  // See http://golang.org/cl/299991.
  1157  func TestBlockProfileBias(t *testing.T) {
  1158  	rate := int(1000) // arbitrary value
  1159  	runtime.SetBlockProfileRate(rate)
  1160  	defer runtime.SetBlockProfileRate(0)
  1161  
  1162  	// simulate blocking events
  1163  	blockFrequentShort(rate)
  1164  	blockInfrequentLong(rate)
  1165  
  1166  	var w bytes.Buffer
  1167  	Lookup("block").WriteTo(&w, 0)
  1168  	p, err := profile.Parse(&w)
  1169  	if err != nil {
  1170  		t.Fatalf("failed to parse profile: %v", err)
  1171  	}
  1172  	t.Logf("parsed proto: %s", p)
  1173  
  1174  	il := float64(-1) // blockInfrequentLong duration
  1175  	fs := float64(-1) // blockFrequentShort duration
  1176  	for _, s := range p.Sample {
  1177  		for _, l := range s.Location {
  1178  			for _, line := range l.Line {
  1179  				if len(s.Value) < 2 {
  1180  					t.Fatal("block profile has less than 2 sample types")
  1181  				}
  1182  
  1183  				if line.Function.Name == "runtime/pprof.blockInfrequentLong" {
  1184  					il = float64(s.Value[1])
  1185  				} else if line.Function.Name == "runtime/pprof.blockFrequentShort" {
  1186  					fs = float64(s.Value[1])
  1187  				}
  1188  			}
  1189  		}
  1190  	}
  1191  	if il == -1 || fs == -1 {
  1192  		t.Fatal("block profile is missing expected functions")
  1193  	}
  1194  
  1195  	// stddev of bias from 100 runs on local machine multiplied by 10x
  1196  	const threshold = 0.2
  1197  	if bias := (il - fs) / il; math.Abs(bias) > threshold {
  1198  		t.Fatalf("bias: abs(%f) > %f", bias, threshold)
  1199  	} else {
  1200  		t.Logf("bias: abs(%f) < %f", bias, threshold)
  1201  	}
  1202  }
  1203  
  1204  // blockFrequentShort produces 100000 block events with an average duration of
  1205  // rate / 10.
  1206  func blockFrequentShort(rate int) {
  1207  	for i := 0; i < 100000; i++ {
  1208  		blockevent(int64(rate/10), 1)
  1209  	}
  1210  }
  1211  
  1212  // blockInfrequentLong produces 10000 block events with an average duration of
  1213  // rate.
  1214  func blockInfrequentLong(rate int) {
  1215  	for i := 0; i < 10000; i++ {
  1216  		blockevent(int64(rate), 1)
  1217  	}
  1218  }
  1219  
  1220  // Used by TestBlockProfileBias.
  1221  //
  1222  //go:linkname blockevent runtime.blockevent
  1223  func blockevent(cycles int64, skip int)
  1224  
  1225  func TestMutexProfile(t *testing.T) {
  1226  	// Generate mutex profile
  1227  
  1228  	old := runtime.SetMutexProfileFraction(1)
  1229  	defer runtime.SetMutexProfileFraction(old)
  1230  	if old != 0 {
  1231  		t.Fatalf("need MutexProfileRate 0, got %d", old)
  1232  	}
  1233  
  1234  	const (
  1235  		N = 100
  1236  		D = 100 * time.Millisecond
  1237  	)
  1238  	start := time.Now()
  1239  	blockMutexN(t, N, D)
  1240  	blockMutexNTime := time.Since(start)
  1241  
  1242  	t.Run("debug=1", func(t *testing.T) {
  1243  		var w strings.Builder
  1244  		Lookup("mutex").WriteTo(&w, 1)
  1245  		prof := w.String()
  1246  		t.Logf("received profile: %v", prof)
  1247  
  1248  		if !strings.HasPrefix(prof, "--- mutex:\ncycles/second=") {
  1249  			t.Errorf("Bad profile header:\n%v", prof)
  1250  		}
  1251  		prof = strings.Trim(prof, "\n")
  1252  		lines := strings.Split(prof, "\n")
  1253  		if len(lines) < 6 {
  1254  			t.Fatalf("expected >=6 lines, got %d %q\n%s", len(lines), prof, prof)
  1255  		}
  1256  		// checking that the line is like "35258904 1 @ 0x48288d 0x47cd28 0x458931"
  1257  		r2 := `^\d+ \d+ @(?: 0x[[:xdigit:]]+)+`
  1258  		if ok, err := regexp.MatchString(r2, lines[3]); err != nil || !ok {
  1259  			t.Errorf("%q didn't match %q", lines[3], r2)
  1260  		}
  1261  		r3 := "^#.*runtime/pprof.blockMutex.*$"
  1262  		if ok, err := regexp.MatchString(r3, lines[5]); err != nil || !ok {
  1263  			t.Errorf("%q didn't match %q", lines[5], r3)
  1264  		}
  1265  		t.Log(prof)
  1266  	})
  1267  	t.Run("proto", func(t *testing.T) {
  1268  		// proto format
  1269  		var w bytes.Buffer
  1270  		Lookup("mutex").WriteTo(&w, 0)
  1271  		p, err := profile.Parse(&w)
  1272  		if err != nil {
  1273  			t.Fatalf("failed to parse profile: %v", err)
  1274  		}
  1275  		t.Logf("parsed proto: %s", p)
  1276  		if err := p.CheckValid(); err != nil {
  1277  			t.Fatalf("invalid profile: %v", err)
  1278  		}
  1279  
  1280  		stks := profileStacks(p)
  1281  		for _, want := range [][]string{
  1282  			{"sync.(*Mutex).Unlock", "runtime/pprof.blockMutexN.func1"},
  1283  		} {
  1284  			if !containsStack(stks, want) {
  1285  				t.Errorf("No matching stack entry for %+v", want)
  1286  			}
  1287  		}
  1288  
  1289  		i := 0
  1290  		for ; i < len(p.SampleType); i++ {
  1291  			if p.SampleType[i].Unit == "nanoseconds" {
  1292  				break
  1293  			}
  1294  		}
  1295  		if i >= len(p.SampleType) {
  1296  			t.Fatalf("profile did not contain nanoseconds sample")
  1297  		}
  1298  		total := int64(0)
  1299  		for _, s := range p.Sample {
  1300  			total += s.Value[i]
  1301  		}
  1302  		// Want d to be at least N*D, but give some wiggle-room to avoid
  1303  		// a test flaking. Set an upper-bound proportional to the total
  1304  		// wall time spent in blockMutexN. Generally speaking, the total
  1305  		// contention time could be arbitrarily high when considering
  1306  		// OS scheduler delays, or any other delays from the environment:
  1307  		// time keeps ticking during these delays. By making the upper
  1308  		// bound proportional to the wall time in blockMutexN, in theory
  1309  		// we're accounting for all these possible delays.
  1310  		d := time.Duration(total)
  1311  		lo := time.Duration(N * D * 9 / 10)
  1312  		hi := time.Duration(N) * blockMutexNTime * 11 / 10
  1313  		if d < lo || d > hi {
  1314  			for _, s := range p.Sample {
  1315  				t.Logf("sample: %s", time.Duration(s.Value[i]))
  1316  			}
  1317  			t.Fatalf("profile samples total %v, want within range [%v, %v] (target: %v)", d, lo, hi, N*D)
  1318  		}
  1319  	})
  1320  
  1321  	t.Run("records", func(t *testing.T) {
  1322  		// Record a mutex profile using the structured record API.
  1323  		var records []runtime.BlockProfileRecord
  1324  		for {
  1325  			n, ok := runtime.MutexProfile(records)
  1326  			if ok {
  1327  				records = records[:n]
  1328  				break
  1329  			}
  1330  			records = make([]runtime.BlockProfileRecord, n*2)
  1331  		}
  1332  
  1333  		// Check that we see the same stack trace as the proto profile. For
  1334  		// historical reason we expect a runtime.goexit root frame here that is
  1335  		// omitted in the proto profile.
  1336  		stks := blockRecordStacks(records)
  1337  		want := []string{"sync.(*Mutex).Unlock", "runtime/pprof.blockMutexN.func1", "runtime.goexit"}
  1338  		if !containsStack(stks, want) {
  1339  			t.Errorf("No matching stack entry for %+v", want)
  1340  		}
  1341  	})
  1342  }
  1343  
  1344  func TestMutexProfileRateAdjust(t *testing.T) {
  1345  	old := runtime.SetMutexProfileFraction(1)
  1346  	defer runtime.SetMutexProfileFraction(old)
  1347  	if old != 0 {
  1348  		t.Fatalf("need MutexProfileRate 0, got %d", old)
  1349  	}
  1350  
  1351  	readProfile := func() (contentions int64, delay int64) {
  1352  		var w bytes.Buffer
  1353  		Lookup("mutex").WriteTo(&w, 0)
  1354  		p, err := profile.Parse(&w)
  1355  		if err != nil {
  1356  			t.Fatalf("failed to parse profile: %v", err)
  1357  		}
  1358  		t.Logf("parsed proto: %s", p)
  1359  		if err := p.CheckValid(); err != nil {
  1360  			t.Fatalf("invalid profile: %v", err)
  1361  		}
  1362  
  1363  		for _, s := range p.Sample {
  1364  			var match, runtimeInternal bool
  1365  			for _, l := range s.Location {
  1366  				for _, line := range l.Line {
  1367  					if line.Function.Name == "runtime/pprof.blockMutex.func1" {
  1368  						match = true
  1369  					}
  1370  					if line.Function.Name == "runtime.unlock" {
  1371  						runtimeInternal = true
  1372  					}
  1373  				}
  1374  			}
  1375  			if match && !runtimeInternal {
  1376  				contentions += s.Value[0]
  1377  				delay += s.Value[1]
  1378  			}
  1379  		}
  1380  		return
  1381  	}
  1382  
  1383  	blockMutex(t)
  1384  	contentions, delay := readProfile()
  1385  	if contentions == 0 { // low-resolution timers can have delay of 0 in mutex profile
  1386  		t.Fatal("did not see expected function in profile")
  1387  	}
  1388  	runtime.SetMutexProfileFraction(0)
  1389  	newContentions, newDelay := readProfile()
  1390  	if newContentions != contentions || newDelay != delay {
  1391  		t.Fatalf("sample value changed: got [%d, %d], want [%d, %d]", newContentions, newDelay, contentions, delay)
  1392  	}
  1393  }
  1394  
  1395  func func1(c chan int) { <-c }
  1396  func func2(c chan int) { <-c }
  1397  func func3(c chan int) { <-c }
  1398  func func4(c chan int) { <-c }
  1399  
  1400  func TestGoroutineCounts(t *testing.T) {
  1401  	// Setting GOMAXPROCS to 1 ensures we can force all goroutines to the
  1402  	// desired blocking point.
  1403  	defer runtime.GOMAXPROCS(runtime.GOMAXPROCS(1))
  1404  
  1405  	c := make(chan int)
  1406  	for i := 0; i < 100; 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  		// Let goroutines block on channel
  1416  		for j := 0; j < 5; j++ {
  1417  			runtime.Gosched()
  1418  		}
  1419  	}
  1420  	ctx := context.Background()
  1421  
  1422  	// ... and again, with labels this time (just with fewer iterations to keep
  1423  	// sorting deterministic).
  1424  	Do(ctx, Labels("label", "value"), func(context.Context) {
  1425  		for i := 0; i < 89; i++ {
  1426  			switch {
  1427  			case i%10 == 0:
  1428  				go func1(c)
  1429  			case i%2 == 0:
  1430  				go func2(c)
  1431  			default:
  1432  				go func3(c)
  1433  			}
  1434  			// Let goroutines block on channel
  1435  			for j := 0; j < 5; j++ {
  1436  				runtime.Gosched()
  1437  			}
  1438  		}
  1439  	})
  1440  
  1441  	SetGoroutineLabels(WithLabels(context.Background(), Labels("self-label", "self-value")))
  1442  	defer SetGoroutineLabels(context.Background())
  1443  
  1444  	garbage := new(*int)
  1445  	fingReady := make(chan struct{})
  1446  	runtime.SetFinalizer(garbage, func(v **int) {
  1447  		Do(context.Background(), Labels("fing-label", "fing-value"), func(ctx context.Context) {
  1448  			close(fingReady)
  1449  			<-c
  1450  		})
  1451  	})
  1452  	garbage = nil
  1453  	for i := 0; i < 2; i++ {
  1454  		runtime.GC()
  1455  	}
  1456  	<-fingReady
  1457  
  1458  	var w bytes.Buffer
  1459  	goroutineProf := Lookup("goroutine")
  1460  
  1461  	// Check debug profile
  1462  	goroutineProf.WriteTo(&w, 1)
  1463  	prof := w.String()
  1464  
  1465  	labels := labelMap{Labels("label", "value")}
  1466  	labelStr := "\n# labels: " + labels.String()
  1467  	selfLabel := labelMap{Labels("self-label", "self-value")}
  1468  	selfLabelStr := "\n# labels: " + selfLabel.String()
  1469  	fingLabel := labelMap{Labels("fing-label", "fing-value")}
  1470  	fingLabelStr := "\n# labels: " + fingLabel.String()
  1471  	orderedPrefix := []string{
  1472  		"\n50 @ ",
  1473  		"\n44 @", labelStr,
  1474  		"\n40 @",
  1475  		"\n36 @", labelStr,
  1476  		"\n10 @",
  1477  		"\n9 @", labelStr,
  1478  		"\n1 @"}
  1479  	if !containsInOrder(prof, append(orderedPrefix, selfLabelStr)...) {
  1480  		t.Errorf("expected sorted goroutine counts with Labels:\n%s", prof)
  1481  	}
  1482  	if !containsInOrder(prof, append(orderedPrefix, fingLabelStr)...) {
  1483  		t.Errorf("expected sorted goroutine counts with Labels:\n%s", prof)
  1484  	}
  1485  
  1486  	// Check proto profile
  1487  	w.Reset()
  1488  	goroutineProf.WriteTo(&w, 0)
  1489  	p, err := profile.Parse(&w)
  1490  	if err != nil {
  1491  		t.Errorf("error parsing protobuf profile: %v", err)
  1492  	}
  1493  	if err := p.CheckValid(); err != nil {
  1494  		t.Errorf("protobuf profile is invalid: %v", err)
  1495  	}
  1496  	expectedLabels := map[int64]map[string]string{
  1497  		50: {},
  1498  		44: {"label": "value"},
  1499  		40: {},
  1500  		36: {"label": "value"},
  1501  		10: {},
  1502  		9:  {"label": "value"},
  1503  		1:  {"self-label": "self-value", "fing-label": "fing-value"},
  1504  	}
  1505  	if !containsCountsLabels(p, expectedLabels) {
  1506  		t.Errorf("expected count profile to contain goroutines with counts and labels %v, got %v",
  1507  			expectedLabels, p)
  1508  	}
  1509  
  1510  	close(c)
  1511  
  1512  	time.Sleep(10 * time.Millisecond) // let goroutines exit
  1513  }
  1514  
  1515  func containsInOrder(s string, all ...string) bool {
  1516  	for _, t := range all {
  1517  		var ok bool
  1518  		if _, s, ok = strings.Cut(s, t); !ok {
  1519  			return false
  1520  		}
  1521  	}
  1522  	return true
  1523  }
  1524  
  1525  func containsCountsLabels(prof *profile.Profile, countLabels map[int64]map[string]string) bool {
  1526  	m := make(map[int64]int)
  1527  	type nkey struct {
  1528  		count    int64
  1529  		key, val string
  1530  	}
  1531  	n := make(map[nkey]int)
  1532  	for c, kv := range countLabels {
  1533  		m[c]++
  1534  		for k, v := range kv {
  1535  			n[nkey{
  1536  				count: c,
  1537  				key:   k,
  1538  				val:   v,
  1539  			}]++
  1540  
  1541  		}
  1542  	}
  1543  	for _, s := range prof.Sample {
  1544  		// The count is the single value in the sample
  1545  		if len(s.Value) != 1 {
  1546  			return false
  1547  		}
  1548  		m[s.Value[0]]--
  1549  		for k, vs := range s.Label {
  1550  			for _, v := range vs {
  1551  				n[nkey{
  1552  					count: s.Value[0],
  1553  					key:   k,
  1554  					val:   v,
  1555  				}]--
  1556  			}
  1557  		}
  1558  	}
  1559  	for _, n := range m {
  1560  		if n > 0 {
  1561  			return false
  1562  		}
  1563  	}
  1564  	for _, ncnt := range n {
  1565  		if ncnt != 0 {
  1566  			return false
  1567  		}
  1568  	}
  1569  	return true
  1570  }
  1571  
  1572  // Inlining disabled to make identification simpler.
  1573  //
  1574  //go:noinline
  1575  func goroutineLeakExample() {
  1576  	<-make(chan struct{})
  1577  	panic("unreachable")
  1578  }
  1579  
  1580  func TestGoroutineLeakProfileConcurrency(t *testing.T) {
  1581  	const leakCount = 3
  1582  
  1583  	testenv.MustHaveParallelism(t)
  1584  	regexLeakCount := regexp.MustCompile("goroutineleak profile: total ")
  1585  	whiteSpace := regexp.MustCompile("\\s+")
  1586  
  1587  	// Regular goroutine profile. Used to check that there is no interference between
  1588  	// the two profile types.
  1589  	goroutineProf := Lookup("goroutine")
  1590  	goroutineLeakProf := goroutineLeakProfile
  1591  
  1592  	// Check that a profile with debug information contains
  1593  	includesLeak := func(t *testing.T, name, s string) {
  1594  		if !strings.Contains(s, "runtime/pprof.goroutineLeakExample") {
  1595  			t.Errorf("%s profile does not contain expected leaked goroutine (runtime/pprof.goroutineLeakExample): %s", name, s)
  1596  		}
  1597  	}
  1598  
  1599  	checkFrame := func(i int, j int, locations []*profile.Location, expectedFunctionName string) {
  1600  		if len(locations) <= i {
  1601  			t.Errorf("leaked goroutine stack locations: out of range index %d, length %d", i, len(locations))
  1602  			return
  1603  		}
  1604  		location := locations[i]
  1605  		if len(location.Line) <= j {
  1606  			t.Errorf("leaked goroutine stack location lines: out of range index %d, length %d", j, len(location.Line))
  1607  			return
  1608  		}
  1609  		if location.Line[j].Function.Name != expectedFunctionName {
  1610  			t.Errorf("leaked goroutine stack expected %s as the location[%d].Line[%d] but found %s (%s:%d)", expectedFunctionName, i, j, location.Line[j].Function.Name, location.Line[j].Function.Filename, location.Line[j].Line)
  1611  		}
  1612  	}
  1613  
  1614  	// We use this helper to count the total number of leaked goroutines in the profile.
  1615  	//
  1616  	// NOTE(vsaioc): This value should match for the number of leaks produced in this test,
  1617  	// but other tests could also leak goroutines, in which case we would have a mismatch
  1618  	// when bulk-running tests.
  1619  	//
  1620  	// The two mismatching outcomes are therefore:
  1621  	//	- More leaks than expected, which is a correctness issue with other tests.
  1622  	//		In this case, this test effectively checks other tests wrt
  1623  	//		goroutine leaks during bulk executions (e.g., running all.bash).
  1624  	//
  1625  	//	- Fewer leaks than expected; this is an unfortunate symptom of scheduling
  1626  	//		non-determinism, which may occur once in a blue moon. We make
  1627  	//		a best-effort attempt to allow the expected leaks to occur, by yielding
  1628  	//		the main thread, but it is never a guarantee.
  1629  	countLeaks := func(t *testing.T, number int, s string) {
  1630  		// Strip the profile header
  1631  		parts := regexLeakCount.Split(s, -1)
  1632  		if len(parts) < 2 {
  1633  			t.Fatalf("goroutineleak profile does not contain 'goroutineleak profile: total ': %s\nparts: %v", s, parts)
  1634  			return
  1635  		}
  1636  
  1637  		parts = whiteSpace.Split(parts[1], -1)
  1638  
  1639  		count, err := strconv.ParseInt(parts[0], 10, 64)
  1640  		if err != nil {
  1641  			t.Fatalf("goroutineleak profile count is not a number: %s\nerror: %v", s, err)
  1642  		}
  1643  
  1644  		// Check that the total number of leaked goroutines is exactly the expected number.
  1645  		if count != int64(number) {
  1646  			t.Errorf("goroutineleak profile does not contain exactly %d leaked goroutines: %d", number, count)
  1647  		}
  1648  	}
  1649  
  1650  	checkLeakStack := func(t *testing.T) func(pc uintptr, locations []*profile.Location, _ map[string][]string) {
  1651  		return func(pc uintptr, locations []*profile.Location, _ map[string][]string) {
  1652  			if pc != leakCount {
  1653  				t.Errorf("expected %d leaked goroutines with specific stack configurations, but found %d", leakCount, pc)
  1654  				return
  1655  			}
  1656  			if len(locations) < 4 || len(locations) > 5 {
  1657  				message := fmt.Sprintf("leaked goroutine stack expected 4 or 5 locations but found %d", len(locations))
  1658  				for _, location := range locations {
  1659  					for _, line := range location.Line {
  1660  						message += fmt.Sprintf("\n%s:%d", line.Function.Name, line.Line)
  1661  					}
  1662  				}
  1663  				t.Errorf("%s", message)
  1664  				return
  1665  			}
  1666  			// We expect a receive operation. This is the typical stack.
  1667  			checkFrame(0, 0, locations, "runtime.gopark")
  1668  			checkFrame(1, 0, locations, "runtime.chanrecv")
  1669  			checkFrame(2, 0, locations, "runtime.chanrecv1")
  1670  			checkFrame(3, 0, locations, "runtime/pprof.goroutineLeakExample")
  1671  			if len(locations) == 5 {
  1672  				checkFrame(4, 0, locations, "runtime/pprof.TestGoroutineLeakProfileConcurrency.func5")
  1673  			}
  1674  		}
  1675  	}
  1676  	// Leak some goroutines that will feature in the goroutine leak profile
  1677  	for i := 0; i < leakCount; i++ {
  1678  		go goroutineLeakExample()
  1679  		go func() {
  1680  			// Leak another goroutine that will feature a slightly different stack.
  1681  			// This includes the frame runtime/pprof.TestGoroutineLeakProfileConcurrency.func1.
  1682  			goroutineLeakExample()
  1683  			panic("unreachable")
  1684  		}()
  1685  		// Yield several times to allow the goroutines to leak.
  1686  		runtime.Gosched()
  1687  		runtime.Gosched()
  1688  	}
  1689  
  1690  	// Give all goroutines a chance to leak.
  1691  	time.Sleep(time.Second)
  1692  
  1693  	t.Run("profile contains leak", func(t *testing.T) {
  1694  		var w strings.Builder
  1695  		goroutineLeakProf.WriteTo(&w, 0)
  1696  		parseProfile(t, []byte(w.String()), checkLeakStack(t))
  1697  	})
  1698  
  1699  	t.Run("leak persists between sequential profiling runs", func(t *testing.T) {
  1700  		for i := 0; i < 2; i++ {
  1701  			var w strings.Builder
  1702  			goroutineLeakProf.WriteTo(&w, 0)
  1703  			parseProfile(t, []byte(w.String()), checkLeakStack(t))
  1704  		}
  1705  	})
  1706  
  1707  	// Concurrent calls to the goroutine leak profiler should not trigger data races
  1708  	// or corruption.
  1709  	t.Run("overlapping profile requests", func(t *testing.T) {
  1710  		ctx := context.Background()
  1711  		ctx, cancel := context.WithTimeout(ctx, time.Second)
  1712  		defer cancel()
  1713  
  1714  		var wg sync.WaitGroup
  1715  		for i := 0; i < 2; i++ {
  1716  			wg.Add(1)
  1717  			Do(ctx, Labels("i", fmt.Sprint(i)), func(context.Context) {
  1718  				go func() {
  1719  					defer wg.Done()
  1720  					for ctx.Err() == nil {
  1721  						var w strings.Builder
  1722  						goroutineLeakProf.WriteTo(&w, 1)
  1723  						countLeaks(t, 2*leakCount, w.String())
  1724  						includesLeak(t, "goroutineleak", w.String())
  1725  					}
  1726  				}()
  1727  			})
  1728  		}
  1729  		wg.Wait()
  1730  	})
  1731  
  1732  	// Concurrent calls to the goroutine leak profiler should not trigger data races
  1733  	// or corruption, or interfere with regular goroutine profiles.
  1734  	t.Run("overlapping goroutine and goroutine leak profile requests", func(t *testing.T) {
  1735  		ctx := context.Background()
  1736  		ctx, cancel := context.WithTimeout(ctx, time.Second)
  1737  		defer cancel()
  1738  
  1739  		var wg sync.WaitGroup
  1740  		for i := 0; i < 2; i++ {
  1741  			wg.Add(2)
  1742  			Do(ctx, Labels("i", fmt.Sprint(i)), func(context.Context) {
  1743  				go func() {
  1744  					defer wg.Done()
  1745  					for ctx.Err() == nil {
  1746  						var w strings.Builder
  1747  						goroutineLeakProf.WriteTo(&w, 1)
  1748  						countLeaks(t, 2*leakCount, w.String())
  1749  						includesLeak(t, "goroutineleak", w.String())
  1750  					}
  1751  				}()
  1752  				go func() {
  1753  					defer wg.Done()
  1754  					for ctx.Err() == nil {
  1755  						var w strings.Builder
  1756  						goroutineProf.WriteTo(&w, 1)
  1757  						// The regular goroutine profile should see the leaked
  1758  						// goroutines. We simply check that the goroutine leak
  1759  						// profile does not corrupt the goroutine profile state.
  1760  						includesLeak(t, "goroutine", w.String())
  1761  					}
  1762  				}()
  1763  			})
  1764  		}
  1765  		wg.Wait()
  1766  	})
  1767  }
  1768  
  1769  func TestGoroutineProfileConcurrency(t *testing.T) {
  1770  	testenv.MustHaveParallelism(t)
  1771  
  1772  	goroutineProf := Lookup("goroutine")
  1773  
  1774  	profilerCalls := func(s string) int {
  1775  		return strings.Count(s, "\truntime/pprof.runtime_goroutineProfileWithLabels+")
  1776  	}
  1777  
  1778  	includesFinalizerOrCleanup := func(s string) bool {
  1779  		return strings.Contains(s, "runtime.runFinalizers") || strings.Contains(s, "runtime.runCleanups")
  1780  	}
  1781  
  1782  	// Concurrent calls to the goroutine profiler should not trigger data races
  1783  	// or corruption.
  1784  	t.Run("overlapping profile requests", func(t *testing.T) {
  1785  		ctx := context.Background()
  1786  		ctx, cancel := context.WithTimeout(ctx, 10*time.Second)
  1787  		defer cancel()
  1788  
  1789  		var wg sync.WaitGroup
  1790  		for i := 0; i < 2; i++ {
  1791  			wg.Add(1)
  1792  			Do(ctx, Labels("i", fmt.Sprint(i)), func(context.Context) {
  1793  				go func() {
  1794  					defer wg.Done()
  1795  					for ctx.Err() == nil {
  1796  						var w strings.Builder
  1797  						goroutineProf.WriteTo(&w, 1)
  1798  						prof := w.String()
  1799  						count := profilerCalls(prof)
  1800  						if count >= 2 {
  1801  							t.Logf("prof %d\n%s", count, prof)
  1802  							cancel()
  1803  						}
  1804  					}
  1805  				}()
  1806  			})
  1807  		}
  1808  		wg.Wait()
  1809  	})
  1810  
  1811  	// The finalizer goroutine should not show up in most profiles, since it's
  1812  	// marked as a system goroutine when idle.
  1813  	t.Run("finalizer not present", func(t *testing.T) {
  1814  		var w strings.Builder
  1815  		goroutineProf.WriteTo(&w, 1)
  1816  		prof := w.String()
  1817  		if includesFinalizerOrCleanup(prof) {
  1818  			t.Errorf("profile includes finalizer or cleanup (but should be marked as system):\n%s", prof)
  1819  		}
  1820  	})
  1821  
  1822  	// The finalizer goroutine should show up when it's running user code.
  1823  	t.Run("finalizer present", func(t *testing.T) {
  1824  		// T is a pointer type so it won't be allocated by the tiny
  1825  		// allocator, which can lead to its finalizer not being called
  1826  		// during this test
  1827  		type T *byte
  1828  		obj := new(T)
  1829  		ch1, ch2 := make(chan int), make(chan int)
  1830  		defer close(ch2)
  1831  		runtime.SetFinalizer(obj, func(_ any) {
  1832  			close(ch1)
  1833  			<-ch2
  1834  		})
  1835  		obj = nil
  1836  		for i := 10; i >= 0; i-- {
  1837  			select {
  1838  			case <-ch1:
  1839  			default:
  1840  				if i == 0 {
  1841  					t.Fatalf("finalizer did not run")
  1842  				}
  1843  				runtime.GC()
  1844  			}
  1845  		}
  1846  		var w strings.Builder
  1847  		goroutineProf.WriteTo(&w, 1)
  1848  		prof := w.String()
  1849  		if !includesFinalizerOrCleanup(prof) {
  1850  			t.Errorf("profile does not include finalizer (and it should be marked as user):\n%s", prof)
  1851  		}
  1852  	})
  1853  
  1854  	// Check that new goroutines only show up in order.
  1855  	testLaunches := func(t *testing.T) {
  1856  		var done sync.WaitGroup
  1857  		defer done.Wait()
  1858  
  1859  		ctx := context.Background()
  1860  		ctx, cancel := context.WithCancel(ctx)
  1861  		defer cancel()
  1862  
  1863  		ch := make(chan int)
  1864  		defer close(ch)
  1865  
  1866  		var ready sync.WaitGroup
  1867  
  1868  		// These goroutines all survive until the end of the subtest, so we can
  1869  		// check that a (numbered) goroutine appearing in the profile implies
  1870  		// that all older goroutines also appear in the profile.
  1871  		ready.Add(1)
  1872  		done.Add(1)
  1873  		go func() {
  1874  			defer done.Done()
  1875  			for i := 0; ctx.Err() == nil; i++ {
  1876  				// Use SetGoroutineLabels rather than Do we can always expect an
  1877  				// extra goroutine (this one) with most recent label.
  1878  				SetGoroutineLabels(WithLabels(ctx, Labels(t.Name()+"-loop-i", fmt.Sprint(i))))
  1879  				done.Add(1)
  1880  				go func() {
  1881  					<-ch
  1882  					done.Done()
  1883  				}()
  1884  				for j := 0; j < i; j++ {
  1885  					// Spin for longer and longer as the test goes on. This
  1886  					// goroutine will do O(N^2) work with the number of
  1887  					// goroutines it launches. This should be slow relative to
  1888  					// the work involved in collecting a goroutine profile,
  1889  					// which is O(N) with the high-water mark of the number of
  1890  					// goroutines in this process (in the allgs slice).
  1891  					runtime.Gosched()
  1892  				}
  1893  				if i == 0 {
  1894  					ready.Done()
  1895  				}
  1896  			}
  1897  		}()
  1898  
  1899  		// Short-lived goroutines exercise different code paths (goroutines with
  1900  		// status _Gdead, for instance). This churn doesn't have behavior that
  1901  		// we can test directly, but does help to shake out data races.
  1902  		ready.Add(1)
  1903  		var churn func(i int)
  1904  		churn = func(i int) {
  1905  			SetGoroutineLabels(WithLabels(ctx, Labels(t.Name()+"-churn-i", fmt.Sprint(i))))
  1906  			if i == 0 {
  1907  				ready.Done()
  1908  			} else if i%16 == 0 {
  1909  				// Yield on occasion so this sequence of goroutine launches
  1910  				// doesn't monopolize a P. See issue #52934.
  1911  				runtime.Gosched()
  1912  			}
  1913  			if ctx.Err() == nil {
  1914  				go churn(i + 1)
  1915  			}
  1916  		}
  1917  		go func() {
  1918  			churn(0)
  1919  		}()
  1920  
  1921  		ready.Wait()
  1922  
  1923  		var w [3]bytes.Buffer
  1924  		for i := range w {
  1925  			goroutineProf.WriteTo(&w[i], 0)
  1926  		}
  1927  		for i := range w {
  1928  			p, err := profile.Parse(bytes.NewReader(w[i].Bytes()))
  1929  			if err != nil {
  1930  				t.Errorf("error parsing protobuf profile: %v", err)
  1931  			}
  1932  
  1933  			// High-numbered loop-i goroutines imply that every lower-numbered
  1934  			// loop-i goroutine should be present in the profile too.
  1935  			counts := make(map[string]int)
  1936  			for _, s := range p.Sample {
  1937  				label := s.Label[t.Name()+"-loop-i"]
  1938  				if len(label) > 0 {
  1939  					counts[label[0]]++
  1940  				}
  1941  			}
  1942  			for j, max := 0, len(counts)-1; j <= max; j++ {
  1943  				n := counts[fmt.Sprint(j)]
  1944  				if n == 1 || (n == 2 && j == max) {
  1945  					continue
  1946  				}
  1947  				t.Errorf("profile #%d's goroutines with label loop-i:%d; %d != 1 (or 2 for the last entry, %d)",
  1948  					i+1, j, n, max)
  1949  				t.Logf("counts %v", counts)
  1950  				break
  1951  			}
  1952  		}
  1953  	}
  1954  
  1955  	runs := 100
  1956  	if testing.Short() {
  1957  		runs = 5
  1958  	}
  1959  	for i := 0; i < runs; i++ {
  1960  		// Run multiple times to shake out data races
  1961  		t.Run("goroutine launches", testLaunches)
  1962  	}
  1963  }
  1964  
  1965  // Regression test for #69998.
  1966  func TestGoroutineProfileCoro(t *testing.T) {
  1967  	testenv.MustHaveParallelism(t)
  1968  
  1969  	goroutineProf := Lookup("goroutine")
  1970  
  1971  	// Set up a goroutine to just create and run coroutine goroutines all day.
  1972  	iterFunc := func() {
  1973  		p, stop := iter.Pull2(
  1974  			func(yield func(int, int) bool) {
  1975  				for i := 0; i < 10000; i++ {
  1976  					if !yield(i, i) {
  1977  						return
  1978  					}
  1979  				}
  1980  			},
  1981  		)
  1982  		defer stop()
  1983  		for {
  1984  			_, _, ok := p()
  1985  			if !ok {
  1986  				break
  1987  			}
  1988  		}
  1989  	}
  1990  	var wg sync.WaitGroup
  1991  	done := make(chan struct{})
  1992  	wg.Add(1)
  1993  	go func() {
  1994  		defer wg.Done()
  1995  		for {
  1996  			iterFunc()
  1997  			select {
  1998  			case <-done:
  1999  			default:
  2000  			}
  2001  		}
  2002  	}()
  2003  
  2004  	// Take a goroutine profile. If the bug in #69998 is present, this will crash
  2005  	// with high probability. We don't care about the output for this bug.
  2006  	goroutineProf.WriteTo(io.Discard, 1)
  2007  }
  2008  
  2009  // This test tries to provoke a situation wherein the finalizer goroutine is
  2010  // erroneously inspected by the goroutine profiler in such a way that could
  2011  // cause a crash. See go.dev/issue/74090.
  2012  func TestGoroutineProfileIssue74090(t *testing.T) {
  2013  	testenv.MustHaveParallelism(t)
  2014  
  2015  	goroutineProf := Lookup("goroutine")
  2016  
  2017  	// T is a pointer type so it won't be allocated by the tiny
  2018  	// allocator, which can lead to its finalizer not being called
  2019  	// during this test.
  2020  	type T *byte
  2021  	for range 10 {
  2022  		// We use finalizers for this test because finalizers transition between
  2023  		// system and user goroutine on each call, since there's substantially
  2024  		// more work to do to set up a finalizer call. Cleanups, on the other hand,
  2025  		// transition once for a whole batch, and so are less likely to trigger
  2026  		// the failure. Under stress testing conditions this test fails approximately
  2027  		// 5 times every 1000 executions on a 64 core machine without the appropriate
  2028  		// fix, which is not ideal but if this test crashes at all, it's a clear
  2029  		// signal that something is broken.
  2030  		var objs []*T
  2031  		for range 10000 {
  2032  			obj := new(T)
  2033  			runtime.SetFinalizer(obj, func(_ any) {})
  2034  			objs = append(objs, obj)
  2035  		}
  2036  		objs = nil
  2037  
  2038  		// Queue up all the finalizers.
  2039  		runtime.GC()
  2040  
  2041  		// Try to run a goroutine profile concurrently with finalizer execution
  2042  		// to trigger the bug.
  2043  		var w strings.Builder
  2044  		goroutineProf.WriteTo(&w, 1)
  2045  	}
  2046  }
  2047  
  2048  func BenchmarkGoroutine(b *testing.B) {
  2049  	withIdle := func(n int, fn func(b *testing.B)) func(b *testing.B) {
  2050  		return func(b *testing.B) {
  2051  			c := make(chan int)
  2052  			var ready, done sync.WaitGroup
  2053  			defer func() {
  2054  				close(c)
  2055  				done.Wait()
  2056  			}()
  2057  
  2058  			for i := 0; i < n; i++ {
  2059  				ready.Add(1)
  2060  				done.Add(1)
  2061  				go func() {
  2062  					ready.Done()
  2063  					<-c
  2064  					done.Done()
  2065  				}()
  2066  			}
  2067  			// Let goroutines block on channel
  2068  			ready.Wait()
  2069  			for i := 0; i < 5; i++ {
  2070  				runtime.Gosched()
  2071  			}
  2072  
  2073  			fn(b)
  2074  		}
  2075  	}
  2076  
  2077  	withChurn := func(fn func(b *testing.B)) func(b *testing.B) {
  2078  		return func(b *testing.B) {
  2079  			ctx := context.Background()
  2080  			ctx, cancel := context.WithCancel(ctx)
  2081  			defer cancel()
  2082  
  2083  			var ready sync.WaitGroup
  2084  			ready.Add(1)
  2085  			var count int64
  2086  			var churn func(i int)
  2087  			churn = func(i int) {
  2088  				SetGoroutineLabels(WithLabels(ctx, Labels("churn-i", fmt.Sprint(i))))
  2089  				atomic.AddInt64(&count, 1)
  2090  				if i == 0 {
  2091  					ready.Done()
  2092  				}
  2093  				if ctx.Err() == nil {
  2094  					go churn(i + 1)
  2095  				}
  2096  			}
  2097  			go func() {
  2098  				churn(0)
  2099  			}()
  2100  			ready.Wait()
  2101  
  2102  			fn(b)
  2103  			b.ReportMetric(float64(atomic.LoadInt64(&count))/float64(b.N), "concurrent_launches/op")
  2104  		}
  2105  	}
  2106  
  2107  	benchWriteTo := func(b *testing.B) {
  2108  		goroutineProf := Lookup("goroutine")
  2109  		b.ResetTimer()
  2110  		for i := 0; i < b.N; i++ {
  2111  			goroutineProf.WriteTo(io.Discard, 0)
  2112  		}
  2113  		b.StopTimer()
  2114  	}
  2115  
  2116  	benchGoroutineProfile := func(b *testing.B) {
  2117  		p := make([]runtime.StackRecord, 10000)
  2118  		b.ResetTimer()
  2119  		for i := 0; i < b.N; i++ {
  2120  			runtime.GoroutineProfile(p)
  2121  		}
  2122  		b.StopTimer()
  2123  	}
  2124  
  2125  	// Note that some costs of collecting a goroutine profile depend on the
  2126  	// length of the runtime.allgs slice, which never shrinks. Stay within race
  2127  	// detector's 8k-goroutine limit
  2128  	for _, n := range []int{50, 500, 5000} {
  2129  		b.Run(fmt.Sprintf("Profile.WriteTo idle %d", n), withIdle(n, benchWriteTo))
  2130  		b.Run(fmt.Sprintf("Profile.WriteTo churn %d", n), withIdle(n, withChurn(benchWriteTo)))
  2131  		b.Run(fmt.Sprintf("runtime.GoroutineProfile churn %d", n), withIdle(n, withChurn(benchGoroutineProfile)))
  2132  	}
  2133  }
  2134  
  2135  var emptyCallStackTestRun int64
  2136  
  2137  // Issue 18836.
  2138  func TestEmptyCallStack(t *testing.T) {
  2139  	name := fmt.Sprintf("test18836_%d", emptyCallStackTestRun)
  2140  	emptyCallStackTestRun++
  2141  
  2142  	t.Parallel()
  2143  	var buf strings.Builder
  2144  	p := NewProfile(name)
  2145  
  2146  	p.Add("foo", 47674)
  2147  	p.WriteTo(&buf, 1)
  2148  	p.Remove("foo")
  2149  	got := buf.String()
  2150  	prefix := name + " profile: total 1\n"
  2151  	if !strings.HasPrefix(got, prefix) {
  2152  		t.Fatalf("got:\n\t%q\nwant prefix:\n\t%q\n", got, prefix)
  2153  	}
  2154  	lostevent := "lostProfileEvent"
  2155  	if !strings.Contains(got, lostevent) {
  2156  		t.Fatalf("got:\n\t%q\ndoes not contain:\n\t%q\n", got, lostevent)
  2157  	}
  2158  }
  2159  
  2160  // stackContainsLabeled takes a spec like funcname;key=value and matches if the stack has that key
  2161  // and value and has funcname somewhere in the stack.
  2162  func stackContainsLabeled(spec string, count uintptr, stk []*profile.Location, labels map[string][]string) bool {
  2163  	base, kv, ok := strings.Cut(spec, ";")
  2164  	if !ok {
  2165  		panic("no semicolon in key/value spec")
  2166  	}
  2167  	k, v, ok := strings.Cut(kv, "=")
  2168  	if !ok {
  2169  		panic("missing = in key/value spec")
  2170  	}
  2171  	if !slices.Contains(labels[k], v) {
  2172  		return false
  2173  	}
  2174  	return stackContains(base, count, stk, labels)
  2175  }
  2176  
  2177  func TestCPUProfileLabel(t *testing.T) {
  2178  	matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, avoidFunctions())
  2179  	testCPUProfile(t, matches, func(dur time.Duration) {
  2180  		Do(context.Background(), Labels("key", "value"), func(context.Context) {
  2181  			cpuHogger(cpuHog1, &salt1, dur)
  2182  		})
  2183  	})
  2184  }
  2185  
  2186  func TestLabelRace(t *testing.T) {
  2187  	testenv.MustHaveParallelism(t)
  2188  	// Test the race detector annotations for synchronization
  2189  	// between setting labels and consuming them from the
  2190  	// profile.
  2191  	matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime/pprof.cpuHogger;key=value"}, nil)
  2192  	testCPUProfile(t, matches, func(dur time.Duration) {
  2193  		start := time.Now()
  2194  		var wg sync.WaitGroup
  2195  		for time.Since(start) < dur {
  2196  			var salts [10]int
  2197  			for i := 0; i < 10; i++ {
  2198  				wg.Add(1)
  2199  				go func(j int) {
  2200  					Do(context.Background(), Labels("key", "value"), func(context.Context) {
  2201  						cpuHogger(cpuHog1, &salts[j], time.Millisecond)
  2202  					})
  2203  					wg.Done()
  2204  				}(i)
  2205  			}
  2206  			wg.Wait()
  2207  		}
  2208  	})
  2209  }
  2210  
  2211  func TestGoroutineProfileLabelRace(t *testing.T) {
  2212  	testenv.MustHaveParallelism(t)
  2213  	// Test the race detector annotations for synchronization
  2214  	// between setting labels and consuming them from the
  2215  	// goroutine profile. See issue #50292.
  2216  
  2217  	t.Run("reset", func(t *testing.T) {
  2218  		ctx := context.Background()
  2219  		ctx, cancel := context.WithCancel(ctx)
  2220  		defer cancel()
  2221  
  2222  		go func() {
  2223  			goroutineProf := Lookup("goroutine")
  2224  			for ctx.Err() == nil {
  2225  				var w strings.Builder
  2226  				goroutineProf.WriteTo(&w, 1)
  2227  				prof := w.String()
  2228  				if strings.Contains(prof, "loop-i") {
  2229  					cancel()
  2230  				}
  2231  			}
  2232  		}()
  2233  
  2234  		for i := 0; ctx.Err() == nil; i++ {
  2235  			Do(ctx, Labels("loop-i", fmt.Sprint(i)), func(ctx context.Context) {
  2236  			})
  2237  		}
  2238  	})
  2239  
  2240  	t.Run("churn", func(t *testing.T) {
  2241  		ctx := context.Background()
  2242  		ctx, cancel := context.WithCancel(ctx)
  2243  		defer cancel()
  2244  
  2245  		var ready sync.WaitGroup
  2246  		ready.Add(1)
  2247  		var churn func(i int)
  2248  		churn = func(i int) {
  2249  			SetGoroutineLabels(WithLabels(ctx, Labels("churn-i", fmt.Sprint(i))))
  2250  			if i == 0 {
  2251  				ready.Done()
  2252  			}
  2253  			if ctx.Err() == nil {
  2254  				go churn(i + 1)
  2255  			}
  2256  		}
  2257  		go func() {
  2258  			churn(0)
  2259  		}()
  2260  		ready.Wait()
  2261  
  2262  		goroutineProf := Lookup("goroutine")
  2263  		for i := 0; i < 10; i++ {
  2264  			goroutineProf.WriteTo(io.Discard, 1)
  2265  		}
  2266  	})
  2267  }
  2268  
  2269  // TestLabelSystemstack makes sure CPU profiler samples of goroutines running
  2270  // on systemstack include the correct pprof labels. See issue #48577
  2271  func TestLabelSystemstack(t *testing.T) {
  2272  	// Grab and re-set the initial value before continuing to ensure
  2273  	// GOGC doesn't actually change following the test.
  2274  	gogc := debug.SetGCPercent(100)
  2275  	debug.SetGCPercent(gogc)
  2276  
  2277  	matches := matchAndAvoidStacks(stackContainsLabeled, []string{"runtime.systemstack;key=value"}, avoidFunctions())
  2278  	p := testCPUProfile(t, matches, func(dur time.Duration) {
  2279  		Do(context.Background(), Labels("key", "value"), func(ctx context.Context) {
  2280  			parallelLabelHog(ctx, dur, gogc)
  2281  		})
  2282  	})
  2283  
  2284  	// Two conditions to check:
  2285  	// * labelHog should always be labeled.
  2286  	// * The label should _only_ appear on labelHog and the Do call above.
  2287  	for _, s := range p.Sample {
  2288  		isLabeled := s.Label != nil && slices.Contains(s.Label["key"], "value")
  2289  		var (
  2290  			mayBeLabeled     bool
  2291  			mustBeLabeled    string
  2292  			mustNotBeLabeled string
  2293  		)
  2294  		for _, loc := range s.Location {
  2295  			for _, l := range loc.Line {
  2296  				switch l.Function.Name {
  2297  				case "runtime/pprof.labelHog", "runtime/pprof.parallelLabelHog", "runtime/pprof.parallelLabelHog.func1":
  2298  					mustBeLabeled = l.Function.Name
  2299  				case "runtime/pprof.Do":
  2300  					// Do sets the labels, so samples may
  2301  					// or may not be labeled depending on
  2302  					// which part of the function they are
  2303  					// at.
  2304  					mayBeLabeled = true
  2305  				case "runtime.bgsweep", "runtime.bgscavenge", "runtime.forcegchelper", "runtime.gcBgMarkWorker", "runtime.runFinalizers", "runtime.runCleanups", "runtime.sysmon":
  2306  					// Runtime system goroutines or threads
  2307  					// (such as those identified by
  2308  					// runtime.isSystemGoroutine). These
  2309  					// should never be labeled.
  2310  					mustNotBeLabeled = l.Function.Name
  2311  				case "gogo", "gosave_systemstack_switch", "racecall":
  2312  					// These are context switch/race
  2313  					// critical that we can't do a full
  2314  					// traceback from. Typically this would
  2315  					// be covered by the runtime check
  2316  					// below, but these symbols don't have
  2317  					// the package name.
  2318  					mayBeLabeled = true
  2319  				}
  2320  
  2321  				if strings.HasPrefix(l.Function.Name, "runtime.") {
  2322  					// There are many places in the runtime
  2323  					// where we can't do a full traceback.
  2324  					// Ideally we'd list them all, but
  2325  					// barring that allow anything in the
  2326  					// runtime, unless explicitly excluded
  2327  					// above.
  2328  					mayBeLabeled = true
  2329  				}
  2330  			}
  2331  		}
  2332  		errorStack := func(f string, args ...any) {
  2333  			var buf strings.Builder
  2334  			fprintStack(&buf, s.Location)
  2335  			t.Errorf("%s: %s", fmt.Sprintf(f, args...), buf.String())
  2336  		}
  2337  		if mustBeLabeled != "" && mustNotBeLabeled != "" {
  2338  			errorStack("sample contains both %s, which must be labeled, and %s, which must not be labeled", mustBeLabeled, mustNotBeLabeled)
  2339  			continue
  2340  		}
  2341  		if mustBeLabeled != "" || mustNotBeLabeled != "" {
  2342  			// We found a definitive frame, so mayBeLabeled hints are not relevant.
  2343  			mayBeLabeled = false
  2344  		}
  2345  		if mayBeLabeled {
  2346  			// This sample may or may not be labeled, so there's nothing we can check.
  2347  			continue
  2348  		}
  2349  		if mustBeLabeled != "" && !isLabeled {
  2350  			errorStack("sample must be labeled because of %s, but is not", mustBeLabeled)
  2351  		}
  2352  		if mustNotBeLabeled != "" && isLabeled {
  2353  			errorStack("sample must not be labeled because of %s, but is", mustNotBeLabeled)
  2354  		}
  2355  	}
  2356  }
  2357  
  2358  // labelHog is designed to burn CPU time in a way that a high number of CPU
  2359  // samples end up running on systemstack.
  2360  func labelHog(stop chan struct{}, gogc int) {
  2361  	// Regression test for issue 50032. We must give GC an opportunity to
  2362  	// be initially triggered by a labelled goroutine.
  2363  	runtime.GC()
  2364  
  2365  	for i := 0; ; i++ {
  2366  		select {
  2367  		case <-stop:
  2368  			return
  2369  		default:
  2370  			debug.SetGCPercent(gogc)
  2371  		}
  2372  	}
  2373  }
  2374  
  2375  // parallelLabelHog runs GOMAXPROCS goroutines running labelHog.
  2376  func parallelLabelHog(ctx context.Context, dur time.Duration, gogc int) {
  2377  	var wg sync.WaitGroup
  2378  	stop := make(chan struct{})
  2379  	for i := 0; i < runtime.GOMAXPROCS(0); i++ {
  2380  		wg.Add(1)
  2381  		go func() {
  2382  			defer wg.Done()
  2383  			labelHog(stop, gogc)
  2384  		}()
  2385  	}
  2386  
  2387  	time.Sleep(dur)
  2388  	close(stop)
  2389  	wg.Wait()
  2390  }
  2391  
  2392  // Check that there is no deadlock when the program receives SIGPROF while in
  2393  // 64bit atomics' critical section. Used to happen on mips{,le}. See #20146.
  2394  func TestAtomicLoadStore64(t *testing.T) {
  2395  	f, err := os.CreateTemp("", "profatomic")
  2396  	if err != nil {
  2397  		t.Fatalf("TempFile: %v", err)
  2398  	}
  2399  	defer os.Remove(f.Name())
  2400  	defer f.Close()
  2401  
  2402  	if err := StartCPUProfile(f); err != nil {
  2403  		t.Fatal(err)
  2404  	}
  2405  	defer StopCPUProfile()
  2406  
  2407  	var flag uint64
  2408  	done := make(chan bool, 1)
  2409  
  2410  	go func() {
  2411  		for atomic.LoadUint64(&flag) == 0 {
  2412  			runtime.Gosched()
  2413  		}
  2414  		done <- true
  2415  	}()
  2416  	time.Sleep(50 * time.Millisecond)
  2417  	atomic.StoreUint64(&flag, 1)
  2418  	<-done
  2419  }
  2420  
  2421  func TestTracebackAll(t *testing.T) {
  2422  	// With gccgo, if a profiling signal arrives at the wrong time
  2423  	// during traceback, it may crash or hang. See issue #29448.
  2424  	f, err := os.CreateTemp("", "proftraceback")
  2425  	if err != nil {
  2426  		t.Fatalf("TempFile: %v", err)
  2427  	}
  2428  	defer os.Remove(f.Name())
  2429  	defer f.Close()
  2430  
  2431  	if err := StartCPUProfile(f); err != nil {
  2432  		t.Fatal(err)
  2433  	}
  2434  	defer StopCPUProfile()
  2435  
  2436  	ch := make(chan int)
  2437  	defer close(ch)
  2438  
  2439  	count := 10
  2440  	for i := 0; i < count; i++ {
  2441  		go func() {
  2442  			<-ch // block
  2443  		}()
  2444  	}
  2445  
  2446  	N := 10000
  2447  	if testing.Short() {
  2448  		N = 500
  2449  	}
  2450  	buf := make([]byte, 10*1024)
  2451  	for i := 0; i < N; i++ {
  2452  		runtime.Stack(buf, true)
  2453  	}
  2454  }
  2455  
  2456  // TestTryAdd tests the cases that are hard to test with real program execution.
  2457  //
  2458  // For example, the current go compilers may not always inline functions
  2459  // involved in recursion but that may not be true in the future compilers. This
  2460  // tests such cases by using fake call sequences and forcing the profile build
  2461  // utilizing translateCPUProfile defined in proto_test.go
  2462  func TestTryAdd(t *testing.T) {
  2463  	if _, found := findInlinedCall(inlinedCallerDump, 4<<10); !found {
  2464  		t.Skip("Can't determine whether anything was inlined into inlinedCallerDump.")
  2465  	}
  2466  
  2467  	// inlinedCallerDump
  2468  	//   inlinedCalleeDump
  2469  	pcs := make([]uintptr, 2)
  2470  	inlinedCallerDump(pcs)
  2471  	inlinedCallerStack := make([]uint64, 2)
  2472  	for i := range pcs {
  2473  		inlinedCallerStack[i] = uint64(pcs[i])
  2474  	}
  2475  	wrapperPCs := make([]uintptr, 1)
  2476  	inlinedWrapperCallerDump(wrapperPCs)
  2477  
  2478  	if _, found := findInlinedCall(recursionChainBottom, 4<<10); !found {
  2479  		t.Skip("Can't determine whether anything was inlined into recursionChainBottom.")
  2480  	}
  2481  
  2482  	// recursionChainTop
  2483  	//   recursionChainMiddle
  2484  	//     recursionChainBottom
  2485  	//       recursionChainTop
  2486  	//         recursionChainMiddle
  2487  	//           recursionChainBottom
  2488  	pcs = make([]uintptr, 6)
  2489  	recursionChainTop(1, pcs)
  2490  	recursionStack := make([]uint64, len(pcs))
  2491  	for i := range pcs {
  2492  		recursionStack[i] = uint64(pcs[i])
  2493  	}
  2494  
  2495  	period := int64(2000 * 1000) // 1/500*1e9 nanosec.
  2496  
  2497  	testCases := []struct {
  2498  		name        string
  2499  		input       []uint64          // following the input format assumed by profileBuilder.addCPUData.
  2500  		count       int               // number of records in input.
  2501  		wantLocs    [][]string        // ordered location entries with function names.
  2502  		wantSamples []*profile.Sample // ordered samples, we care only about Value and the profile location IDs.
  2503  	}{{
  2504  		// Sanity test for a normal, complete stack trace.
  2505  		name: "full_stack_trace",
  2506  		input: []uint64{
  2507  			3, 0, 500, // hz = 500. Must match the period.
  2508  			5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
  2509  		},
  2510  		count: 2,
  2511  		wantLocs: [][]string{
  2512  			{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
  2513  		},
  2514  		wantSamples: []*profile.Sample{
  2515  			{Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
  2516  		},
  2517  	}, {
  2518  		name: "bug35538",
  2519  		input: []uint64{
  2520  			3, 0, 500, // hz = 500. Must match the period.
  2521  			// Fake frame: tryAdd will have inlinedCallerDump
  2522  			// (stack[1]) on the deck when it encounters the next
  2523  			// inline function. It should accept this.
  2524  			7, 0, 10, inlinedCallerStack[0], inlinedCallerStack[1], inlinedCallerStack[0], inlinedCallerStack[1],
  2525  			5, 0, 20, inlinedCallerStack[0], inlinedCallerStack[1],
  2526  		},
  2527  		count:    3,
  2528  		wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
  2529  		wantSamples: []*profile.Sample{
  2530  			{Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}}},
  2531  			{Value: []int64{20, 20 * period}, Location: []*profile.Location{{ID: 1}}},
  2532  		},
  2533  	}, {
  2534  		name: "bug38096",
  2535  		input: []uint64{
  2536  			3, 0, 500, // hz = 500. Must match the period.
  2537  			// count (data[2]) == 0 && len(stk) == 1 is an overflow
  2538  			// entry. The "stk" entry is actually the count.
  2539  			4, 0, 0, 4242,
  2540  		},
  2541  		count:    2,
  2542  		wantLocs: [][]string{{"runtime/pprof.lostProfileEvent"}},
  2543  		wantSamples: []*profile.Sample{
  2544  			{Value: []int64{4242, 4242 * period}, Location: []*profile.Location{{ID: 1}}},
  2545  		},
  2546  	}, {
  2547  		// If a function is directly called recursively then it must
  2548  		// not be inlined in the caller.
  2549  		//
  2550  		// N.B. We're generating an impossible profile here, with a
  2551  		// recursive inlineCalleeDump call. This is simulating a non-Go
  2552  		// function that looks like an inlined Go function other than
  2553  		// its recursive property. See pcDeck.tryAdd.
  2554  		name: "directly_recursive_func_is_not_inlined",
  2555  		input: []uint64{
  2556  			3, 0, 500, // hz = 500. Must match the period.
  2557  			5, 0, 30, inlinedCallerStack[0], inlinedCallerStack[0],
  2558  			4, 0, 40, inlinedCallerStack[0],
  2559  		},
  2560  		count: 3,
  2561  		// inlinedCallerDump shows up here because
  2562  		// runtime_expandFinalInlineFrame adds it to the stack frame.
  2563  		wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump"}, {"runtime/pprof.inlinedCallerDump"}},
  2564  		wantSamples: []*profile.Sample{
  2565  			{Value: []int64{30, 30 * period}, Location: []*profile.Location{{ID: 1}, {ID: 1}, {ID: 2}}},
  2566  			{Value: []int64{40, 40 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}}},
  2567  		},
  2568  	}, {
  2569  		name: "recursion_chain_inline",
  2570  		input: []uint64{
  2571  			3, 0, 500, // hz = 500. Must match the period.
  2572  			9, 0, 10, recursionStack[0], recursionStack[1], recursionStack[2], recursionStack[3], recursionStack[4], recursionStack[5],
  2573  		},
  2574  		count: 2,
  2575  		wantLocs: [][]string{
  2576  			{"runtime/pprof.recursionChainBottom"},
  2577  			{
  2578  				"runtime/pprof.recursionChainMiddle",
  2579  				"runtime/pprof.recursionChainTop",
  2580  				"runtime/pprof.recursionChainBottom",
  2581  			},
  2582  			{
  2583  				"runtime/pprof.recursionChainMiddle",
  2584  				"runtime/pprof.recursionChainTop",
  2585  				"runtime/pprof.TestTryAdd", // inlined into the test.
  2586  			},
  2587  		},
  2588  		wantSamples: []*profile.Sample{
  2589  			{Value: []int64{10, 10 * period}, Location: []*profile.Location{{ID: 1}, {ID: 2}, {ID: 3}}},
  2590  		},
  2591  	}, {
  2592  		name: "truncated_stack_trace_later",
  2593  		input: []uint64{
  2594  			3, 0, 500, // hz = 500. Must match the period.
  2595  			5, 0, 50, inlinedCallerStack[0], inlinedCallerStack[1],
  2596  			4, 0, 60, inlinedCallerStack[0],
  2597  		},
  2598  		count:    3,
  2599  		wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
  2600  		wantSamples: []*profile.Sample{
  2601  			{Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
  2602  			{Value: []int64{60, 60 * period}, Location: []*profile.Location{{ID: 1}}},
  2603  		},
  2604  	}, {
  2605  		name: "truncated_stack_trace_first",
  2606  		input: []uint64{
  2607  			3, 0, 500, // hz = 500. Must match the period.
  2608  			4, 0, 70, inlinedCallerStack[0],
  2609  			5, 0, 80, inlinedCallerStack[0], inlinedCallerStack[1],
  2610  		},
  2611  		count:    3,
  2612  		wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
  2613  		wantSamples: []*profile.Sample{
  2614  			{Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
  2615  			{Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 1}}},
  2616  		},
  2617  	}, {
  2618  		// We can recover the inlined caller from a truncated stack.
  2619  		name: "truncated_stack_trace_only",
  2620  		input: []uint64{
  2621  			3, 0, 500, // hz = 500. Must match the period.
  2622  			4, 0, 70, inlinedCallerStack[0],
  2623  		},
  2624  		count:    2,
  2625  		wantLocs: [][]string{{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"}},
  2626  		wantSamples: []*profile.Sample{
  2627  			{Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
  2628  		},
  2629  	}, {
  2630  		// The same location is used for duplicated stacks.
  2631  		name: "truncated_stack_trace_twice",
  2632  		input: []uint64{
  2633  			3, 0, 500, // hz = 500. Must match the period.
  2634  			4, 0, 70, inlinedCallerStack[0],
  2635  			// Fake frame: add a fake call to
  2636  			// inlinedCallerDump to prevent this sample
  2637  			// from getting merged into above.
  2638  			5, 0, 80, inlinedCallerStack[1], inlinedCallerStack[0],
  2639  		},
  2640  		count: 3,
  2641  		wantLocs: [][]string{
  2642  			{"runtime/pprof.inlinedCalleeDump", "runtime/pprof.inlinedCallerDump"},
  2643  			{"runtime/pprof.inlinedCallerDump"},
  2644  		},
  2645  		wantSamples: []*profile.Sample{
  2646  			{Value: []int64{70, 70 * period}, Location: []*profile.Location{{ID: 1}}},
  2647  			{Value: []int64{80, 80 * period}, Location: []*profile.Location{{ID: 2}, {ID: 1}}},
  2648  		},
  2649  	}, {
  2650  		name: "expand_wrapper_function",
  2651  		input: []uint64{
  2652  			3, 0, 500, // hz = 500. Must match the period.
  2653  			4, 0, 50, uint64(wrapperPCs[0]),
  2654  		},
  2655  		count:    2,
  2656  		wantLocs: [][]string{{"runtime/pprof.inlineWrapper.dump"}},
  2657  		wantSamples: []*profile.Sample{
  2658  			{Value: []int64{50, 50 * period}, Location: []*profile.Location{{ID: 1}}},
  2659  		},
  2660  	}}
  2661  
  2662  	for _, tc := range testCases {
  2663  		t.Run(tc.name, func(t *testing.T) {
  2664  			p, err := translateCPUProfile(tc.input, tc.count)
  2665  			if err != nil {
  2666  				t.Fatalf("translating profile: %v", err)
  2667  			}
  2668  			t.Logf("Profile: %v\n", p)
  2669  
  2670  			// One location entry with all inlined functions.
  2671  			var gotLoc [][]string
  2672  			for _, loc := range p.Location {
  2673  				var names []string
  2674  				for _, line := range loc.Line {
  2675  					names = append(names, line.Function.Name)
  2676  				}
  2677  				gotLoc = append(gotLoc, names)
  2678  			}
  2679  			if got, want := fmtJSON(gotLoc), fmtJSON(tc.wantLocs); got != want {
  2680  				t.Errorf("Got Location = %+v\n\twant %+v", got, want)
  2681  			}
  2682  			// All samples should point to one location.
  2683  			var gotSamples []*profile.Sample
  2684  			for _, sample := range p.Sample {
  2685  				var locs []*profile.Location
  2686  				for _, loc := range sample.Location {
  2687  					locs = append(locs, &profile.Location{ID: loc.ID})
  2688  				}
  2689  				gotSamples = append(gotSamples, &profile.Sample{Value: sample.Value, Location: locs})
  2690  			}
  2691  			if got, want := fmtJSON(gotSamples), fmtJSON(tc.wantSamples); got != want {
  2692  				t.Errorf("Got Samples = %+v\n\twant %+v", got, want)
  2693  			}
  2694  		})
  2695  	}
  2696  }
  2697  
  2698  func TestTimeVDSO(t *testing.T) {
  2699  	// Test that time functions have the right stack trace. In particular,
  2700  	// it shouldn't be recursive.
  2701  
  2702  	if runtime.GOOS == "android" {
  2703  		// Flaky on Android, issue 48655. VDSO may not be enabled.
  2704  		testenv.SkipFlaky(t, 48655)
  2705  	}
  2706  
  2707  	matches := matchAndAvoidStacks(stackContains, []string{"time.now"}, avoidFunctions())
  2708  	p := testCPUProfile(t, matches, func(dur time.Duration) {
  2709  		t0 := time.Now()
  2710  		for {
  2711  			t := time.Now()
  2712  			if t.Sub(t0) >= dur {
  2713  				return
  2714  			}
  2715  		}
  2716  	})
  2717  
  2718  	// Check for recursive time.now sample.
  2719  	for _, sample := range p.Sample {
  2720  		var seenNow bool
  2721  		for _, loc := range sample.Location {
  2722  			for _, line := range loc.Line {
  2723  				if line.Function.Name == "time.now" {
  2724  					if seenNow {
  2725  						t.Fatalf("unexpected recursive time.now")
  2726  					}
  2727  					seenNow = true
  2728  				}
  2729  			}
  2730  		}
  2731  	}
  2732  }
  2733  
  2734  func TestProfilerStackDepth(t *testing.T) {
  2735  	t.Cleanup(disableSampling())
  2736  
  2737  	const depth = 128
  2738  	go produceProfileEvents(t, depth)
  2739  	awaitBlockedGoroutine(t, "chan receive", "goroutineDeep", 1)
  2740  
  2741  	tests := []struct {
  2742  		profiler string
  2743  		prefix   []string
  2744  	}{
  2745  		{"heap", []string{"runtime/pprof.allocDeep"}},
  2746  		{"block", []string{"runtime.chanrecv1", "runtime/pprof.blockChanDeep"}},
  2747  		{"mutex", []string{"sync.(*Mutex).Unlock", "runtime/pprof.blockMutexDeep"}},
  2748  		{"goroutine", []string{"runtime.gopark", "runtime.chanrecv", "runtime.chanrecv1", "runtime/pprof.goroutineDeep"}},
  2749  	}
  2750  
  2751  	for _, test := range tests {
  2752  		t.Run(test.profiler, func(t *testing.T) {
  2753  			var buf bytes.Buffer
  2754  			if err := Lookup(test.profiler).WriteTo(&buf, 0); err != nil {
  2755  				t.Fatalf("failed to write heap profile: %v", err)
  2756  			}
  2757  			p, err := profile.Parse(&buf)
  2758  			if err != nil {
  2759  				t.Fatalf("failed to parse heap profile: %v", err)
  2760  			}
  2761  			t.Logf("Profile = %v", p)
  2762  
  2763  			stks := profileStacks(p)
  2764  			var matchedStacks [][]string
  2765  			for _, stk := range stks {
  2766  				if !hasPrefix(stk, test.prefix) {
  2767  					continue
  2768  				}
  2769  				// We may get multiple stacks which contain the prefix we want, but
  2770  				// which might not have enough frames, e.g. if the profiler hides
  2771  				// some leaf frames that would count against the stack depth limit.
  2772  				// Check for at least one match
  2773  				matchedStacks = append(matchedStacks, stk)
  2774  				if len(stk) != depth {
  2775  					continue
  2776  				}
  2777  				if rootFn, wantFn := stk[depth-1], "runtime/pprof.produceProfileEvents"; rootFn != wantFn {
  2778  					continue
  2779  				}
  2780  				// Found what we wanted
  2781  				return
  2782  			}
  2783  			for _, stk := range matchedStacks {
  2784  				t.Logf("matched stack=%s", stk)
  2785  				if len(stk) != depth {
  2786  					t.Errorf("want stack depth = %d, got %d", depth, len(stk))
  2787  					continue
  2788  				}
  2789  
  2790  				if rootFn, wantFn := stk[depth-1], "runtime/pprof.allocDeep"; rootFn != wantFn {
  2791  					t.Errorf("want stack stack root %s, got %v", wantFn, rootFn)
  2792  				}
  2793  			}
  2794  		})
  2795  	}
  2796  }
  2797  
  2798  func hasPrefix(stk []string, prefix []string) bool {
  2799  	return len(prefix) <= len(stk) && slices.Equal(stk[:len(prefix)], prefix)
  2800  }
  2801  
  2802  // ensure that stack records are valid map keys (comparable)
  2803  var _ = map[runtime.MemProfileRecord]struct{}{}
  2804  var _ = map[runtime.StackRecord]struct{}{}
  2805  
  2806  // allocDeep calls itself n times before calling fn.
  2807  func allocDeep(n int) {
  2808  	if n > 1 {
  2809  		allocDeep(n - 1)
  2810  		return
  2811  	}
  2812  	memSink = make([]byte, 1<<20)
  2813  }
  2814  
  2815  // blockChanDeep produces a block profile event at stack depth n, including the
  2816  // caller.
  2817  func blockChanDeep(t *testing.T, n int) {
  2818  	if n > 1 {
  2819  		blockChanDeep(t, n-1)
  2820  		return
  2821  	}
  2822  	ch := make(chan struct{})
  2823  	go func() {
  2824  		awaitBlockedGoroutine(t, "chan receive", "blockChanDeep", 1)
  2825  		ch <- struct{}{}
  2826  	}()
  2827  	<-ch
  2828  }
  2829  
  2830  // blockMutexDeep produces a block profile event at stack depth n, including the
  2831  // caller.
  2832  func blockMutexDeep(t *testing.T, n int) {
  2833  	if n > 1 {
  2834  		blockMutexDeep(t, n-1)
  2835  		return
  2836  	}
  2837  	var mu sync.Mutex
  2838  	go func() {
  2839  		mu.Lock()
  2840  		mu.Lock()
  2841  	}()
  2842  	awaitBlockedGoroutine(t, "sync.Mutex.Lock", "blockMutexDeep", 1)
  2843  	mu.Unlock()
  2844  }
  2845  
  2846  // goroutineDeep blocks at stack depth n, including the caller until the test is
  2847  // finished.
  2848  func goroutineDeep(t *testing.T, n int) {
  2849  	if n > 1 {
  2850  		goroutineDeep(t, n-1)
  2851  		return
  2852  	}
  2853  	wait := make(chan struct{}, 1)
  2854  	t.Cleanup(func() {
  2855  		wait <- struct{}{}
  2856  	})
  2857  	<-wait
  2858  }
  2859  
  2860  // produceProfileEvents produces pprof events at the given stack depth and then
  2861  // blocks in goroutineDeep until the test completes. The stack traces are
  2862  // guaranteed to have exactly the desired depth with produceProfileEvents as
  2863  // their root frame which is expected by TestProfilerStackDepth.
  2864  func produceProfileEvents(t *testing.T, depth int) {
  2865  	allocDeep(depth - 1)       // -1 for produceProfileEvents, **
  2866  	blockChanDeep(t, depth-2)  // -2 for produceProfileEvents, **, chanrecv1
  2867  	blockMutexDeep(t, depth-2) // -2 for produceProfileEvents, **, Unlock
  2868  	memSink = nil
  2869  	runtime.GC()
  2870  	goroutineDeep(t, depth-4) // -4 for produceProfileEvents, **, chanrecv1, chanrev, gopark
  2871  }
  2872  
  2873  func getProfileStacks(collect func([]runtime.BlockProfileRecord) (int, bool), fileLine bool, pcs bool) []string {
  2874  	var n int
  2875  	var ok bool
  2876  	var p []runtime.BlockProfileRecord
  2877  	for {
  2878  		p = make([]runtime.BlockProfileRecord, n)
  2879  		n, ok = collect(p)
  2880  		if ok {
  2881  			p = p[:n]
  2882  			break
  2883  		}
  2884  	}
  2885  	var stacks []string
  2886  	for _, r := range p {
  2887  		var stack strings.Builder
  2888  		for i, pc := range r.Stack() {
  2889  			if i > 0 {
  2890  				stack.WriteByte('\n')
  2891  			}
  2892  			if pcs {
  2893  				fmt.Fprintf(&stack, "%x ", pc)
  2894  			}
  2895  			// Use FuncForPC instead of CallersFrames,
  2896  			// because we want to see the info for exactly
  2897  			// the PCs returned by the mutex profile to
  2898  			// ensure inlined calls have already been properly
  2899  			// expanded.
  2900  			f := runtime.FuncForPC(pc - 1)
  2901  			stack.WriteString(f.Name())
  2902  			if fileLine {
  2903  				stack.WriteByte(' ')
  2904  				file, line := f.FileLine(pc - 1)
  2905  				stack.WriteString(file)
  2906  				stack.WriteByte(':')
  2907  				stack.WriteString(strconv.Itoa(line))
  2908  			}
  2909  		}
  2910  		stacks = append(stacks, stack.String())
  2911  	}
  2912  	return stacks
  2913  }
  2914  
  2915  func TestMutexBlockFullAggregation(t *testing.T) {
  2916  	// This regression test is adapted from
  2917  	// https://github.com/grafana/pyroscope-go/issues/103,
  2918  	// authored by Tolya Korniltsev
  2919  
  2920  	var m sync.Mutex
  2921  
  2922  	prev := runtime.SetMutexProfileFraction(-1)
  2923  	defer runtime.SetMutexProfileFraction(prev)
  2924  
  2925  	const fraction = 1
  2926  	const iters = 100
  2927  	const workers = 2
  2928  
  2929  	runtime.SetMutexProfileFraction(fraction)
  2930  	runtime.SetBlockProfileRate(1)
  2931  	defer runtime.SetBlockProfileRate(0)
  2932  
  2933  	wg := sync.WaitGroup{}
  2934  	wg.Add(workers)
  2935  	for range workers {
  2936  		go func() {
  2937  			for range iters {
  2938  				m.Lock()
  2939  				// Wait at least 1 millisecond to pass the
  2940  				// starvation threshold for the mutex
  2941  				time.Sleep(time.Millisecond)
  2942  				m.Unlock()
  2943  			}
  2944  			wg.Done()
  2945  		}()
  2946  	}
  2947  	wg.Wait()
  2948  
  2949  	assertNoDuplicates := func(name string, collect func([]runtime.BlockProfileRecord) (int, bool)) {
  2950  		stacks := getProfileStacks(collect, true, true)
  2951  		seen := make(map[string]struct{})
  2952  		for _, s := range stacks {
  2953  			if _, ok := seen[s]; ok {
  2954  				t.Errorf("saw duplicate entry in %s profile with stack:\n%s", name, s)
  2955  			}
  2956  			seen[s] = struct{}{}
  2957  		}
  2958  		if len(seen) == 0 {
  2959  			t.Errorf("did not see any samples in %s profile for this test", name)
  2960  		}
  2961  	}
  2962  	t.Run("mutex", func(t *testing.T) {
  2963  		assertNoDuplicates("mutex", runtime.MutexProfile)
  2964  	})
  2965  	t.Run("block", func(t *testing.T) {
  2966  		assertNoDuplicates("block", runtime.BlockProfile)
  2967  	})
  2968  }
  2969  
  2970  func inlineA(mu *sync.Mutex, wg *sync.WaitGroup) { inlineB(mu, wg) }
  2971  func inlineB(mu *sync.Mutex, wg *sync.WaitGroup) { inlineC(mu, wg) }
  2972  func inlineC(mu *sync.Mutex, wg *sync.WaitGroup) {
  2973  	defer wg.Done()
  2974  	mu.Lock()
  2975  	mu.Unlock()
  2976  }
  2977  
  2978  func inlineD(mu *sync.Mutex, wg *sync.WaitGroup) { inlineE(mu, wg) }
  2979  func inlineE(mu *sync.Mutex, wg *sync.WaitGroup) { inlineF(mu, wg) }
  2980  func inlineF(mu *sync.Mutex, wg *sync.WaitGroup) {
  2981  	defer wg.Done()
  2982  	mu.Unlock()
  2983  }
  2984  
  2985  func TestBlockMutexProfileInlineExpansion(t *testing.T) {
  2986  	runtime.SetBlockProfileRate(1)
  2987  	defer runtime.SetBlockProfileRate(0)
  2988  	prev := runtime.SetMutexProfileFraction(1)
  2989  	defer runtime.SetMutexProfileFraction(prev)
  2990  
  2991  	var mu sync.Mutex
  2992  	var wg sync.WaitGroup
  2993  	wg.Add(2)
  2994  	mu.Lock()
  2995  	go inlineA(&mu, &wg)
  2996  	awaitBlockedGoroutine(t, "sync.Mutex.Lock", "inlineC", 1)
  2997  	// inlineD will unblock inlineA
  2998  	go inlineD(&mu, &wg)
  2999  	wg.Wait()
  3000  
  3001  	tcs := []struct {
  3002  		Name     string
  3003  		Collect  func([]runtime.BlockProfileRecord) (int, bool)
  3004  		SubStack string
  3005  	}{
  3006  		{
  3007  			Name:    "mutex",
  3008  			Collect: runtime.MutexProfile,
  3009  			SubStack: `sync.(*Mutex).Unlock
  3010  runtime/pprof.inlineF
  3011  runtime/pprof.inlineE
  3012  runtime/pprof.inlineD`,
  3013  		},
  3014  		{
  3015  			Name:    "block",
  3016  			Collect: runtime.BlockProfile,
  3017  			SubStack: `sync.(*Mutex).Lock
  3018  runtime/pprof.inlineC
  3019  runtime/pprof.inlineB
  3020  runtime/pprof.inlineA`,
  3021  		},
  3022  	}
  3023  
  3024  	for _, tc := range tcs {
  3025  		t.Run(tc.Name, func(t *testing.T) {
  3026  			stacks := getProfileStacks(tc.Collect, false, false)
  3027  			for _, s := range stacks {
  3028  				if strings.Contains(s, tc.SubStack) {
  3029  					return
  3030  				}
  3031  			}
  3032  			t.Error("did not see expected stack")
  3033  			t.Logf("wanted:\n%s", tc.SubStack)
  3034  			t.Logf("got: %s", stacks)
  3035  		})
  3036  	}
  3037  }
  3038  
  3039  func TestProfileRecordNullPadding(t *testing.T) {
  3040  	// Produce events for the different profile types.
  3041  	t.Cleanup(disableSampling())
  3042  	memSink = make([]byte, 1)      // MemProfile
  3043  	<-time.After(time.Millisecond) // BlockProfile
  3044  	blockMutex(t)                  // MutexProfile
  3045  	runtime.GC()
  3046  
  3047  	// Test that all profile records are null padded.
  3048  	testProfileRecordNullPadding(t, "MutexProfile", runtime.MutexProfile)
  3049  	testProfileRecordNullPadding(t, "GoroutineProfile", runtime.GoroutineProfile)
  3050  	testProfileRecordNullPadding(t, "BlockProfile", runtime.BlockProfile)
  3051  	testProfileRecordNullPadding(t, "MemProfile/inUseZero=true", func(p []runtime.MemProfileRecord) (int, bool) {
  3052  		return runtime.MemProfile(p, true)
  3053  	})
  3054  	testProfileRecordNullPadding(t, "MemProfile/inUseZero=false", func(p []runtime.MemProfileRecord) (int, bool) {
  3055  		return runtime.MemProfile(p, false)
  3056  	})
  3057  	// Not testing ThreadCreateProfile because it is broken, see issue 6104.
  3058  }
  3059  
  3060  func testProfileRecordNullPadding[T runtime.StackRecord | runtime.MemProfileRecord | runtime.BlockProfileRecord](t *testing.T, name string, fn func([]T) (int, bool)) {
  3061  	stack0 := func(sr *T) *[32]uintptr {
  3062  		switch t := any(sr).(type) {
  3063  		case *runtime.StackRecord:
  3064  			return &t.Stack0
  3065  		case *runtime.MemProfileRecord:
  3066  			return &t.Stack0
  3067  		case *runtime.BlockProfileRecord:
  3068  			return &t.Stack0
  3069  		default:
  3070  			panic(fmt.Sprintf("unexpected type %T", sr))
  3071  		}
  3072  	}
  3073  
  3074  	t.Run(name, func(t *testing.T) {
  3075  		var p []T
  3076  		for {
  3077  			n, ok := fn(p)
  3078  			if ok {
  3079  				p = p[:n]
  3080  				break
  3081  			}
  3082  			p = make([]T, n*2)
  3083  			for i := range p {
  3084  				s0 := stack0(&p[i])
  3085  				for j := range s0 {
  3086  					// Poison the Stack0 array to identify lack of zero padding
  3087  					s0[j] = ^uintptr(0)
  3088  				}
  3089  			}
  3090  		}
  3091  
  3092  		if len(p) == 0 {
  3093  			t.Fatal("no records found")
  3094  		}
  3095  
  3096  		for _, sr := range p {
  3097  			for i, v := range stack0(&sr) {
  3098  				if v == ^uintptr(0) {
  3099  					t.Fatalf("record p[%d].Stack0 is not null padded: %+v", i, sr)
  3100  				}
  3101  			}
  3102  		}
  3103  	})
  3104  }
  3105  
  3106  // disableSampling configures the profilers to capture all events, otherwise
  3107  // it's difficult to assert anything.
  3108  func disableSampling() func() {
  3109  	oldMemRate := runtime.MemProfileRate
  3110  	runtime.MemProfileRate = 1
  3111  	runtime.SetBlockProfileRate(1)
  3112  	oldMutexRate := runtime.SetMutexProfileFraction(1)
  3113  	return func() {
  3114  		runtime.MemProfileRate = oldMemRate
  3115  		runtime.SetBlockProfileRate(0)
  3116  		runtime.SetMutexProfileFraction(oldMutexRate)
  3117  	}
  3118  }
  3119  

View as plain text