blob: ef500db63c4c0acb7676e850f476d4d068d04a1a [file] [log] [blame] [view]
JBD54581732017-09-06 14:08:31 -07001Originally published at https://rakyll.org/custom-profiles/.
2
JBDdc34def2017-09-07 09:41:24 -07003----
JBD54581732017-09-06 14:08:31 -07004
Shulhane8dc08f2019-01-30 21:40:12 +07005Go provides several pprof profiles out of the box to gather
JBD54581732017-09-06 14:08:31 -07006profiling data from Go programs.
7
8The builtin profiles provided by the [runtime/pprof](https://golang.org/pkg/runtime/pprof/) package:
9
10* **profile**: CPU profile determines where a program spends its time while actively consuming CPU cycles (as opposed while sleeping or waiting for I/O).
11* **heap**: Heap profile reports the currently live allocations; used to monitor current memory usage or check for memory leaks.
12* **threadcreate**: Thread creation profile reports the sections of the program that lead the creation of new OS threads.
13* **goroutine**: Goroutine profile report the stack traces of all current goroutines.
14* **block**: Block profile show where goroutines block waiting on synchronization primitives (including timer channels). Block profile is not enabled by default; use runtime.SetBlockProfileRate to enable it.
15* **mutex**: Mutex profile reports the lock contentions. When you think your CPU is not fully utilized due to a mutex contention, use this profile. Mutex profile is not enabled by default, see runtime.SetMutexProfileFraction to enable.
16
17Additional to the builtin profiles, [runtime/pprof](https://golang.org/pkg/runtime/pprof/) package allows you to export your custom profiles, and instrument your code to record
18execution stacks that contributes to this profile.
19
20Imagine we have a blob server, and we are writing a Go client for it. And our users want to be able to profile the opened blobs on the client. We can create a profile and record the events of blob opening and closing, so the user can tell how many open blobs they are at any time.
21
22Here is a blobstore package that allows you to open some blobs. We will create a new custom profile and start
23recording execution stacks that contributes to opening of blobs:
24
25``` go
26package blobstore
27
28import "runtime/pprof"
29
30var openBlobProfile = pprof.NewProfile("blobstore.Open")
31
32// Open opens a blob, all opened blobs need
33// to be closed when no longer in use.
34func Open(name string) (*Blob, error) {
35 blob := &Blob{name: name}
36 // TODO: Initialize the blob...
37
38 openBlobProfile.Add(blob, 2) // add the current execution stack to the profile
39 return blob, nil
40}
41```
42
43And once users want to close the blob, we need to remove the execution stack associated with the current blob from the profile:
44
45```go
46// Close closes the blob and frees the
47// underlying resources.
48func (b *Blob) Close() error {
49 // TODO: Free other resources.
50 openBlobProfile.Remove(b)
51 return nil
52}
53```
54
55And now, from the programs using this package, we should be able to retrieve `blobstore.Open` profile data and use our daily pprof tools to examine and visualize them.
56
57Let's write a small main program than opens some blobs:
58
59```
60package main
61
62import (
63 "fmt"
64 "math/rand"
65 "net/http"
66 _ "net/http/pprof" // as a side effect, registers the pprof endpoints.
67 "time"
68
69 "myproject.org/blobstore"
70)
71
72func main() {
73 for i := 0; i < 1000; i++ {
74 name := fmt.Sprintf("task-blob-%d", i)
75 go func() {
76 b, err := blobstore.Open(name)
77 if err != nil {
78 // TODO: Handle error.
79 }
80 defer b.Close()
81
Shulhane8dc08f2019-01-30 21:40:12 +070082 // TODO: Perform some work, write to the blob.
JBD54581732017-09-06 14:08:31 -070083 }()
84 }
85 http.ListenAndServe("localhost:8888", nil)
86}
87```
88
89Start the server, then use go tool to read and visualize the profile data:
90
91```
92$ go tool pprof http://localhost:8888/debug/pprof/blobstore.Open
93(pprof) top
94Showing nodes accounting for 800, 100% of 800 total
95 flat flat% sum% cum cum%
96 800 100% 100% 800 100% main.main.func1 /Users/jbd/src/hello/main.go
97```
98
99You will see that there are 800 open blobs and all openings are coming from main.main.func1. In this small example, there is nothing more to see, but in a complex server you can examine the hottest spots that works with an open blob and find out bottlenecks or leaks.