From 9671050e5b520e3cf979b113f19e554e6402a3c6 Mon Sep 17 00:00:00 2001 From: Simon Zolin Date: Wed, 22 Apr 2020 16:00:26 +0300 Subject: [PATCH] + config: add "debug_pprof" setting Squashed commit of the following: commit 96d185cf4acc55b21a00d10072e0a641ef7655b8 Merge: 3b75a8cb 9b7c1181 Author: Simon Zolin Date: Wed Apr 22 15:57:50 2020 +0300 Merge remote-tracking branch 'origin/master' into add-pprof commit 3b75a8cbec5d72be8865a56bfd7ebb8b0673c3bc Author: Simon Zolin Date: Wed Apr 22 13:52:36 2020 +0300 * use localhost:6060 for pprof commit f66f2fbd7409b98cd9f7d297c268fca998f85e3b Author: Simon Zolin Date: Wed Apr 22 12:46:25 2020 +0300 minor commit 6e38712fb5542f612675858eb957efdefc38f9b0 Author: Simon Zolin Date: Wed Apr 22 11:59:39 2020 +0300 use separate HTTP server for pprof commit 988d95b5fad22f536bf9204b6b96f3697cf9a589 Author: Simon Zolin Date: Tue Apr 21 17:04:04 2020 +0300 minor commit 90ee6e9753be2af49467687cdf71c35b3943b78b Author: Simon Zolin Date: Tue Apr 21 16:57:38 2020 +0300 * use modified version of pprof commit 413002220fe0717950539a8b7e6b0f31cef31bb8 Author: Simon Zolin Date: Mon Apr 20 16:35:21 2020 +0300 minor commit d4655d3849de1d9fe97efdb7f18fc21d5ac19eda Author: Simon Zolin Date: Mon Apr 20 15:57:57 2020 +0300 + config: add "enable_pprof" setting --- .golangci.yml | 5 +- home/config.go | 1 + home/home.go | 10 ++ util/pprof.go | 352 +++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 367 insertions(+), 1 deletion(-) create mode 100644 util/pprof.go diff --git a/.golangci.yml b/.golangci.yml index 341a62d4..60b7ee1c 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -13,6 +13,7 @@ run: skip-files: - ".*generated.*" - dnsfilter/rule_to_regexp.go + - util/pprof.go - ".*_test.go" @@ -65,5 +66,7 @@ issues: - Error return value of ..*.Shutdown. # goconst - string .forcesafesearch.google.com. has 3 occurrences + # gosec: Profiling endpoint is automatically exposed on /debug/pprof + - G108 # gosec: Subprocess launched with function call as argument or cmd arguments - - G204 \ No newline at end of file + - G204 diff --git a/home/config.go b/home/config.go index 2d78b42c..35940ebd 100644 --- a/home/config.go +++ b/home/config.go @@ -45,6 +45,7 @@ type configuration struct { ProxyURL string `yaml:"http_proxy"` // Proxy address for our HTTP client Language string `yaml:"language"` // two-letter ISO 639-1 language code RlimitNoFile uint `yaml:"rlimit_nofile"` // Maximum number of opened fd's per process (0: default) + DebugPProf bool `yaml:"debug_pprof"` // Enable pprof HTTP server on port 6060 // TTL for a web session (in hours) // An active session is automatically refreshed once a day. diff --git a/home/home.go b/home/home.go index 98ad8841..2340ca6c 100644 --- a/home/home.go +++ b/home/home.go @@ -242,6 +242,16 @@ func run(args options) { if err != nil { log.Fatal(err) } + + if config.DebugPProf { + mux := http.NewServeMux() + util.PProfRegisterWebHandlers(mux) + go func() { + log.Info("pprof: listening on localhost:6060") + err := http.ListenAndServe("localhost:6060", mux) + log.Error("Error while running the pprof server: %s", err) + }() + } } err := os.MkdirAll(Context.getDataDir(), 0755) diff --git a/util/pprof.go b/util/pprof.go new file mode 100644 index 00000000..031e6c78 --- /dev/null +++ b/util/pprof.go @@ -0,0 +1,352 @@ +// Modified pprof package +// The problem with the mainstream package is that it registers HTTP handlers +// inside init() function. +// This behaviour makes it impossible to enable pprof on demand in runtime. +// But this package has a separate function for this - +// PProfRegisterWebHandlers(). + +// Copyright 2010 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +// Package pprof serves via its HTTP server runtime profiling data +// in the format expected by the pprof visualization tool. +// +// The package is typically only imported for the side effect of +// registering its HTTP handlers. +// The handled paths all begin with /debug/pprof/. +// +// To use pprof, link this package into your program: +// import _ "net/http/pprof" +// +// If your application is not already running an http server, you +// need to start one. Add "net/http" and "log" to your imports and +// the following code to your main function: +// +// go func() { +// log.Println(http.ListenAndServe("localhost:6060", nil)) +// }() +// +// If you are not using DefaultServeMux, you will have to register handlers +// with the mux you are using. +// +// Then use the pprof tool to look at the heap profile: +// +// go tool pprof http://localhost:6060/debug/pprof/heap +// +// Or to look at a 30-second CPU profile: +// +// go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30 +// +// Or to look at the goroutine blocking profile, after calling +// runtime.SetBlockProfileRate in your program: +// +// go tool pprof http://localhost:6060/debug/pprof/block +// +// Or to collect a 5-second execution trace: +// +// wget http://localhost:6060/debug/pprof/trace?seconds=5 +// +// Or to look at the holders of contended mutexes, after calling +// runtime.SetMutexProfileFraction in your program: +// +// go tool pprof http://localhost:6060/debug/pprof/mutex +// +// To view all available profiles, open http://localhost:6060/debug/pprof/ +// in your browser. +// +// For a study of the facility in action, visit +// +// https://blog.golang.org/2011/06/profiling-go-programs.html +// +package util + +import ( + "bufio" + "bytes" + "fmt" + "html/template" + "io" + "log" + "net/http" + "os" + "runtime" + "runtime/pprof" + "runtime/trace" + "sort" + "strconv" + "strings" + "time" +) + +// PProfRegisterWebHandlers - register HTTP handlers for pprof +func PProfRegisterWebHandlers(mux *http.ServeMux) { + mux.HandleFunc("/debug/pprof/", Index) + mux.HandleFunc("/debug/pprof/cmdline", Cmdline) + mux.HandleFunc("/debug/pprof/profile", Profile) + mux.HandleFunc("/debug/pprof/symbol", Symbol) + mux.HandleFunc("/debug/pprof/trace", Trace) +} + +// Cmdline responds with the running program's +// command line, with arguments separated by NUL bytes. +// The package initialization registers it as /debug/pprof/cmdline. +func Cmdline(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Content-Type-Options", "nosniff") + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + fmt.Fprintf(w, strings.Join(os.Args, "\x00")) +} + +func sleep(w http.ResponseWriter, d time.Duration) { + var clientGone <-chan bool + if cn, ok := w.(http.CloseNotifier); ok { + clientGone = cn.CloseNotify() + } + select { + case <-time.After(d): + case <-clientGone: + } +} + +func durationExceedsWriteTimeout(r *http.Request, seconds float64) bool { + srv, ok := r.Context().Value(http.ServerContextKey).(*http.Server) + return ok && srv.WriteTimeout != 0 && seconds >= srv.WriteTimeout.Seconds() +} + +func serveError(w http.ResponseWriter, status int, txt string) { + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + w.Header().Set("X-Go-Pprof", "1") + w.Header().Del("Content-Disposition") + w.WriteHeader(status) + fmt.Fprintln(w, txt) +} + +// Profile responds with the pprof-formatted cpu profile. +// Profiling lasts for duration specified in seconds GET parameter, or for 30 seconds if not specified. +// The package initialization registers it as /debug/pprof/profile. +func Profile(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Content-Type-Options", "nosniff") + sec, err := strconv.ParseInt(r.FormValue("seconds"), 10, 64) + if sec <= 0 || err != nil { + sec = 30 + } + + if durationExceedsWriteTimeout(r, float64(sec)) { + serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout") + return + } + + // Set Content Type assuming StartCPUProfile will work, + // because if it does it starts writing. + w.Header().Set("Content-Type", "application/octet-stream") + w.Header().Set("Content-Disposition", `attachment; filename="profile"`) + if err := pprof.StartCPUProfile(w); err != nil { + // StartCPUProfile failed, so no writes yet. + serveError(w, http.StatusInternalServerError, + fmt.Sprintf("Could not enable CPU profiling: %s", err)) + return + } + sleep(w, time.Duration(sec)*time.Second) + pprof.StopCPUProfile() +} + +// Trace responds with the execution trace in binary form. +// Tracing lasts for duration specified in seconds GET parameter, or for 1 second if not specified. +// The package initialization registers it as /debug/pprof/trace. +func Trace(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Content-Type-Options", "nosniff") + sec, err := strconv.ParseFloat(r.FormValue("seconds"), 64) + if sec <= 0 || err != nil { + sec = 1 + } + + if durationExceedsWriteTimeout(r, sec) { + serveError(w, http.StatusBadRequest, "profile duration exceeds server's WriteTimeout") + return + } + + // Set Content Type assuming trace.Start will work, + // because if it does it starts writing. + w.Header().Set("Content-Type", "application/octet-stream") + w.Header().Set("Content-Disposition", `attachment; filename="trace"`) + if err := trace.Start(w); err != nil { + // trace.Start failed, so no writes yet. + serveError(w, http.StatusInternalServerError, + fmt.Sprintf("Could not enable tracing: %s", err)) + return + } + sleep(w, time.Duration(sec*float64(time.Second))) + trace.Stop() +} + +// Symbol looks up the program counters listed in the request, +// responding with a table mapping program counters to function names. +// The package initialization registers it as /debug/pprof/symbol. +func Symbol(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Content-Type-Options", "nosniff") + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + + // We have to read the whole POST body before + // writing any output. Buffer the output here. + var buf bytes.Buffer + + // We don't know how many symbols we have, but we + // do have symbol information. Pprof only cares whether + // this number is 0 (no symbols available) or > 0. + fmt.Fprintf(&buf, "num_symbols: 1\n") + + var b *bufio.Reader + if r.Method == "POST" { + b = bufio.NewReader(r.Body) + } else { + b = bufio.NewReader(strings.NewReader(r.URL.RawQuery)) + } + + for { + word, err := b.ReadSlice('+') + if err == nil { + word = word[0 : len(word)-1] // trim + + } + pc, _ := strconv.ParseUint(string(word), 0, 64) + if pc != 0 { + f := runtime.FuncForPC(uintptr(pc)) + if f != nil { + fmt.Fprintf(&buf, "%#x %s\n", pc, f.Name()) + } + } + + // Wait until here to check for err; the last + // symbol will have an err because it doesn't end in +. + if err != nil { + if err != io.EOF { + fmt.Fprintf(&buf, "reading request: %v\n", err) + } + break + } + } + + w.Write(buf.Bytes()) +} + +// Handler returns an HTTP handler that serves the named profile. +func Handler(name string) http.Handler { + return handler(name) +} + +type handler string + +func (name handler) ServeHTTP(w http.ResponseWriter, r *http.Request) { + w.Header().Set("X-Content-Type-Options", "nosniff") + p := pprof.Lookup(string(name)) + if p == nil { + serveError(w, http.StatusNotFound, "Unknown profile") + return + } + gc, _ := strconv.Atoi(r.FormValue("gc")) + if name == "heap" && gc > 0 { + runtime.GC() + } + debug, _ := strconv.Atoi(r.FormValue("debug")) + if debug != 0 { + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + } else { + w.Header().Set("Content-Type", "application/octet-stream") + w.Header().Set("Content-Disposition", fmt.Sprintf(`attachment; filename="%s"`, name)) + } + p.WriteTo(w, debug) +} + +var profileDescriptions = map[string]string{ + "allocs": "A sampling of all past memory allocations", + "block": "Stack traces that led to blocking on synchronization primitives", + "cmdline": "The command line invocation of the current program", + "goroutine": "Stack traces of all current goroutines", + "heap": "A sampling of memory allocations of live objects. You can specify the gc GET parameter to run GC before taking the heap sample.", + "mutex": "Stack traces of holders of contended mutexes", + "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.", + "threadcreate": "Stack traces that led to the creation of new OS threads", + "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.", +} + +// Index responds with the pprof-formatted profile named by the request. +// For example, "/debug/pprof/heap" serves the "heap" profile. +// Index responds to a request for "/debug/pprof/" with an HTML page +// listing the available profiles. +func Index(w http.ResponseWriter, r *http.Request) { + if strings.HasPrefix(r.URL.Path, "/debug/pprof/") { + name := strings.TrimPrefix(r.URL.Path, "/debug/pprof/") + if name != "" { + handler(name).ServeHTTP(w, r) + return + } + } + + type profile struct { + Name string + Href string + Desc string + Count int + } + var profiles []profile + for _, p := range pprof.Profiles() { + profiles = append(profiles, profile{ + Name: p.Name(), + Href: p.Name() + "?debug=1", + Desc: profileDescriptions[p.Name()], + Count: p.Count(), + }) + } + + // Adding other profiles exposed from within this package + for _, p := range []string{"cmdline", "profile", "trace"} { + profiles = append(profiles, profile{ + Name: p, + Href: p, + Desc: profileDescriptions[p], + }) + } + + sort.Slice(profiles, func(i, j int) bool { + return profiles[i].Name < profiles[j].Name + }) + + if err := indexTmpl.Execute(w, profiles); err != nil { + log.Print(err) + } +} + +var indexTmpl = template.Must(template.New("index").Parse(` + +/debug/pprof/ + + + +/debug/pprof/
+
+Types of profiles available: + + +{{range .}} + + + +{{end}} +
CountProfile
{{.Count}}{{.Name}}
+full goroutine stack dump +
+

+Profile Descriptions: +

    +{{range .}} +
  • {{.Name}}:
    {{.Desc}}
    • +{{end}} +
+

+ + +`))