Go's execution tracer
the pprof endpoint you haven't used yet
Slide 2
Slide 2 text
$ go doc runtime/trace
package trace // import "runtime/trace"
Go execution tracer. The tracer captures
a wide range of execution events ...
A trace can be analyzed later with
'go tool trace' command.
Slide 3
Slide 3 text
$ go doc cmd/trace
Trace is a tool for viewing trace files.
...
View the trace in a web browser:
go tool trace trace.out
Slide 4
Slide 4 text
The tool in three demos:
1. A timing-dependent bug
2. What it doesn't show
3. Latency during GC
Slide 5
Slide 5 text
#1: Canceling requests
Slide 6
Slide 6 text
"Cancelation is transitive"
https://talks.golang.org/2014/gotham-context.slide#6
Slide 7
Slide 7 text
"Cancelation is transitive"
https://talks.golang.org/2014/gotham-context.slide#6
blocked on
net.(*netFD).Read
"closeNotifyAwaitActivityRead"
Slide 19
Slide 19 text
#2: It's not a panacea
Slide 20
Slide 20 text
No content
Slide 21
Slide 21 text
user code in
goroutines
runtime work
on the bottom syscall
SWEEP to
help GC
Slide 22
Slide 22 text
memory allocation
Slide 23
Slide 23 text
Classic GC advice:
"allocate less memory"
Slide 24
Slide 24 text
statsd package
uses locks
not saturated!
Slide 25
Slide 25 text
5.4s of waiting
in a 2s profile
Slide 26
Slide 26 text
#3: Sometimes it is the GC
Slide 27
Slide 27 text
GC
Slide 28
Slide 28 text
goroutines
in queue
9ms delay
Slide 29
Slide 29 text
9000µs 200µs
50µs
50µs
Slide 30
Slide 30 text
Check golang.org/issue
found #14812,
filed #16432
Slide 31
Slide 31 text
1. Allocation is counter to GC
2. Must assist (or steal credit)
3. Can't steal early in GC
4. Assists are amortized
5. 12MB minimum assist*
* based on concurrent GC pacing
Slide 32
Slide 32 text
50µs
50µs 50µs
Slide 33
Slide 33 text
go tool trace
http://.../debug/pprof/trace
Slide 34
Slide 34 text
More details on the GC bug,
soon on blog.twitch.tv
Slide 35
Slide 35 text
How can the tool help you?
1. See time-dependent issues
2. Complements other profiles
3. Find latency improvements