cpu-profile.go

     1  // Copyright 2023 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  // Tests CPU profiling.
     6  
     7  //go:build ignore
     8  
     9  package main
    10  
    11  import (
    12  	"bytes"
    13  	"context"
    14  	"fmt"
    15  	"internal/profile"
    16  	"log"
    17  	"os"
    18  	"runtime"
    19  	"runtime/pprof"
    20  	"runtime/trace"
    21  	"strings"
    22  	"time"
    23  )
    24  
    25  func main() {
    26  	cpuBuf := new(bytes.Buffer)
    27  	if err := pprof.StartCPUProfile(cpuBuf); err != nil {
    28  		log.Fatalf("failed to start CPU profile: %v", err)
    29  	}
    30  
    31  	if err := trace.Start(os.Stdout); err != nil {
    32  		log.Fatalf("failed to start tracing: %v", err)
    33  	}
    34  
    35  	dur := 100 * time.Millisecond
    36  	func() {
    37  		// Create a region in the execution trace. Set and clear goroutine
    38  		// labels fully within that region, so we know that any CPU profile
    39  		// sample with the label must also be eligible for inclusion in the
    40  		// execution trace.
    41  		ctx := context.Background()
    42  		defer trace.StartRegion(ctx, "cpuHogger").End()
    43  		pprof.Do(ctx, pprof.Labels("tracing", "on"), func(ctx context.Context) {
    44  			cpuHogger(cpuHog1, &salt1, dur)
    45  		})
    46  		// Be sure the execution trace's view, when filtered to this goroutine
    47  		// via the explicit goroutine ID in each event, gets many more samples
    48  		// than the CPU profiler when filtered to this goroutine via labels.
    49  		cpuHogger(cpuHog1, &salt1, dur)
    50  	}()
    51  
    52  	trace.Stop()
    53  	pprof.StopCPUProfile()
    54  
    55  	// Summarize the CPU profile to stderr so the test can check against it.
    56  
    57  	prof, err := profile.Parse(cpuBuf)
    58  	if err != nil {
    59  		log.Fatalf("failed to parse CPU profile: %v", err)
    60  	}
    61  	// Examine the CPU profiler's view. Filter it to only include samples from
    62  	// the single test goroutine. Use labels to execute that filter: they should
    63  	// apply to all work done while that goroutine is getg().m.curg, and they
    64  	// should apply to no other goroutines.
    65  	pprofStacks := make(map[string]int)
    66  	for _, s := range prof.Sample {
    67  		if s.Label["tracing"] != nil {
    68  			var fns []string
    69  			var leaf string
    70  			for _, loc := range s.Location {
    71  				for _, line := range loc.Line {
    72  					fns = append(fns, fmt.Sprintf("%s:%d", line.Function.Name, line.Line))
    73  					leaf = line.Function.Name
    74  				}
    75  			}
    76  			// runtime.sigprof synthesizes call stacks when "normal traceback is
    77  			// impossible or has failed", using particular placeholder functions
    78  			// to represent common failure cases. Look for those functions in
    79  			// the leaf position as a sign that the call stack and its
    80  			// symbolization are more complex than this test can handle.
    81  			//
    82  			// TODO: Make the symbolization done by the execution tracer and CPU
    83  			// profiler match up even in these harder cases. See #53378.
    84  			switch leaf {
    85  			case "runtime._System", "runtime._GC", "runtime._ExternalCode", "runtime._VDSO":
    86  				continue
    87  			}
    88  			stack := strings.Join(fns, "|")
    89  			samples := int(s.Value[0])
    90  			pprofStacks[stack] += samples
    91  		}
    92  	}
    93  	for stack, samples := range pprofStacks {
    94  		fmt.Fprintf(os.Stderr, "%s\t%d\n", stack, samples)
    95  	}
    96  }
    97  
    98  func cpuHogger(f func(x int) int, y *int, dur time.Duration) {
    99  	// We only need to get one 100 Hz clock tick, so we've got
   100  	// a large safety buffer.
   101  	// But do at least 500 iterations (which should take about 100ms),
   102  	// otherwise TestCPUProfileMultithreaded can fail if only one
   103  	// thread is scheduled during the testing period.
   104  	t0 := time.Now()
   105  	accum := *y
   106  	for i := 0; i < 500 || time.Since(t0) < dur; i++ {
   107  		accum = f(accum)
   108  	}
   109  	*y = accum
   110  }
   111  
   112  var (
   113  	salt1 = 0
   114  )
   115  
   116  // The actual CPU hogging function.
   117  // Must not call other functions nor access heap/globals in the loop,
   118  // otherwise under race detector the samples will be in the race runtime.
   119  func cpuHog1(x int) int {
   120  	return cpuHog0(x, 1e5)
   121  }
   122  
   123  func cpuHog0(x, n int) int {
   124  	foo := x
   125  	for i := 0; i < n; i++ {
   126  		if i%1000 == 0 {
   127  			// Spend time in mcall, stored as gp.m.curg, with g0 running
   128  			runtime.Gosched()
   129  		}
   130  		if foo > 0 {
   131  			foo *= foo
   132  		} else {
   133  			foo *= foo + 1
   134  		}
   135  	}
   136  	return foo
   137  }
   138
View as plain text