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

View as plain text