pprof.go

     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 serves via its HTTP server runtime profiling data
     6  // in the format expected by the pprof visualization tool.
     7  //
     8  // The package is typically only imported for the side effect of
     9  // registering its HTTP handlers.
    10  // The handled paths all begin with /debug/pprof/.
    11  //
    12  // To use pprof, link this package into your program:
    13  //	import _ "net/http/pprof"
    14  //
    15  // If your application is not already running an http server, you
    16  // need to start one. Add "net/http" and "log" to your imports and
    17  // the following code to your main function:
    18  //
    19  // 	go func() {
    20  // 		log.Println(http.ListenAndServe("localhost:6060", nil))
    21  // 	}()
    22  //
    23  // If you are not using DefaultServeMux, you will have to register handlers
    24  // with the mux you are using.
    25  //
    26  // Then use the pprof tool to look at the heap profile:
    27  //
    28  //	go tool pprof http://localhost:6060/debug/pprof/heap
    29  //
    30  // Or to look at a 30-second CPU profile:
    31  //
    32  //	go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
    33  //
    34  // Or to look at the goroutine blocking profile, after calling
    35  // runtime.SetBlockProfileRate in your program:
    36  //
    37  //	go tool pprof http://localhost:6060/debug/pprof/block
    38  //
    39  // Or to look at the holders of contended mutexes, after calling
    40  // runtime.SetMutexProfileFraction in your program:
    41  //
    42  //	go tool pprof http://localhost:6060/debug/pprof/mutex
    43  //
    44  // The package also exports a handler that serves execution trace data
    45  // for the "go tool trace" command. To collect a 5-second execution trace:
    46  //
    47  //	curl -o trace.out http://localhost:6060/debug/pprof/trace?seconds=5
    48  //	go tool trace trace.out
    49  //
    50  // To view all available profiles, open http://localhost:6060/debug/pprof/
    51  // in your browser.
    52  //
    53  // For a study of the facility in action, visit
    54  //
    55  //	https://blog.golang.org/2011/06/profiling-go-programs.html
    56  //
    57  package pprof
    58  
    59  import (
    60  	"bufio"
    61  	"bytes"
    62  	"context"
    63  	"fmt"
    64  	"html"
    65  	"internal/profile"
    66  	"io"
    67  	"log"
    68  	"net/http"
    69  	"net/url"
    70  	"os"
    71  	"runtime"
    72  	"runtime/pprof"
    73  	"runtime/trace"
    74  	"sort"
    75  	"strconv"
    76  	"strings"
    77  	"time"
    78  )
    79  
    80  func init() {
    81  	http.HandleFunc("/debug/pprof/", Index)
    82  	http.HandleFunc("/debug/pprof/cmdline", Cmdline)
    83  	http.HandleFunc("/debug/pprof/profile", Profile)
    84  	http.HandleFunc("/debug/pprof/symbol", Symbol)
    85  	http.HandleFunc("/debug/pprof/trace", Trace)
    86  }
    87  
    88  // Cmdline responds with the running program's
    89  // command line, with arguments separated by NUL bytes.
    90  // The package initialization registers it as /debug/pprof/cmdline.
    91  func Cmdline(w http.ResponseWriter, r *http.Request) {
    92  	w.Header().Set("X-Content-Type-Options", "nosniff")
    93  	w.Header().Set("Content-Type", "text/plain; charset=utf-8")
    94  	fmt.Fprint(w, strings.Join(os.Args, "\x00"))
    95  }
    96  
    97  func sleep(r *http.Request, d time.Duration) {
    98  	select {
    99  	case <-time.After(d):
   100  	case <-r.Context().Done():
   101  	}
   102  }
   103  
   104  func durationExceedsWriteTimeout(r *http.Request, seconds float64) bool {
   105  	srv, ok := r.Context().Value(http.ServerContextKey).(*http.Server)
   106  	return ok && srv.WriteTimeout != 0 && seconds >= srv.WriteTimeout.Seconds()
   107  }
   108  
   109  func serveError(w http.ResponseWriter, status int, txt string) {
   110  	w.Header().Set("Content-Type", "text/plain; charset=utf-8")
   111  	w.Header().Set("X-Go-Pprof", "1")
   112  	w.Header().Del("Content-Disposition")
   113  	w.WriteHeader(status)
   114  	fmt.Fprintln(w, txt)
   115  }
   116  
   117  // Profile responds with the pprof-formatted cpu profile.
   118  // Profiling lasts for duration specified in seconds GET parameter, or for 30 seconds if not specified.
   119  // The package initialization registers it as /debug/pprof/profile.
   120  func Profile(w http.ResponseWriter, r *http.Request) {
   121  	w.Header().Set("X-Content-Type-Options", "nosniff")
   122  	sec, err := strconv.ParseInt(r.FormValue("seconds"), 10, 64)
   123  	if sec <= 0 || err != nil {
   124  		sec = 30
   125  	}
   126  
   127  	if durationExceedsWriteTimeout(r, float64(sec)) {
   128  		serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout")
   129  		return
   130  	}
   131  
   132  	// Set Content Type assuming StartCPUProfile will work,
   133  	// because if it does it starts writing.
   134  	w.Header().Set("Content-Type", "application/octet-stream")
   135  	w.Header().Set("Content-Disposition", `attachment; filename="profile"`)
   136  	if err := pprof.StartCPUProfile(w); err != nil {
   137  		// StartCPUProfile failed, so no writes yet.
   138  		serveError(w, http.StatusInternalServerError,
   139  			fmt.Sprintf("Could not enable CPU profiling: %s", err))
   140  		return
   141  	}
   142  	sleep(r, time.Duration(sec)*time.Second)
   143  	pprof.StopCPUProfile()
   144  }
   145  
   146  // Trace responds with the execution trace in binary form.
   147  // Tracing lasts for duration specified in seconds GET parameter, or for 1 second if not specified.
   148  // The package initialization registers it as /debug/pprof/trace.
   149  func Trace(w http.ResponseWriter, r *http.Request) {
   150  	w.Header().Set("X-Content-Type-Options", "nosniff")
   151  	sec, err := strconv.ParseFloat(r.FormValue("seconds"), 64)
   152  	if sec <= 0 || err != nil {
   153  		sec = 1
   154  	}
   155  
   156  	if durationExceedsWriteTimeout(r, sec) {
   157  		serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout")
   158  		return
   159  	}
   160  
   161  	// Set Content Type assuming trace.Start will work,
   162  	// because if it does it starts writing.
   163  	w.Header().Set("Content-Type", "application/octet-stream")
   164  	w.Header().Set("Content-Disposition", `attachment; filename="trace"`)
   165  	if err := trace.Start(w); err != nil {
   166  		// trace.Start failed, so no writes yet.
   167  		serveError(w, http.StatusInternalServerError,
   168  			fmt.Sprintf("Could not enable tracing: %s", err))
   169  		return
   170  	}
   171  	sleep(r, time.Duration(sec*float64(time.Second)))
   172  	trace.Stop()
   173  }
   174  
   175  // Symbol looks up the program counters listed in the request,
   176  // responding with a table mapping program counters to function names.
   177  // The package initialization registers it as /debug/pprof/symbol.
   178  func Symbol(w http.ResponseWriter, r *http.Request) {
   179  	w.Header().Set("X-Content-Type-Options", "nosniff")
   180  	w.Header().Set("Content-Type", "text/plain; charset=utf-8")
   181  
   182  	// We have to read the whole POST body before
   183  	// writing any output. Buffer the output here.
   184  	var buf bytes.Buffer
   185  
   186  	// We don't know how many symbols we have, but we
   187  	// do have symbol information. Pprof only cares whether
   188  	// this number is 0 (no symbols available) or > 0.
   189  	fmt.Fprintf(&buf, "num_symbols: 1\n")
   190  
   191  	var b *bufio.Reader
   192  	if r.Method == "POST" {
   193  		b = bufio.NewReader(r.Body)
   194  	} else {
   195  		b = bufio.NewReader(strings.NewReader(r.URL.RawQuery))
   196  	}
   197  
   198  	for {
   199  		word, err := b.ReadSlice('+')
   200  		if err == nil {
   201  			word = word[0 : len(word)-1] // trim +
   202  		}
   203  		pc, _ := strconv.ParseUint(string(word), 0, 64)
   204  		if pc != 0 {
   205  			f := runtime.FuncForPC(uintptr(pc))
   206  			if f != nil {
   207  				fmt.Fprintf(&buf, "%#x %s\n", pc, f.Name())
   208  			}
   209  		}
   210  
   211  		// Wait until here to check for err; the last
   212  		// symbol will have an err because it doesn't end in +.
   213  		if err != nil {
   214  			if err != io.EOF {
   215  				fmt.Fprintf(&buf, "reading request: %v\n", err)
   216  			}
   217  			break
   218  		}
   219  	}
   220  
   221  	w.Write(buf.Bytes())
   222  }
   223  
   224  // Handler returns an HTTP handler that serves the named profile.
   225  func Handler(name string) http.Handler {
   226  	return handler(name)
   227  }
   228  
   229  type handler string
   230  
   231  func (name handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
   232  	w.Header().Set("X-Content-Type-Options", "nosniff")
   233  	p := pprof.Lookup(string(name))
   234  	if p == nil {
   235  		serveError(w, http.StatusNotFound, "Unknown profile")
   236  		return
   237  	}
   238  	if sec := r.FormValue("seconds"); sec != "" {
   239  		name.serveDeltaProfile(w, r, p, sec)
   240  		return
   241  	}
   242  	gc, _ := strconv.Atoi(r.FormValue("gc"))
   243  	if name == "heap" && gc > 0 {
   244  		runtime.GC()
   245  	}
   246  	debug, _ := strconv.Atoi(r.FormValue("debug"))
   247  	if debug != 0 {
   248  		w.Header().Set("Content-Type", "text/plain; charset=utf-8")
   249  	} else {
   250  		w.Header().Set("Content-Type", "application/octet-stream")
   251  		w.Header().Set("Content-Disposition", fmt.Sprintf(`attachment; filename="%s"`, name))
   252  	}
   253  	p.WriteTo(w, debug)
   254  }
   255  
   256  func (name handler) serveDeltaProfile(w http.ResponseWriter, r *http.Request, p *pprof.Profile, secStr string) {
   257  	sec, err := strconv.ParseInt(secStr, 10, 64)
   258  	if err != nil || sec <= 0 {
   259  		serveError(w, http.StatusBadRequest, `invalid value for "seconds" - must be a positive integer`)
   260  		return
   261  	}
   262  	if !profileSupportsDelta[name] {
   263  		serveError(w, http.StatusBadRequest, `"seconds" parameter is not supported for this profile type`)
   264  		return
   265  	}
   266  	// 'name' should be a key in profileSupportsDelta.
   267  	if durationExceedsWriteTimeout(r, float64(sec)) {
   268  		serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout")
   269  		return
   270  	}
   271  	debug, _ := strconv.Atoi(r.FormValue("debug"))
   272  	if debug != 0 {
   273  		serveError(w, http.StatusBadRequest, "seconds and debug params are incompatible")
   274  		return
   275  	}
   276  	p0, err := collectProfile(p)
   277  	if err != nil {
   278  		serveError(w, http.StatusInternalServerError, "failed to collect profile")
   279  		return
   280  	}
   281  
   282  	t := time.NewTimer(time.Duration(sec) * time.Second)
   283  	defer t.Stop()
   284  
   285  	select {
   286  	case <-r.Context().Done():
   287  		err := r.Context().Err()
   288  		if err == context.DeadlineExceeded {
   289  			serveError(w, http.StatusRequestTimeout, err.Error())
   290  		} else { // TODO: what's a good status code for canceled requests? 400?
   291  			serveError(w, http.StatusInternalServerError, err.Error())
   292  		}
   293  		return
   294  	case <-t.C:
   295  	}
   296  
   297  	p1, err := collectProfile(p)
   298  	if err != nil {
   299  		serveError(w, http.StatusInternalServerError, "failed to collect profile")
   300  		return
   301  	}
   302  	ts := p1.TimeNanos
   303  	dur := p1.TimeNanos - p0.TimeNanos
   304  
   305  	p0.Scale(-1)
   306  
   307  	p1, err = profile.Merge([]*profile.Profile{p0, p1})
   308  	if err != nil {
   309  		serveError(w, http.StatusInternalServerError, "failed to compute delta")
   310  		return
   311  	}
   312  
   313  	p1.TimeNanos = ts // set since we don't know what profile.Merge set for TimeNanos.
   314  	p1.DurationNanos = dur
   315  
   316  	w.Header().Set("Content-Type", "application/octet-stream")
   317  	w.Header().Set("Content-Disposition", fmt.Sprintf(`attachment; filename="%s-delta"`, name))
   318  	p1.Write(w)
   319  }
   320  
   321  func collectProfile(p *pprof.Profile) (*profile.Profile, error) {
   322  	var buf bytes.Buffer
   323  	if err := p.WriteTo(&buf, 0); err != nil {
   324  		return nil, err
   325  	}
   326  	ts := time.Now().UnixNano()
   327  	p0, err := profile.Parse(&buf)
   328  	if err != nil {
   329  		return nil, err
   330  	}
   331  	p0.TimeNanos = ts
   332  	return p0, nil
   333  }
   334  
   335  var profileSupportsDelta = map[handler]bool{
   336  	"allocs":       true,
   337  	"block":        true,
   338  	"goroutine":    true,
   339  	"heap":         true,
   340  	"mutex":        true,
   341  	"threadcreate": true,
   342  }
   343  
   344  var profileDescriptions = map[string]string{
   345  	"allocs":       "A sampling of all past memory allocations",
   346  	"block":        "Stack traces that led to blocking on synchronization primitives",
   347  	"cmdline":      "The command line invocation of the current program",
   348  	"goroutine":    "Stack traces of all current goroutines",
   349  	"heap":         "A sampling of memory allocations of live objects. You can specify the gc GET parameter to run GC before taking the heap sample.",
   350  	"mutex":        "Stack traces of holders of contended mutexes",
   351  	"profile":      "CPU profile. You can specify the duration in the seconds GET parameter. After you get the profile file, use the go tool pprof command to investigate the profile.",
   352  	"threadcreate": "Stack traces that led to the creation of new OS threads",
   353  	"trace":        "A trace of execution of the current program. You can specify the duration in the seconds GET parameter. After you get the trace file, use the go tool trace command to investigate the trace.",
   354  }
   355  
   356  type profileEntry struct {
   357  	Name  string
   358  	Href  string
   359  	Desc  string
   360  	Count int
   361  }
   362  
   363  // Index responds with the pprof-formatted profile named by the request.
   364  // For example, "/debug/pprof/heap" serves the "heap" profile.
   365  // Index responds to a request for "/debug/pprof/" with an HTML page
   366  // listing the available profiles.
   367  func Index(w http.ResponseWriter, r *http.Request) {
   368  	if strings.HasPrefix(r.URL.Path, "/debug/pprof/") {
   369  		name := strings.TrimPrefix(r.URL.Path, "/debug/pprof/")
   370  		if name != "" {
   371  			handler(name).ServeHTTP(w, r)
   372  			return
   373  		}
   374  	}
   375  
   376  	w.Header().Set("X-Content-Type-Options", "nosniff")
   377  	w.Header().Set("Content-Type", "text/html; charset=utf-8")
   378  
   379  	var profiles []profileEntry
   380  	for _, p := range pprof.Profiles() {
   381  		profiles = append(profiles, profileEntry{
   382  			Name:  p.Name(),
   383  			Href:  p.Name(),
   384  			Desc:  profileDescriptions[p.Name()],
   385  			Count: p.Count(),
   386  		})
   387  	}
   388  
   389  	// Adding other profiles exposed from within this package
   390  	for _, p := range []string{"cmdline", "profile", "trace"} {
   391  		profiles = append(profiles, profileEntry{
   392  			Name: p,
   393  			Href: p,
   394  			Desc: profileDescriptions[p],
   395  		})
   396  	}
   397  
   398  	sort.Slice(profiles, func(i, j int) bool {
   399  		return profiles[i].Name < profiles[j].Name
   400  	})
   401  
   402  	if err := indexTmplExecute(w, profiles); err != nil {
   403  		log.Print(err)
   404  	}
   405  }
   406  
   407  func indexTmplExecute(w io.Writer, profiles []profileEntry) error {
   408  	var b bytes.Buffer
   409  	b.WriteString(`<html>
   410  <head>
   411  <title>/debug/pprof/</title>
   412  <style>
   413  .profile-name{
   414  	display:inline-block;
   415  	width:6rem;
   416  }
   417  </style>
   418  </head>
   419  <body>
   420  /debug/pprof/<br>
   421  <br>
   422  Types of profiles available:
   423  <table>
   424  <thead><td>Count</td><td>Profile</td></thead>
   425  `)
   426  
   427  	for _, profile := range profiles {
   428  		link := &url.URL{Path: profile.Href, RawQuery: "debug=1"}
   429  		fmt.Fprintf(&b, "<tr><td>%d</td><td><a href='%s'>%s</a></td></tr>\n", profile.Count, link, html.EscapeString(profile.Name))
   430  	}
   431  
   432  	b.WriteString(`</table>
   433  <a href="goroutine?debug=2">full goroutine stack dump</a>
   434  <br>
   435  <p>
   436  Profile Descriptions:
   437  <ul>
   438  `)
   439  	for _, profile := range profiles {
   440  		fmt.Fprintf(&b, "<li><div class=profile-name>%s: </div> %s</li>\n", html.EscapeString(profile.Name), html.EscapeString(profile.Desc))
   441  	}
   442  	b.WriteString(`</ul>
   443  </p>
   444  </body>
   445  </html>`)
   446  
   447  	_, err := w.Write(b.Bytes())
   448  	return err
   449  }
   450
View as plain text