Upgrade to Pro
— share decks privately, control downloads, hide ads and more …
Speaker Deck
Features
Speaker Deck
PRO
Sign in
Sign up for free
Search
Search
You, latency and profiling @ GolangUK 2017
Search
Filippo Valsorda
August 17, 2017
Programming
0
1.2k
You, latency and profiling @ GolangUK 2017
Filippo Valsorda
August 17, 2017
Tweet
Share
More Decks by Filippo Valsorda
See All by Filippo Valsorda
Asynchronous networking @ GopherCon 2018
filosottile
3
2k
Le note cifrate di Antonio Marzi
filosottile
1
390
Why cgo is slow @ CapitalGo 2018
filosottile
2
4.5k
Squeezing a key through a carry bit @ 34c3
filosottile
0
1.7k
Calling Rust from Go, without cgo @ GothamGo 2017
filosottile
1
2.7k
Encrypting the Internet with Go @ GopherCon 2017
filosottile
9
2.6k
You, latency and profiling @ GopherCon India 2017
filosottile
13
4k
TLS 1.3 @ 33c3
filosottile
4
6.8k
Stealing Bitcoin With Math - HOPE XI
filosottile
13
30k
Other Decks in Programming
See All in Programming
プロダクト開発でも使おう 関数のオーバーロード
yoiwamoto
0
150
Webからモバイルへ Vue.js × Capacitor 活用事例
naokihaba
0
540
エラーって何種類あるの?
kajitack
5
140
iOSアプリ開発で 関数型プログラミングを実現する The Composable Architectureの紹介
yimajo
2
210
Effect の双対、Coeffect
yukikurage
5
1.4k
無関心の谷
kanayannet
0
160
PT AI без купюр
v0lka
0
230
Blueskyのプラグインを作ってみた
hakkadaikon
1
520
Parallel::Pipesの紹介
skaji
2
910
Cloudflare Realtime と Workers でつくるサーバーレス WebRTC
nekoya3
0
390
A comprehensive view of refactoring
marabesi
0
120
Elixir で IoT 開発、 Nerves なら簡単にできる!?
pojiro
1
120
Featured
See All Featured
Fashionably flexible responsive web design (full day workshop)
malarkey
407
66k
Visualizing Your Data: Incorporating Mongo into Loggly Infrastructure
mongodb
46
9.6k
Facilitating Awesome Meetings
lara
54
6.4k
Balancing Empowerment & Direction
lara
1
290
Visualization
eitanlees
146
16k
jQuery: Nuts, Bolts and Bling
dougneiner
63
7.8k
How STYLIGHT went responsive
nonsquared
100
5.6k
GraphQLとの向き合い方2022年版
quramy
46
14k
BBQ
matthewcrist
89
9.7k
Six Lessons from altMBA
skipperchong
28
3.8k
How to Think Like a Performance Engineer
csswizardry
24
1.7k
Sharpening the Axe: The Primacy of Toolmaking
bcantrill
43
2.4k
Transcript
You, latency and profiling Filippo Valsorda — @FiloSo/le
What is fast?
A fast hash… … can hash many MB per second
A fast regex… … can process many MB/s
A fast database… … can store many GB per second
A fast database… … can store many GB per second
… or replies to queries in a few ms
A fast website… … can handle many requests … or
loads in a few milliseconds
A fast API… … can handle many clients … or
answers in a few milliseconds
Fast is… Throughput and Latency
CPU profiling -cpuprofile /debug/pprof/profile
SIGPROF CPU profiling
runtime/proc.go
h>p.Handler 1 Running on CPU h>p.Handler 2 I/O I/O h>p.Handler
3 I/O h>p.Handler 4 I/O CPU profiling
Running on CPU I/O I/O I/O I/O h>p.Handler 1 h>p.Handler
2 h>p.Handler 3 h>p.Handler 4 CPU profiling
I/O Observed latency h>p.Handler 1 CPU profiling
func Write(data []byte) { for i := 0; i <
50; i++ { tmpfile, _ := ioutil.TempFile("", "ex") defer os.Remove(tmpfile.Name()) _, err = tmpfile.Write(data) tmpfile.Close() } } func Hash(data []byte) { for i := 0; i < 50; i++ { sha256.Sum256(data) } }
$ time curl http://127.0.0.1:12345/hash-and-write 9.831 total go tool pprof -web
slowserver cpu.pprof
None
$ time curl http://127.0.0.1:12345/hash-and-write 9.831 total $ time
curl http://127.0.0.1:12345/write-no-hash 7.692 total
Latency is not all about CPU
CPU profiling is for throughput The tracer is for latency
$ time curl http://127.0.0.1:12345/write-no-hash 7.692 total go tool trace -pprof=syscall
trace.out > syscall.pprof go tool pprof -web syscall.pprof
None
The tracer Detailed nanosecond-level log of execuOon events: • gorouOne
scheduling, blocking • syscalls, network, I/O • garbage collecOon
•log files are BIG •25% overhead (aWer Go 1.7) •symbols
are embedded (Go 1.7) The tracer
•Full event context •GorouOne metadata and history •Discrete events, not
samples Trace vs. profile
CPU profiling Total: 20 samples
Tracing events
import "runtime/trace" import "net/http/pprof" /debug/pprof/trace?seconds=5 The tracer
None
go tool trace -pprof=TYPE trace.out Supported profile types are: -
net: network blocking profile - sync: synchronization blocking profile - syscall: syscall blocking profile - sched: scheduler latency profile
go tool trace -pprof=syscall trace.out > syscall.pprof go tool pprof
-web syscall.pprof
go tool trace -pprof=syscall trace.out > syscall.pprof go-torch -b syscall.pprof
&& open torch.svg
None
None
-pprof=syscall func Write(data []byte) { for i := 0; i
< 50; i++ { tmpfile, _ := ioutil.TempFile("", "ex") defer os.Remove(tmpfile.Name()) _, err = tmpfile.Write(data) tmpfile.Close() } }
-pprof=sync // Block waits on a channel func Block() {
<-time.After(1 * time.Second) }
-pprof=sync
-pprof=sync
-pprof=net func Download() []byte { r, err := http.Get("https://golang.org/doc/go1.8") body,
err := ioutil.ReadAll(r.Body) r.Body.Close() return body }
-pprof=net
-pprof=net
-pprof=net
None
WriIng our own profile prof := make(map[uint64]pprof.Record) for _, ev
:= range events { if ev.Type != trace.EvGoBlockNet { continue } rec := prof[ev.StkID] rec.Stk = ev.Stk rec.N++ rec.Time += ev.Link.Ts - ev.Ts prof[ev.StkID] = rec } pprof.BuildProfile(prof).Write(os.Stdout)
var childG = make(map[uint64]struct{}) var lastGLen int for { for
_, ev := range events { if ev.Type != trace.EvGoCreate { continue } if _, ok := childG[ev.G]; !ok && !filterStack(ev.Stk, re) { continue } childG[ev.Args[0]] = struct{}{} } if len(childG) == lastGLen { break } lastGLen = len(childG) }
tracefocus tracefocus -filter=ServeHTTP trace.out > net.pprof github.com/FiloSottile/tracetools
None
None
Build more tools! • Focus on gorouOne number • Aggregate
all blocking types • VisualizaOons • …
tracehist tracehist -filter=Close trace.out github.com/FiloSottile/tracetools
None
Build more tools! Profile latency!
QuesIons? Filippo Valsorda @FiloSo/le hi@filippo.io