...

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

View as plain text