profilinggo

by samonzeweb

samonzeweb / profilinggo

A quick tour (or reminder) of Go performance tools

212 Stars 9 Forks Last release: Not found 12 Commits 0 Releases

Available items

No Items, yet!

The developer of this repository has not created any items for sale yet. Need a bug fixed? Help with integration? A different license? Create a request here:

Basics of benchmarking, profiling and tracing with Go

Introduction

This documentation gives an overview of possibilities offered by go tooling to measure performances or collect runtime information. It is not a detailed tutorial about benchmarking, profiling or tracing.

This documentation could also act as a reminder.

In most cases, you can try by yourself by running provided example source code. It is easy to experiment and play with these tools, as a kind of live demo or for a workshop.

Main subjects are :

  • Benchmarking : focus on a particular piece of code, allowing measurement of time and/or memory information.
  • Profiling : aggregated data collected through sampling during program (or test) execution. Profiling has no timeline.
  • Tracing : data collected through events occurring during program (or test) execution. Tracing has a timeline.

Profiling and tracing could apply to benchmarks.

Note about Go version

The code is provided as a Go module. There is no need to set the

GOPATH
environment variable.

You need a Go version compatible with Go modules. Provided code uses Go 1.12.

Note about CPU measures

Go tooling does not measure CPU usage, it measures elapsed time. It's important not to confuse both, because if the code isn't CPU bound, they are not correlated.

For example if you add

time.Sleep(time.Millisecond)
into the code it will change the output. The CPU isn't involved, but the result changes.

Benchmarking

Benchmarking is done through the Go testing tools. It's rather simple and well documented.

The primary result of a benchmark is, per tested operation :

  • the time it takes.
  • the amount of memory allocated on the heap.
  • the amount of allocations.

Each benchmark could also be a starting point for profiling or tracing operations.

See the code of

fibonacci/fibonacci_test.go
for a minimal example.

Running benchmarks

Run the tests :

  • without any benchmarks :
    go test ./fibonacci
  • with benchmarks (time) :
    go test ./fibonacci -bench .
  • with benchmarks (time and memory) :
    go test ./fibonacci -bench . -benchmem

The argument following

-bench
is a regular expression. All benchmark functions whose names match are executed. The
.
in the previous examples isn't the current directory but a pattern matching all tests. To run a specific benchmark, use the regexp :
-bench Suite
(means everything containing Suite).

Useful tip : see

ResetTimer()
to ignore test setup in measures, see also
StopTimer()
and
StartTimer()
: https://golang.org/pkg/testing/#B.ResetTimer

Comparing benchmarks

It's possible to compare benchmarks with an external tool :

go get -u golang.org/x/tools/cmd/benchcmp

go test ./fibonacci -bench . -benchmem > old.txt (do some changes in the code) go test ./fibonacci -bench . -benchmem > new.txt

~/go/bin/benchcmp old.txt new.txt

Profiling

Profiling data are sampled and aggregated ones, not detailed traces. CPU profile measures elapsed time, and memory profile measures heap allocations (the stack is ignored).

While CPU benchmarks show how long an operation take (global view), profiling show function's execution duration (detailed view). You get the same global/detailed view with memory consumption.

Profiling benchmarks

Get profiling data from the benchmarks:

  • CPU profiling using
    -cpuprofile=cpu.out
  • Memory profiling using
    -benchmem -memprofile=mem.out

An example with both :

go test ./fibonacci \
  -bench BenchmarkSuite \
  -benchmem \
  -cpuprofile=cpu.out \
  -memprofile=mem.out

CPU and memory profiling data from benchmarks are always stored in two separate files and will be analysed separately.

Viewing profiling data

There are two way to exploit profiling data with standard go tools :

  • through command line :
    go tool pprof cpu.out
  • with a browser :
    go tool pprof -http=localhost:8080 cpu.out

The View menu :

  • Top : ordered list of functions sorted by their duration/memory consumption.
  • Graph : function call tree, with time/memory annotations.
  • Flamegraph : self-explanatory
  • others...

Graph and flamegraph are rather similar, but there is a major difference : flamegraph shows sampled call stack with time/memory data (it's a tree), while graph could have multiple path converging to the same function (it's not a tree). The time/memory data associated to functions having multiple paths converging to is an aggregation. Both are useful, just choose the good one for your case.

Profiling program with code

Use

pprof.StartCPUProfile()
,
pprof.StopCPUProfile()
and
pprof.WriteHeapProfile()
. See the
pprof
package documentation for more information.

A simple example :

cd showfib
go build
./showfib 30 2>cpu.out
go tool pprof -http=localhost:8080 cpu.out

Tracing the GC work

This part isn't the most useful, but GC traces could easily spot a too high GC pressure.

Using an environment variable with any program (or test) :

GODEBUG=gctrace=1

Or using code :

  "runtime/trace"

trace.Start(os.Stderr)
defer trace.Stop()

Example with

webfib
:
cd webfib
go build
GODEBUG=gctrace=1 ./webfib

(other terminal)

go get -u github.com/rakyll/hey ~/go/bin/hey -n 1000 http://localhost:8000/?n=30

Tracing

Traces are event collected during the program execution. They give a chronological view of program's execution with detailed information about heap, GC, goroutines, core usage, ...

With tests

Generate traces with a test, and visualize data :

go test ./fibonacci \
  -bench BenchmarkSuite \
  -trace=trace.out

go tool trace trace.out

WARNING : Chrome is the only supported browser !

There are many detailed information... the blog post Go execution tracer is a good quick tour of the trace tool GUI.

Tip : from the View trace part hit

?
to show a help.

With code in a program

Like tracing with test, but you have to add code to collect traces into a file, and then use

go tool trace
.
  "runtime/trace"

trace.Start(os.Stderr)
defer trace.Stop()

(no example, see

trace
package for more information)

Tracing and profiling long running programs

Here Go tooling starts to really shine ! Go allows any program running a http server to be analysed during execution, even in production. And it's really easy.

Data are gathered only on demand, it doesn't use resources when it is not used.

Setup

Importing the

net/http/pprof
standard package add handler to
DefaultServeMux
. If there is already a web server using it, that's all.
import _ "net/http/pprof"

// Add this only if needed go func() { log.Println(http.ListenAndServe("localhost:8000", nil)) }()

The

webfib
exemple use it. Live data are available here : http://localhost:8000/debug/pprof/ , but is is it's not very user friendly.

Security

Handlers provided by

net/http/pprof
should only be accessible to trusted client. It is not something you want to be available directly through internet, or internally by untrusted third party.

The package

net/http/pprof
register handlers to
DefaultServeMux
, use a separate server (create a dedicated
Mux
) for your http server. Each one using a different port, different security rules could be applied.

Profiling

It's possible to profile program using

net/http/pprof
with
go tool pprof
.

We'll use 3 terminals to :

  • run the application
  • collect traces (it could take one or two minutes)
  • generate load
cd webfib
go build
./webfib

go tool pprof -http=localhost:8080 http://localhost:8000/

~/go/bin/hey -n 2000 -c 200 http://localhost:8000/?n=30

The

go tool ...
command line collect data, then open the browser. Be patient...

Trace analysis

Trace data have to be collected manually, and feed into

go tool trace
.

We'll use 3 terminals to :

  • run application
  • collect traces for 15 seconds
  • generate load
cd webfib
go build
./webfib

curl -o trace.out http://localhost:8000/debug/pprof/trace?seconds=15

~/go/bin/hey -n 2000 -c 200 http://localhost:8000/?n=30

Now analyse data with Chrome :

go tool trace trace.out

User-defined traces

User-defined traces were introduced with Go 1.11. It's not a new tool, but rather a way to add events to traces within your code.

What's in the box :

  • Task
    struct : to trace high-level operations.
  • Region
    struct : to trace lower-level operations.
  • Log
    function : to add log information into traces.

The

anowebfib
(like another webfib) use all mentionned points. Each HTTP request are identified using a
Task
, each call to fibonacci package with
Region
, and n are logged.

Example, with 3 terminals :

cd anowebfib
go build
./anowebfib

curl -o trace.out http://localhost:8000/debug/pprof/trace?seconds=20

~/go/bin/hey -n 2000 -c 200 http://localhost:8000/unique?n=30 ~/go/bin/hey -n 2000 -c 200 http://localhost:8000/multiple?n=30

As usual :

go tool trace trace.out

See : * User-defined tasks (and go down). * User-defined regions (and go down). * View trace : see events in goroutines.

Useful links

Packages :

  • Go testing package : https://golang.org/pkg/testing/
  • Go runtime package : https://golang.org/pkg/runtime/
  • Go trace package : https://golang.org/pkg/runtime/trace/
  • Go pprof package : https://golang.org/pkg/runtime/pprof/

Others :

  • How to Write Benchmarks in Go : https://dave.cheney.net/2013/06/30/how-to-write-benchmarks-in-go
  • Profiling Go programs : https://blog.golang.org/profiling-go-programs
  • Debugging performance issues in Go programs : https://github.com/golang/go/wiki/Performance
  • Go execution tracer : https://blog.gopheracademy.com/advent-2017/go-execution-tracer/ (see also the The tracer design doc link)
  • A whirlwind tour of Go’s runtime environment variables (see godebug) : https://dave.cheney.net/2015/11/29/a-whirlwind-tour-of-gos-runtime-environment-variables
  • benchstat : https://godoc.org/golang.org/x/perf/cmd/benchstat

We use cookies. If you continue to browse the site, you agree to the use of cookies. For more information on our use of cookies please see our Privacy Policy.