Create custom Go profiles with pprof. Storing Stacks / Badoo Blog

Frame from the series “Colombo” The

go-to-pprof package is often used to profile the processor or memory, but not everyone knows about the ability to create their own custom profiles. They can be useful for finding resource leaks or, for example, for tracking the abuse of any difficult calls.

Profiles

From the pprof documentation :

A profile is a set of stack traces showing the order of calls that led to an event. For example, memory allocation. Packages can create and maintain their own profiles. The most common reason is to keep track of any resources that require explicit closure: files, network connections.

Another potential use of profiles may be to track not for something that needs to be explicitly closed, but for a function or resource that can block execution on a call, and you need to understand where such calls are, how many there are, and so on. Profiles are especially useful where stack traces are useful, and the main advantage is the easy integration with go tool pprof.

Profile Cautions

The profile package panics for almost any misuse. For instance:

• Create a profile that already exists
• Binding a profile to the same object twice
• Deleting a stack that has not been added before
• Deleting a stack that has already been deleted

Try to avoid such situations.

Profile Creation

var libProfile *pprof.Profile
func init() {
   profName := "my_experiment_thing"
   libProfile = pprof.Lookup(profName)
   if libProfile == nil {
       libProfile = pprof.NewProfile(profName)
   }
}

Since we cannot create two different profiles with the same name, it makes sense to create them in init (). You might want to create a single line profile.

// Warning: /vendor panic possibilities
var panicProfile = pprof.NewProfile("this_unique_name")

But such use is fraught with the fact that your chosen name can already be used. Even if you are sure that it is unique, if your library is vendor several times (which is quite possible), the application will panic at startup. Because the profiles are thread safe, and init () - the function is executed once, the check-and-create approach is the right approach.

Godoc mentions that the common way to create unique names is to use the ' import / path.' Prefix , but following the advice will cause you to come across a known bug in cmd / pprof . So use the path and name of your package, but only with the following characters [a-zA-Z0-9_].

Profile Usage

type someResource struct {
      *os.File
}
func MustResource() *someResource {
      f, err := os.Create(...)
      if err != nil {
             panic(err)
      }
      r := &someResource{f}
      libProfile.Add(r, 1)
      return r
}
func (r *someResource) Close() error {
      libProfile.Remove(r)
      return r.File.Close()
}

The main functions of the package are Add and Remove . In this example, I will follow all the created resources that are not closed, so I will add a stack trace at the moment when I create the resource and delete it when I close it. The Add function requires a unique object for every call, so I can use the resource itself as a key. Sometimes there is no good key, in which case you can create a dummy byte and use its address.

func usesAResource() {
      pprofKey := new(byte)
      libProfile.Add(pprofKey, 1)
      defer libProfile.Remove(pprofKey)
      // ....
}

Exporting a new profile in pprof

If you enable the http pprof library , Go will register the http handlers for the profile package. This is usually done by adding an “empty” import in the main.go file.

import _ "net/http/pprof"

You can achieve the same thing by manually registering the pprof handler.

httpMux.Handle("/debug/pprof/", http.HandlerFunc(pprof.Index))

Using pprof

I created a test application to demonstrate everything that I'm talking about.

package main
import (
	"fmt"
	"log"
	"net/http"
	_ "net/http/pprof"
	"os"
	"runtime/pprof"
	"sync/atomic"
	"time"
)
var libProfile *pprof.Profile
func init() {
	profName := "my_experiment_thing"
	libProfile = pprof.Lookup(profName)
	if libProfile == nil {
		libProfile = pprof.NewProfile(profName)
	}
}
type someResource struct {
	*os.File
}
var fileIndex = int64(0)
func MustResource() *someResource {
	f, err := os.Create(fmt.Sprintf("/tmp/%d.txt", atomic.AddInt64(&fileIndex, 1)))
	if err != nil {
		panic(err)
	}
	r := &someResource{f}
	libProfile.Add(r, 1)
	return r
}
func (r *someResource) Close() error {
	libProfile.Remove(r)
	return r.File.Close()
}
func trackAFunction() {
	tracked := new(byte)
	libProfile.Add(tracked, 1)
	defer libProfile.Remove(tracked)
	time.Sleep(time.Second)
}
func usesAResource() {
	res := MustResource()
	defer res.Close()
	for i := 0; i < 10; i++ {
		time.Sleep(time.Second)
	}
}
func main() {
	http.HandleFunc("/nonblock", func(rw http.ResponseWriter, req *http.Request) {
		go usesAResource()
	})
	http.HandleFunc("/functiontrack", func(rw http.ResponseWriter, req *http.Request) {
		trackAFunction()
	})
	http.HandleFunc("/block", func(rw http.ResponseWriter, req *http.Request) {
		usesAResource()
	})
	log.Println("Running!")
	log.Println(http.ListenAndServe("localhost:6060", nil))
}

By running this program, you can go to http: // localhost: 6060 / debug / pprof / and see all available profiles.



Feed some traffic to / nonblock and / block, then click on the my_example_thing link to see the profile.

my_experiment_thing profile: total 6
4 @ 0x2245 0x5d961
#	0x2244	main.usesAResource+0x64	/Users/.../pproftest.go:64
2 @ 0x2245 0x2574 0x9c184 0x9d56f 0x9df7d 0x9aa07 0x5d961
#	0x2244	main.usesAResource+0x64			/Users/.../pproftest.go:64
#	0x2573	main.main.func3+0x13			/Users/.../pproftest.go:79
#	0x9c183	net/http.HandlerFunc.ServeHTTP+0x43	/usr/local/Cellar/go/1.7.1/libexec/src/net/http/server.go:1726
#	0x9d56e	net/http.(*ServeMux).ServeHTTP+0x7e	/usr/local/Cellar/go/1.7.1/libexec/src/net/http/server.go:2022
#	0x9df7c	net/http.serverHandler.ServeHTTP+0x7c	/usr/local/Cellar/go/1.7.1/libexec/src/net/http/server.go:2202
#	0x9aa06	net/http.(*conn).serve+0x4b6		/usr/local/Cellar/go/1.7.1/libexec/src/net/http/server.go:1579

Call graph

I used brew to install Graphviz on my Mac: it is needed so that pprof can create png images.

brew install Graphviz

After installing graphviz, I can use pprof to generate a png image with a call graph.

go tool pprof -png /tmp/mybinary ‘localhost:6060/debug/pprof/my_experiment_thing?debug=1’ > /tmp/exp.png

I used PNG for easy insertion into this article, but SVG is usually more convenient for viewing in a browser. Generate svg instead of png by adding -svg instead of -png when the pprof command is called.
The finished picture is below.



This picture shows me stack traces of creating those resources that were not closed. When I generated this picture, I sent twice as many non-blocking requests, and this can be seen by the trace. All stack traces end in MustResource. If you don't like this, you can pass an integer when calling Profile.Add .

You can also use the interactive console, which is available when starting pprof from the terminal. Below, I launched pprof and use the top command to see which calls are more common among all my stack traces.

> go tool pprof 'localhost:6060/debug/pprof/my_experiment_thing?debug=1'
Fetching profile from http://localhost:6060/debug/pprof/my_experiment_thing?debug=1
Saved profile in /Users/.../pprof/pprof.localhost:6060.my_experiment_thing.007.pb.gz
Entering interactive mode (type "help" for commands)
(pprof) top30
6 of 6 total (  100%)
     flat  flat%   sum%        cum   cum%
        6   100%   100%          6   100%  main.usesAResource
        0     0%   100%          2 33.33%  main.main.func3
        0     0%   100%          2 33.33%  net/http.(*ServeMux).ServeHTTP
        0     0%   100%          2 33.33%  net/http.(*conn).serve
        0     0%   100%          2 33.33%  net/http.HandlerFunc.ServeHTTP
        0     0%   100%          2 33.33%  net/http.serverHandler.ServeHTTP
        0     0%   100%          6   100%  runtime.goexit
(pprof)

Conclusion

Not all the features used in profiling a processor or memory are available through the pprof API, but still we get a very cool visualization, given how little code is needed. The next time you write a library, look, maybe stack traces will help you to specifically defuse your problem.