pprof.go

Documentation: runtime/pprof

     1  // Copyright 2010 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  // Package pprof writes runtime profiling data in the format expected
     6  // by the pprof visualization tool.
     7  //
     8  // Profiling a Go program
     9  //
    10  // The first step to profiling a Go program is to enable profiling.
    11  // Support for profiling benchmarks built with the standard testing
    12  // package is built into go test. For example, the following command
    13  // runs benchmarks in the current directory and writes the CPU and
    14  // memory profiles to cpu.prof and mem.prof:
    15  //
    16  //     go test -cpuprofile cpu.prof -memprofile mem.prof -bench .
    17  //
    18  // To add equivalent profiling support to a standalone program, add
    19  // code like the following to your main function:
    20  //
    21  //    var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`")
    22  //    var memprofile = flag.String("memprofile", "", "write memory profile to `file`")
    23  //
    24  //    func main() {
    25  //        flag.Parse()
    26  //        if *cpuprofile != "" {
    27  //            f, err := os.Create(*cpuprofile)
    28  //            if err != nil {
    29  //                log.Fatal("could not create CPU profile: ", err)
    30  //            }
    31  //            if err := pprof.StartCPUProfile(f); err != nil {
    32  //                log.Fatal("could not start CPU profile: ", err)
    33  //            }
    34  //            defer pprof.StopCPUProfile()
    35  //        }
    36  //
    37  //        // ... rest of the program ...
    38  //
    39  //        if *memprofile != "" {
    40  //            f, err := os.Create(*memprofile)
    41  //            if err != nil {
    42  //                log.Fatal("could not create memory profile: ", err)
    43  //            }
    44  //            runtime.GC() // get up-to-date statistics
    45  //            if err := pprof.WriteHeapProfile(f); err != nil {
    46  //                log.Fatal("could not write memory profile: ", err)
    47  //            }
    48  //            f.Close()
    49  //        }
    50  //    }
    51  //
    52  // There is also a standard HTTP interface to profiling data. Adding
    53  // the following line will install handlers under the /debug/pprof/
    54  // URL to download live profiles:
    55  //
    56  //    import _ "net/http/pprof"
    57  //
    58  // See the net/http/pprof package for more details.
    59  //
    60  // Profiles can then be visualized with the pprof tool:
    61  //
    62  //    go tool pprof cpu.prof
    63  //
    64  // There are many commands available from the pprof command line.
    65  // Commonly used commands include "top", which prints a summary of the
    66  // top program hot-spots, and "web", which opens an interactive graph
    67  // of hot-spots and their call graphs. Use "help" for information on
    68  // all pprof commands.
    69  //
    70  // For more information about pprof, see
    71  // https://github.com/google/pprof/blob/master/doc/pprof.md.
    72  package pprof
    73  
    74  import (
    75  	"bufio"
    76  	"bytes"
    77  	"fmt"
    78  	"io"
    79  	"runtime"
    80  	"sort"
    81  	"strings"
    82  	"sync"
    83  	"text/tabwriter"
    84  	"time"
    85  	"unsafe"
    86  )
    87  
    88  // BUG(rsc): Profiles are only as good as the kernel support used to generate them.
    89  // See https://golang.org/issue/13841 for details about known problems.
    90  
    91  // A Profile is a collection of stack traces showing the call sequences
    92  // that led to instances of a particular event, such as allocation.
    93  // Packages can create and maintain their own profiles; the most common
    94  // use is for tracking resources that must be explicitly closed, such as files
    95  // or network connections.
    96  //
    97  // A Profile's methods can be called from multiple goroutines simultaneously.
    98  //
    99  // Each Profile has a unique name. A few profiles are predefined:
   100  //
   101  //	goroutine    - stack traces of all current goroutines
   102  //	heap         - a sampling of all heap allocations
   103  //	threadcreate - stack traces that led to the creation of new OS threads
   104  //	block        - stack traces that led to blocking on synchronization primitives
   105  //	mutex        - stack traces of holders of contended mutexes
   106  //
   107  // These predefined profiles maintain themselves and panic on an explicit
   108  // Add or Remove method call.
   109  //
   110  // The heap profile reports statistics as of the most recently completed
   111  // garbage collection; it elides more recent allocation to avoid skewing
   112  // the profile away from live data and toward garbage.
   113  // If there has been no garbage collection at all, the heap profile reports
   114  // all known allocations. This exception helps mainly in programs running
   115  // without garbage collection enabled, usually for debugging purposes.
   116  //
   117  // The CPU profile is not available as a Profile. It has a special API,
   118  // the StartCPUProfile and StopCPUProfile functions, because it streams
   119  // output to a writer during profiling.
   120  //
   121  type Profile struct {
   122  	name  string
   123  	mu    sync.Mutex
   124  	m     map[interface{}][]uintptr
   125  	count func() int
   126  	write func(io.Writer, int) error
   127  }
   128  
   129  // profiles records all registered profiles.
   130  var profiles struct {
   131  	mu sync.Mutex
   132  	m  map[string]*Profile
   133  }
   134  
   135  var goroutineProfile = &Profile{
   136  	name:  "goroutine",
   137  	count: countGoroutine,
   138  	write: writeGoroutine,
   139  }
   140  
   141  var threadcreateProfile = &Profile{
   142  	name:  "threadcreate",
   143  	count: countThreadCreate,
   144  	write: writeThreadCreate,
   145  }
   146  
   147  var heapProfile = &Profile{
   148  	name:  "heap",
   149  	count: countHeap,
   150  	write: writeHeap,
   151  }
   152  
   153  var blockProfile = &Profile{
   154  	name:  "block",
   155  	count: countBlock,
   156  	write: writeBlock,
   157  }
   158  
   159  var mutexProfile = &Profile{
   160  	name:  "mutex",
   161  	count: countMutex,
   162  	write: writeMutex,
   163  }
   164  
   165  func lockProfiles() {
   166  	profiles.mu.Lock()
   167  	if profiles.m == nil {
   168  		// Initial built-in profiles.
   169  		profiles.m = map[string]*Profile{
   170  			"goroutine":    goroutineProfile,
   171  			"threadcreate": threadcreateProfile,
   172  			"heap":         heapProfile,
   173  			"block":        blockProfile,
   174  			"mutex":        mutexProfile,
   175  		}
   176  	}
   177  }
   178  
   179  func unlockProfiles() {
   180  	profiles.mu.Unlock()
   181  }
   182  
   183  // NewProfile creates a new profile with the given name.
   184  // If a profile with that name already exists, NewProfile panics.
   185  // The convention is to use a 'import/path.' prefix to create
   186  // separate name spaces for each package.
   187  // For compatibility with various tools that read pprof data,
   188  // profile names should not contain spaces.
   189  func NewProfile(name string) *Profile {
   190  	lockProfiles()
   191  	defer unlockProfiles()
   192  	if name == "" {
   193  		panic("pprof: NewProfile with empty name")
   194  	}
   195  	if profiles.m[name] != nil {
   196  		panic("pprof: NewProfile name already in use: " + name)
   197  	}
   198  	p := &Profile{
   199  		name: name,
   200  		m:    map[interface{}][]uintptr{},
   201  	}
   202  	profiles.m[name] = p
   203  	return p
   204  }
   205  
   206  // Lookup returns the profile with the given name, or nil if no such profile exists.
   207  func Lookup(name string) *Profile {
   208  	lockProfiles()
   209  	defer unlockProfiles()
   210  	return profiles.m[name]
   211  }
   212  
   213  // Profiles returns a slice of all the known profiles, sorted by name.
   214  func Profiles() []*Profile {
   215  	lockProfiles()
   216  	defer unlockProfiles()
   217  
   218  	all := make([]*Profile, 0, len(profiles.m))
   219  	for _, p := range profiles.m {
   220  		all = append(all, p)
   221  	}
   222  
   223  	sort.Slice(all, func(i, j int) bool { return all[i].name < all[j].name })
   224  	return all
   225  }
   226  
   227  // Name returns this profile's name, which can be passed to Lookup to reobtain the profile.
   228  func (p *Profile) Name() string {
   229  	return p.name
   230  }
   231  
   232  // Count returns the number of execution stacks currently in the profile.
   233  func (p *Profile) Count() int {
   234  	p.mu.Lock()
   235  	defer p.mu.Unlock()
   236  	if p.count != nil {
   237  		return p.count()
   238  	}
   239  	return len(p.m)
   240  }
   241  
   242  // Add adds the current execution stack to the profile, associated with value.
   243  // Add stores value in an internal map, so value must be suitable for use as
   244  // a map key and will not be garbage collected until the corresponding
   245  // call to Remove. Add panics if the profile already contains a stack for value.
   246  //
   247  // The skip parameter has the same meaning as runtime.Caller's skip
   248  // and controls where the stack trace begins. Passing skip=0 begins the
   249  // trace in the function calling Add. For example, given this
   250  // execution stack:
   251  //
   252  //	Add
   253  //	called from rpc.NewClient
   254  //	called from mypkg.Run
   255  //	called from main.main
   256  //
   257  // Passing skip=0 begins the stack trace at the call to Add inside rpc.NewClient.
   258  // Passing skip=1 begins the stack trace at the call to NewClient inside mypkg.Run.
   259  //
   260  func (p *Profile) Add(value interface{}, skip int) {
   261  	if p.name == "" {
   262  		panic("pprof: use of uninitialized Profile")
   263  	}
   264  	if p.write != nil {
   265  		panic("pprof: Add called on built-in Profile " + p.name)
   266  	}
   267  
   268  	stk := make([]uintptr, 32)
   269  	n := runtime.Callers(skip+1, stk[:])
   270  	stk = stk[:n]
   271  	if len(stk) == 0 {
   272  		// The value for skip is too large, and there's no stack trace to record.
   273  		stk = []uintptr{funcPC(lostProfileEvent)}
   274  	}
   275  
   276  	p.mu.Lock()
   277  	defer p.mu.Unlock()
   278  	if p.m[value] != nil {
   279  		panic("pprof: Profile.Add of duplicate value")
   280  	}
   281  	p.m[value] = stk
   282  }
   283  
   284  // Remove removes the execution stack associated with value from the profile.
   285  // It is a no-op if the value is not in the profile.
   286  func (p *Profile) Remove(value interface{}) {
   287  	p.mu.Lock()
   288  	defer p.mu.Unlock()
   289  	delete(p.m, value)
   290  }
   291  
   292  // WriteTo writes a pprof-formatted snapshot of the profile to w.
   293  // If a write to w returns an error, WriteTo returns that error.
   294  // Otherwise, WriteTo returns nil.
   295  //
   296  // The debug parameter enables additional output.
   297  // Passing debug=0 prints only the hexadecimal addresses that pprof needs.
   298  // Passing debug=1 adds comments translating addresses to function names
   299  // and line numbers, so that a programmer can read the profile without tools.
   300  //
   301  // The predefined profiles may assign meaning to other debug values;
   302  // for example, when printing the "goroutine" profile, debug=2 means to
   303  // print the goroutine stacks in the same form that a Go program uses
   304  // when dying due to an unrecovered panic.
   305  func (p *Profile) WriteTo(w io.Writer, debug int) error {
   306  	if p.name == "" {
   307  		panic("pprof: use of zero Profile")
   308  	}
   309  	if p.write != nil {
   310  		return p.write(w, debug)
   311  	}
   312  
   313  	// Obtain consistent snapshot under lock; then process without lock.
   314  	p.mu.Lock()
   315  	all := make([][]uintptr, 0, len(p.m))
   316  	for _, stk := range p.m {
   317  		all = append(all, stk)
   318  	}
   319  	p.mu.Unlock()
   320  
   321  	// Map order is non-deterministic; make output deterministic.
   322  	sort.Slice(all, func(i, j int) bool {
   323  		t, u := all[i], all[j]
   324  		for k := 0; k < len(t) && k < len(u); k++ {
   325  			if t[k] != u[k] {
   326  				return t[k] < u[k]
   327  			}
   328  		}
   329  		return len(t) < len(u)
   330  	})
   331  
   332  	return printCountProfile(w, debug, p.name, stackProfile(all))
   333  }
   334  
   335  type stackProfile [][]uintptr
   336  
   337  func (x stackProfile) Len() int              { return len(x) }
   338  func (x stackProfile) Stack(i int) []uintptr { return x[i] }
   339  
   340  // A countProfile is a set of stack traces to be printed as counts
   341  // grouped by stack trace. There are multiple implementations:
   342  // all that matters is that we can find out how many traces there are
   343  // and obtain each trace in turn.
   344  type countProfile interface {
   345  	Len() int
   346  	Stack(i int) []uintptr
   347  }
   348  
   349  // printCountCycleProfile outputs block profile records (for block or mutex profiles)
   350  // as the pprof-proto format output. Translations from cycle count to time duration
   351  // are done because The proto expects count and time (nanoseconds) instead of count
   352  // and the number of cycles for block, contention profiles.
   353  // Possible 'scaler' functions are scaleBlockProfile and scaleMutexProfile.
   354  func printCountCycleProfile(w io.Writer, countName, cycleName string, scaler func(int64, float64) (int64, float64), records []runtime.BlockProfileRecord) error {
   355  	// Output profile in protobuf form.
   356  	b := newProfileBuilder(w)
   357  	b.pbValueType(tagProfile_PeriodType, countName, "count")
   358  	b.pb.int64Opt(tagProfile_Period, 1)
   359  	b.pbValueType(tagProfile_SampleType, countName, "count")
   360  	b.pbValueType(tagProfile_SampleType, cycleName, "nanoseconds")
   361  
   362  	cpuGHz := float64(runtime_cyclesPerSecond()) / 1e9
   363  
   364  	values := []int64{0, 0}
   365  	var locs []uint64
   366  	for _, r := range records {
   367  		count, nanosec := scaler(r.Count, float64(r.Cycles)/cpuGHz)
   368  		values[0] = count
   369  		values[1] = int64(nanosec)
   370  		locs = locs[:0]
   371  		for _, addr := range r.Stack() {
   372  			// For count profiles, all stack addresses are
   373  			// return PCs, which is what locForPC expects.
   374  			l := b.locForPC(addr)
   375  			if l == 0 { // runtime.goexit
   376  				continue
   377  			}
   378  			locs = append(locs, l)
   379  		}
   380  		b.pbSample(values, locs, nil)
   381  	}
   382  	b.build()
   383  	return nil
   384  }
   385  
   386  // printCountProfile prints a countProfile at the specified debug level.
   387  // The profile will be in compressed proto format unless debug is nonzero.
   388  func printCountProfile(w io.Writer, debug int, name string, p countProfile) error {
   389  	// Build count of each stack.
   390  	var buf bytes.Buffer
   391  	key := func(stk []uintptr) string {
   392  		buf.Reset()
   393  		fmt.Fprintf(&buf, "@")
   394  		for _, pc := range stk {
   395  			fmt.Fprintf(&buf, " %#x", pc)
   396  		}
   397  		return buf.String()
   398  	}
   399  	count := map[string]int{}
   400  	index := map[string]int{}
   401  	var keys []string
   402  	n := p.Len()
   403  	for i := 0; i < n; i++ {
   404  		k := key(p.Stack(i))
   405  		if count[k] == 0 {
   406  			index[k] = i
   407  			keys = append(keys, k)
   408  		}
   409  		count[k]++
   410  	}
   411  
   412  	sort.Sort(&keysByCount{keys, count})
   413  
   414  	if debug > 0 {
   415  		// Print debug profile in legacy format
   416  		tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0)
   417  		fmt.Fprintf(tw, "%s profile: total %d\n", name, p.Len())
   418  		for _, k := range keys {
   419  			fmt.Fprintf(tw, "%d %s\n", count[k], k)
   420  			printStackRecord(tw, p.Stack(index[k]), false)
   421  		}
   422  		return tw.Flush()
   423  	}
   424  
   425  	// Output profile in protobuf form.
   426  	b := newProfileBuilder(w)
   427  	b.pbValueType(tagProfile_PeriodType, name, "count")
   428  	b.pb.int64Opt(tagProfile_Period, 1)
   429  	b.pbValueType(tagProfile_SampleType, name, "count")
   430  
   431  	values := []int64{0}
   432  	var locs []uint64
   433  	for _, k := range keys {
   434  		values[0] = int64(count[k])
   435  		locs = locs[:0]
   436  		for _, addr := range p.Stack(index[k]) {
   437  			// For count profiles, all stack addresses are
   438  			// return PCs, which is what locForPC expects.
   439  			l := b.locForPC(addr)
   440  			if l == 0 { // runtime.goexit
   441  				continue
   442  			}
   443  			locs = append(locs, l)
   444  		}
   445  		b.pbSample(values, locs, nil)
   446  	}
   447  	b.build()
   448  	return nil
   449  }
   450  
   451  // keysByCount sorts keys with higher counts first, breaking ties by key string order.
   452  type keysByCount struct {
   453  	keys  []string
   454  	count map[string]int
   455  }
   456  
   457  func (x *keysByCount) Len() int      { return len(x.keys) }
   458  func (x *keysByCount) Swap(i, j int) { x.keys[i], x.keys[j] = x.keys[j], x.keys[i] }
   459  func (x *keysByCount) Less(i, j int) bool {
   460  	ki, kj := x.keys[i], x.keys[j]
   461  	ci, cj := x.count[ki], x.count[kj]
   462  	if ci != cj {
   463  		return ci > cj
   464  	}
   465  	return ki < kj
   466  }
   467  
   468  // printStackRecord prints the function + source line information
   469  // for a single stack trace.
   470  func printStackRecord(w io.Writer, stk []uintptr, allFrames bool) {
   471  	show := allFrames
   472  	frames := runtime.CallersFrames(stk)
   473  	for {
   474  		frame, more := frames.Next()
   475  		name := frame.Function
   476  		if name == "" {
   477  			show = true
   478  			fmt.Fprintf(w, "#\t%#x\n", frame.PC)
   479  		} else if name != "runtime.goexit" && (show || !strings.HasPrefix(name, "runtime.")) {
   480  			// Hide runtime.goexit and any runtime functions at the beginning.
   481  			// This is useful mainly for allocation traces.
   482  			show = true
   483  			fmt.Fprintf(w, "#\t%#x\t%s+%#x\t%s:%d\n", frame.PC, name, frame.PC-frame.Entry, frame.File, frame.Line)
   484  		}
   485  		if !more {
   486  			break
   487  		}
   488  	}
   489  	if !show {
   490  		// We didn't print anything; do it again,
   491  		// and this time include runtime functions.
   492  		printStackRecord(w, stk, true)
   493  		return
   494  	}
   495  	fmt.Fprintf(w, "\n")
   496  }
   497  
   498  // Interface to system profiles.
   499  
   500  // WriteHeapProfile is shorthand for Lookup("heap").WriteTo(w, 0).
   501  // It is preserved for backwards compatibility.
   502  func WriteHeapProfile(w io.Writer) error {
   503  	return writeHeap(w, 0)
   504  }
   505  
   506  // countHeap returns the number of records in the heap profile.
   507  func countHeap() int {
   508  	n, _ := runtime.MemProfile(nil, true)
   509  	return n
   510  }
   511  
   512  // writeHeap writes the current runtime heap profile to w.
   513  func writeHeap(w io.Writer, debug int) error {
   514  	var memStats *runtime.MemStats
   515  	if debug != 0 {
   516  		// Read mem stats first, so that our other allocations
   517  		// do not appear in the statistics.
   518  		memStats = new(runtime.MemStats)
   519  		runtime.ReadMemStats(memStats)
   520  	}
   521  
   522  	// Find out how many records there are (MemProfile(nil, true)),
   523  	// allocate that many records, and get the data.
   524  	// There's a race—more records might be added between
   525  	// the two calls—so allocate a few extra records for safety
   526  	// and also try again if we're very unlucky.
   527  	// The loop should only execute one iteration in the common case.
   528  	var p []runtime.MemProfileRecord
   529  	n, ok := runtime.MemProfile(nil, true)
   530  	for {
   531  		// Allocate room for a slightly bigger profile,
   532  		// in case a few more entries have been added
   533  		// since the call to MemProfile.
   534  		p = make([]runtime.MemProfileRecord, n+50)
   535  		n, ok = runtime.MemProfile(p, true)
   536  		if ok {
   537  			p = p[0:n]
   538  			break
   539  		}
   540  		// Profile grew; try again.
   541  	}
   542  
   543  	if debug == 0 {
   544  		return writeHeapProto(w, p, int64(runtime.MemProfileRate))
   545  	}
   546  
   547  	sort.Slice(p, func(i, j int) bool { return p[i].InUseBytes() > p[j].InUseBytes() })
   548  
   549  	b := bufio.NewWriter(w)
   550  	tw := tabwriter.NewWriter(b, 1, 8, 1, '\t', 0)
   551  	w = tw
   552  
   553  	var total runtime.MemProfileRecord
   554  	for i := range p {
   555  		r := &p[i]
   556  		total.AllocBytes += r.AllocBytes
   557  		total.AllocObjects += r.AllocObjects
   558  		total.FreeBytes += r.FreeBytes
   559  		total.FreeObjects += r.FreeObjects
   560  	}
   561  
   562  	// Technically the rate is MemProfileRate not 2*MemProfileRate,
   563  	// but early versions of the C++ heap profiler reported 2*MemProfileRate,
   564  	// so that's what pprof has come to expect.
   565  	fmt.Fprintf(w, "heap profile: %d: %d [%d: %d] @ heap/%d\n",
   566  		total.InUseObjects(), total.InUseBytes(),
   567  		total.AllocObjects, total.AllocBytes,
   568  		2*runtime.MemProfileRate)
   569  
   570  	for i := range p {
   571  		r := &p[i]
   572  		fmt.Fprintf(w, "%d: %d [%d: %d] @",
   573  			r.InUseObjects(), r.InUseBytes(),
   574  			r.AllocObjects, r.AllocBytes)
   575  		for _, pc := range r.Stack() {
   576  			fmt.Fprintf(w, " %#x", pc)
   577  		}
   578  		fmt.Fprintf(w, "\n")
   579  		printStackRecord(w, r.Stack(), false)
   580  	}
   581  
   582  	// Print memstats information too.
   583  	// Pprof will ignore, but useful for people
   584  	s := memStats
   585  	fmt.Fprintf(w, "\n# runtime.MemStats\n")
   586  	fmt.Fprintf(w, "# Alloc = %d\n", s.Alloc)
   587  	fmt.Fprintf(w, "# TotalAlloc = %d\n", s.TotalAlloc)
   588  	fmt.Fprintf(w, "# Sys = %d\n", s.Sys)
   589  	fmt.Fprintf(w, "# Lookups = %d\n", s.Lookups)
   590  	fmt.Fprintf(w, "# Mallocs = %d\n", s.Mallocs)
   591  	fmt.Fprintf(w, "# Frees = %d\n", s.Frees)
   592  
   593  	fmt.Fprintf(w, "# HeapAlloc = %d\n", s.HeapAlloc)
   594  	fmt.Fprintf(w, "# HeapSys = %d\n", s.HeapSys)
   595  	fmt.Fprintf(w, "# HeapIdle = %d\n", s.HeapIdle)
   596  	fmt.Fprintf(w, "# HeapInuse = %d\n", s.HeapInuse)
   597  	fmt.Fprintf(w, "# HeapReleased = %d\n", s.HeapReleased)
   598  	fmt.Fprintf(w, "# HeapObjects = %d\n", s.HeapObjects)
   599  
   600  	fmt.Fprintf(w, "# Stack = %d / %d\n", s.StackInuse, s.StackSys)
   601  	fmt.Fprintf(w, "# MSpan = %d / %d\n", s.MSpanInuse, s.MSpanSys)
   602  	fmt.Fprintf(w, "# MCache = %d / %d\n", s.MCacheInuse, s.MCacheSys)
   603  	fmt.Fprintf(w, "# BuckHashSys = %d\n", s.BuckHashSys)
   604  	fmt.Fprintf(w, "# GCSys = %d\n", s.GCSys)
   605  	fmt.Fprintf(w, "# OtherSys = %d\n", s.OtherSys)
   606  
   607  	fmt.Fprintf(w, "# NextGC = %d\n", s.NextGC)
   608  	fmt.Fprintf(w, "# LastGC = %d\n", s.LastGC)
   609  	fmt.Fprintf(w, "# PauseNs = %d\n", s.PauseNs)
   610  	fmt.Fprintf(w, "# PauseEnd = %d\n", s.PauseEnd)
   611  	fmt.Fprintf(w, "# NumGC = %d\n", s.NumGC)
   612  	fmt.Fprintf(w, "# NumForcedGC = %d\n", s.NumForcedGC)
   613  	fmt.Fprintf(w, "# GCCPUFraction = %v\n", s.GCCPUFraction)
   614  	fmt.Fprintf(w, "# DebugGC = %v\n", s.DebugGC)
   615  
   616  	tw.Flush()
   617  	return b.Flush()
   618  }
   619  
   620  // countThreadCreate returns the size of the current ThreadCreateProfile.
   621  func countThreadCreate() int {
   622  	n, _ := runtime.ThreadCreateProfile(nil)
   623  	return n
   624  }
   625  
   626  // writeThreadCreate writes the current runtime ThreadCreateProfile to w.
   627  func writeThreadCreate(w io.Writer, debug int) error {
   628  	return writeRuntimeProfile(w, debug, "threadcreate", runtime.ThreadCreateProfile)
   629  }
   630  
   631  // countGoroutine returns the number of goroutines.
   632  func countGoroutine() int {
   633  	return runtime.NumGoroutine()
   634  }
   635  
   636  // writeGoroutine writes the current runtime GoroutineProfile to w.
   637  func writeGoroutine(w io.Writer, debug int) error {
   638  	if debug >= 2 {
   639  		return writeGoroutineStacks(w)
   640  	}
   641  	return writeRuntimeProfile(w, debug, "goroutine", runtime.GoroutineProfile)
   642  }
   643  
   644  func writeGoroutineStacks(w io.Writer) error {
   645  	// We don't know how big the buffer needs to be to collect
   646  	// all the goroutines. Start with 1 MB and try a few times, doubling each time.
   647  	// Give up and use a truncated trace if 64 MB is not enough.
   648  	buf := make([]byte, 1<<20)
   649  	for i := 0; ; i++ {
   650  		n := runtime.Stack(buf, true)
   651  		if n < len(buf) {
   652  			buf = buf[:n]
   653  			break
   654  		}
   655  		if len(buf) >= 64<<20 {
   656  			// Filled 64 MB - stop there.
   657  			break
   658  		}
   659  		buf = make([]byte, 2*len(buf))
   660  	}
   661  	_, err := w.Write(buf)
   662  	return err
   663  }
   664  
   665  func writeRuntimeProfile(w io.Writer, debug int, name string, fetch func([]runtime.StackRecord) (int, bool)) error {
   666  	// Find out how many records there are (fetch(nil)),
   667  	// allocate that many records, and get the data.
   668  	// There's a race—more records might be added between
   669  	// the two calls—so allocate a few extra records for safety
   670  	// and also try again if we're very unlucky.
   671  	// The loop should only execute one iteration in the common case.
   672  	var p []runtime.StackRecord
   673  	n, ok := fetch(nil)
   674  	for {
   675  		// Allocate room for a slightly bigger profile,
   676  		// in case a few more entries have been added
   677  		// since the call to ThreadProfile.
   678  		p = make([]runtime.StackRecord, n+10)
   679  		n, ok = fetch(p)
   680  		if ok {
   681  			p = p[0:n]
   682  			break
   683  		}
   684  		// Profile grew; try again.
   685  	}
   686  
   687  	return printCountProfile(w, debug, name, runtimeProfile(p))
   688  }
   689  
   690  type runtimeProfile []runtime.StackRecord
   691  
   692  func (p runtimeProfile) Len() int              { return len(p) }
   693  func (p runtimeProfile) Stack(i int) []uintptr { return p[i].Stack() }
   694  
   695  var cpu struct {
   696  	sync.Mutex
   697  	profiling bool
   698  	done      chan bool
   699  }
   700  
   701  // StartCPUProfile enables CPU profiling for the current process.
   702  // While profiling, the profile will be buffered and written to w.
   703  // StartCPUProfile returns an error if profiling is already enabled.
   704  //
   705  // On Unix-like systems, StartCPUProfile does not work by default for
   706  // Go code built with -buildmode=c-archive or -buildmode=c-shared.
   707  // StartCPUProfile relies on the SIGPROF signal, but that signal will
   708  // be delivered to the main program's SIGPROF signal handler (if any)
   709  // not to the one used by Go. To make it work, call os/signal.Notify
   710  // for syscall.SIGPROF, but note that doing so may break any profiling
   711  // being done by the main program.
   712  func StartCPUProfile(w io.Writer) error {
   713  	// The runtime routines allow a variable profiling rate,
   714  	// but in practice operating systems cannot trigger signals
   715  	// at more than about 500 Hz, and our processing of the
   716  	// signal is not cheap (mostly getting the stack trace).
   717  	// 100 Hz is a reasonable choice: it is frequent enough to
   718  	// produce useful data, rare enough not to bog down the
   719  	// system, and a nice round number to make it easy to
   720  	// convert sample counts to seconds. Instead of requiring
   721  	// each client to specify the frequency, we hard code it.
   722  	const hz = 100
   723  
   724  	cpu.Lock()
   725  	defer cpu.Unlock()
   726  	if cpu.done == nil {
   727  		cpu.done = make(chan bool)
   728  	}
   729  	// Double-check.
   730  	if cpu.profiling {
   731  		return fmt.Errorf("cpu profiling already in use")
   732  	}
   733  	cpu.profiling = true
   734  	runtime.SetCPUProfileRate(hz)
   735  	go profileWriter(w)
   736  	return nil
   737  }
   738  
   739  // readProfile, provided by the runtime, returns the next chunk of
   740  // binary CPU profiling stack trace data, blocking until data is available.
   741  // If profiling is turned off and all the profile data accumulated while it was
   742  // on has been returned, readProfile returns eof=true.
   743  // The caller must save the returned data and tags before calling readProfile again.
   744  func readProfile() (data []uint64, tags []unsafe.Pointer, eof bool)
   745  
   746  func profileWriter(w io.Writer) {
   747  	b := newProfileBuilder(w)
   748  	var err error
   749  	for {
   750  		time.Sleep(100 * time.Millisecond)
   751  		data, tags, eof := readProfile()
   752  		if e := b.addCPUData(data, tags); e != nil && err == nil {
   753  			err = e
   754  		}
   755  		if eof {
   756  			break
   757  		}
   758  	}
   759  	if err != nil {
   760  		// The runtime should never produce an invalid or truncated profile.
   761  		// It drops records that can't fit into its log buffers.
   762  		panic("runtime/pprof: converting profile: " + err.Error())
   763  	}
   764  	b.build()
   765  	cpu.done <- true
   766  }
   767  
   768  // StopCPUProfile stops the current CPU profile, if any.
   769  // StopCPUProfile only returns after all the writes for the
   770  // profile have completed.
   771  func StopCPUProfile() {
   772  	cpu.Lock()
   773  	defer cpu.Unlock()
   774  
   775  	if !cpu.profiling {
   776  		return
   777  	}
   778  	cpu.profiling = false
   779  	runtime.SetCPUProfileRate(0)
   780  	<-cpu.done
   781  }
   782  
   783  // countBlock returns the number of records in the blocking profile.
   784  func countBlock() int {
   785  	n, _ := runtime.BlockProfile(nil)
   786  	return n
   787  }
   788  
   789  // countMutex returns the number of records in the mutex profile.
   790  func countMutex() int {
   791  	n, _ := runtime.MutexProfile(nil)
   792  	return n
   793  }
   794  
   795  // writeBlock writes the current blocking profile to w.
   796  func writeBlock(w io.Writer, debug int) error {
   797  	var p []runtime.BlockProfileRecord
   798  	n, ok := runtime.BlockProfile(nil)
   799  	for {
   800  		p = make([]runtime.BlockProfileRecord, n+50)
   801  		n, ok = runtime.BlockProfile(p)
   802  		if ok {
   803  			p = p[:n]
   804  			break
   805  		}
   806  	}
   807  
   808  	sort.Slice(p, func(i, j int) bool { return p[i].Cycles > p[j].Cycles })
   809  
   810  	if debug <= 0 {
   811  		return printCountCycleProfile(w, "contentions", "delay", scaleBlockProfile, p)
   812  	}
   813  
   814  	b := bufio.NewWriter(w)
   815  	tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0)
   816  	w = tw
   817  
   818  	fmt.Fprintf(w, "--- contention:\n")
   819  	fmt.Fprintf(w, "cycles/second=%v\n", runtime_cyclesPerSecond())
   820  	for i := range p {
   821  		r := &p[i]
   822  		fmt.Fprintf(w, "%v %v @", r.Cycles, r.Count)
   823  		for _, pc := range r.Stack() {
   824  			fmt.Fprintf(w, " %#x", pc)
   825  		}
   826  		fmt.Fprint(w, "\n")
   827  		if debug > 0 {
   828  			printStackRecord(w, r.Stack(), true)
   829  		}
   830  	}
   831  
   832  	if tw != nil {
   833  		tw.Flush()
   834  	}
   835  	return b.Flush()
   836  }
   837  
   838  func scaleBlockProfile(cnt int64, ns float64) (int64, float64) {
   839  	// Do nothing.
   840  	// The current way of block profile sampling makes it
   841  	// hard to compute the unsampled number. The legacy block
   842  	// profile parse doesn't attempt to scale or unsample.
   843  	return cnt, ns
   844  }
   845  
   846  // writeMutex writes the current mutex profile to w.
   847  func writeMutex(w io.Writer, debug int) error {
   848  	// TODO(pjw): too much common code with writeBlock. FIX!
   849  	var p []runtime.BlockProfileRecord
   850  	n, ok := runtime.MutexProfile(nil)
   851  	for {
   852  		p = make([]runtime.BlockProfileRecord, n+50)
   853  		n, ok = runtime.MutexProfile(p)
   854  		if ok {
   855  			p = p[:n]
   856  			break
   857  		}
   858  	}
   859  
   860  	sort.Slice(p, func(i, j int) bool { return p[i].Cycles > p[j].Cycles })
   861  
   862  	if debug <= 0 {
   863  		return printCountCycleProfile(w, "contentions", "delay", scaleMutexProfile, p)
   864  	}
   865  
   866  	b := bufio.NewWriter(w)
   867  	tw := tabwriter.NewWriter(w, 1, 8, 1, '\t', 0)
   868  	w = tw
   869  
   870  	fmt.Fprintf(w, "--- mutex:\n")
   871  	fmt.Fprintf(w, "cycles/second=%v\n", runtime_cyclesPerSecond())
   872  	fmt.Fprintf(w, "sampling period=%d\n", runtime.SetMutexProfileFraction(-1))
   873  	for i := range p {
   874  		r := &p[i]
   875  		fmt.Fprintf(w, "%v %v @", r.Cycles, r.Count)
   876  		for _, pc := range r.Stack() {
   877  			fmt.Fprintf(w, " %#x", pc)
   878  		}
   879  		fmt.Fprint(w, "\n")
   880  		if debug > 0 {
   881  			printStackRecord(w, r.Stack(), true)
   882  		}
   883  	}
   884  
   885  	if tw != nil {
   886  		tw.Flush()
   887  	}
   888  	return b.Flush()
   889  }
   890  
   891  func scaleMutexProfile(cnt int64, ns float64) (int64, float64) {
   892  	period := runtime.SetMutexProfileFraction(-1)
   893  	return cnt * int64(period), ns * float64(period)
   894  }
   895  
   896  func runtime_cyclesPerSecond() int64
   897
View as plain text