Profiling Golang with pprof

This is a brief reference on how to use **Go tool pprof**, the long version can be found on the Go blog[1].

To use pprof, link this package into your program:

import _ "net/http/pprof"

This can be included conditionally during build[1].

1: conditionally during build

If your application is not already running an http server, you need to start one. To view all available profiles, open http://localhost:8080/debug/pprof/[1] in your browser (use the port of your webserver).

1: http://localhost:8080/debug/pprof/

Golang pprof available profiles[1]

1: Golang pprof available profiles

We can connect the `go tool pprof` program to the web interface at `host:port`, e.g.:

go tool pprof http://localhost:8082/debug/pprof/goroutine

This puts us into an interactive mode where we run the `top` command

(pprof) top
Showing nodes accounting for 25, 100% of 25 total
Showing top 10 nodes out of 97
      flat  flat%   sum%        cum   cum%
        23 92.00% 92.00%         23 92.00%  runtime.gopark
         1  4.00% 96.00%          1  4.00%  runtime.sigNoteSleep
         1  4.00%   100%          1  4.00%  runtime/pprof.runtime_goroutineProfileWithLabels
         0     0%   100%          3 12.00%  bufio.(*Reader).Peek
         0     0%   100%          1  4.00%  bufio.(*Reader).Read
         0     0%   100%          2  8.00%  bufio.(*Reader).ReadByte
         0     0%   100%          5 20.00%  bufio.(*Reader).fill
         0     0%   100%          1  4.00%  bytes.(*Buffer).ReadFrom
         0     0%   100%          1  4.00%  crypto/tls.(*Conn).Read
         0     0%   100%          1  4.00%  crypto/tls.(*Conn).readFromUntil

We can use topN and sort with the -cum (for cumulative) flag:

(pprof) top10
(pprof) top5 -cum

with graphviz installed, we can generate a web repot

(pprof) web

to find out the functions that spend most of the time in mallocgc

(pprof) web mallocgc

Get a heap memory profile

go tool pprof http://localhost:8082/debug/pprof/heap

We can generate a PNG profile if we have the `dot` tool from graphviz[1] installed.

1: graphviz

go tool pprof -png http://localhost:8082/debug/pprof/heap > pprof-heap.png

CPU profile

go tool pprof http://localhost:8082/debug/pprof/profile

(pprof) top
Showing nodes accounting for 150ms, 100% of 150ms total
Showing top 10 nodes out of 99
      flat  flat%   sum%        cum   cum%
      80ms 53.33% 53.33%       80ms 53.33%  runtime.cgocall
      30ms 20.00% 73.33%       30ms 20.00%  syscall.syscall
      10ms  6.67% 80.00%       10ms  6.67%  google.golang.org/protobuf/internal/encoding/json.(*Decoder).parseNext
      10ms  6.67% 86.67%       10ms  6.67%  runtime.madvise
      10ms  6.67% 93.33%       10ms  6.67%  runtime.mallocgc
      10ms  6.67%   100%       10ms  6.67%  runtime.netpoll
         0     0%   100%       10ms  6.67%  bufio.(*Reader).Read
         0     0%   100%       10ms  6.67%  bufio.(*Reader).ReadByte
         0     0%   100%       10ms  6.67%  bufio.(*Reader).fill
         0     0%   100%       20ms 13.33%  bufio.(*Writer).Flush

**Note**: the trace endpoint (`/debug/pprof/trace?seconds=5`), outputs a file that is not a pprof profile but a trace that we can view using `go tool trace`.

For goroutine blocking and to see the holders of contended mutexex, we need to call runtime.SetBlockProfileRate and runtime.SetMutexProfileFraction in the program:

runtime.SetBlockProfileRate(1)
runtime.SetMutexProfileFraction(1)

go tool pprof http://localhost:8082/debug/pprof/block
go tool pprof http://localhost:8082/debug/pprof/mutex

Allocated and In-Use memory

we can view either allocation or in-use memory. When we're concerned with the amount of memory being used, chose the 'inuse' metrics, if we're concerned with time spend in garbage collection, view allocations

-inuse_space Display in-use memory size

-inuse_objects Display in-use object counts

-alloc_space Display allocated memory size

-alloc_objects Display allocated object counts

-- Response ended

-- Page fetched on Fri May 10 11:34:33 2024