Golang application performance profiling and visualising with pprof

In this example I am going to show you how you can use Golang's pprof package in order to collect and visualise application performance data. The findings can be used to identify bottlenecks and improve overall performance. You can even see which line takes how long. I mean line by line performance analysis! I personally managed to improve one of my APIs performance by 60%. I suggest you to read a very valuable High Performance Go Workshop post.

Installation

The full installation guide is here but I think it is enough to start by just running go get -u github.com/google/pprof command.

Application

Assuming that we have a HTTP API with basic info as follows.

Path: /Users/inanzzz/Language/Go/src/github.com/inanzzz/game
Binary: /Users/inanzzz/Language/Go/src/github.com/inanzzz/game/bin/game
Server: http://0.0.0.0:8000

Routes

Add routes below to your HTTP server's router. You can open core pprof.go file to see what those routes do.

// router := github.com/julienschmidt/httprouter
router.HandlerFunc(http.MethodGet, "/debug/pprof/", pprof.Index)
router.HandlerFunc(http.MethodGet, "/debug/pprof/allocs", pprof.Index)
router.HandlerFunc(http.MethodGet, "/debug/pprof/goroutine", pprof.Index)
router.HandlerFunc(http.MethodGet, "/debug/pprof/heap", pprof.Index)
router.HandlerFunc(http.MethodGet, "/debug/pprof/profile", pprof.Profile)
router.HandlerFunc(http.MethodGet, "/debug/pprof/trace", pprof.Trace)
router.HandlerFunc(http.MethodGet, "/debug/pprof/symbol", pprof.Symbol)

Import _ "net/http/pprof" package. That's it! We can move on to collect and visualise data.

Data generation and collection

You must to send many requests constantly to one of your endpoints so that the pprof is able to collect data otherwise application exists quickly and you have no time to collect data. For that I am using a k6 script but you can just use a cURL command in a loop if you wish. I will send 100 concurrent requests for 10 seconds to GET http://0.0.0.0:8000/home endpoint.

Let's send some request and collect CPU data. As soon as you run pprof command, you must run your request script or the other way round as long as you are quick!

Send requests

$ k6 run scripts/k6/home.js

Collect data

This will run for a bit so be patient.

$ go tool pprof /Users/inanzzz/Language/Go/src/github.com/inanzzz/game/bin/game http://0.0.0.0:8000/debug/pprof/profile

// Result
Fetching profile over HTTP from http://0.0.0.0:8000/debug/pprof/profile
Saved profile in /Users/inanzzz/pprof/pprof.game.samples.cpu.018.pb.gz
File: game
Type: cpu
Time: Dec 28, 2019 at 2:15pm (GMT)
Duration: 30.01s, Total samples = 0 
No samples were found with the default sample value type.
Try "sample_index" command to analyze different sample values.
Entering interactive mode (type "help" for commands, "o" for options)

Visualising the data

This command will open up your browser at http://localhost:8080/ui/ where you will see graphs.

$ go tool pprof -http=:8080 /Users/inanzzz/pprof/pprof.game.samples.cpu.017.pb.gz

This command is used only for the "trace" diagram data generation and visualisation.

// Generate data.
$ wget http://0.0.0.0:8000/debug/pprof/trace?seconds=10 -O tracing

// Serve on the browser.
$ go tool trace tracing 
2019/12/28 14:43:20 Parsing trace...
2019/12/28 14:43:21 Splitting trace...
2019/12/28 14:43:22 Opening browser. Trace viewer is listening on http://127.0.0.1:64056