Upgrade to Pro
— share decks privately, control downloads, hide ads and more …
Speaker Deck
Speaker Deck
PRO
Sign in
Sign up for free
You, latency and profiling @ GopherCon India 2017
Filippo Valsorda
February 25, 2017
Programming
13
3.1k
You, latency and profiling @ GopherCon India 2017
Filippo Valsorda
February 25, 2017
Tweet
Share
More Decks by Filippo Valsorda
See All by Filippo Valsorda
Asynchronous networking @ GopherCon 2018
filosottile
3
1.5k
Le note cifrate di Antonio Marzi
filosottile
1
190
Why cgo is slow @ CapitalGo 2018
filosottile
2
3k
Squeezing a key through a carry bit @ 34c3
filosottile
0
1.1k
Calling Rust from Go, without cgo @ GothamGo 2017
filosottile
1
1.7k
You, latency and profiling @ GolangUK 2017
filosottile
0
770
Encrypting the Internet with Go @ GopherCon 2017
filosottile
9
2.2k
TLS 1.3 @ 33c3
filosottile
4
5.6k
Stealing Bitcoin With Math - HOPE XI
filosottile
13
28k
Other Decks in Programming
See All in Programming
Oculus Interaction SDK 概説 / xrdnk-caunity-LT4
xrdnk
0
230
TextPruner による大規模言語モデルの軽量化 / Large language model pruning using TextPruner
misawann
0
160
확장 가능한 테라폼 코드 관리 (Scalable Terraform Code Management)
posquit0
1
320
dbtとBigQueryで始めるData Vault入門
kazk1018
0
190
あなたの会社の古いシステム、なんとかしませんか?~システム刷新から考えるDX化への道筋とバリエーション~/webinar20220420-grapecity
grapecity_dev
0
130
Groovy Roadmap
paulk
7
13k
実録mruby組み込み体験
coe401_
0
110
「新卒だけ」じゃない!学び直しを支えるミクシィの技術研修を紹介
mixi_engineers
PRO
0
100
Node.js 最新動向 TFCon 2022
yosuke_furukawa
PRO
6
2.9k
WindowsコンテナDojo:第2回 Windowsコンテナアプリのビルド、公開、デプロイ
oniak3ibm
PRO
0
150
Kotlin KSP - Intro
taehwandev
1
490
クリエイティブ系のウェブサイト制作で役立つCSS技法 / CSS for develop creative website
clockmaker
2
1.6k
Featured
See All Featured
JavaScript: Past, Present, and Future - NDC Porto 2020
reverentgeek
37
3.2k
Large-scale JavaScript Application Architecture
addyosmani
499
110k
Code Reviewing Like a Champion
maltzj
506
37k
Infographics Made Easy
chrislema
233
17k
How New CSS Is Changing Everything About Graphic Design on the Web
jensimmons
212
11k
CSS Pre-Processors: Stylus, Less & Sass
bermonpainter
349
27k
Producing Creativity
orderedlist
PRO
333
37k
What's new in Ruby 2.0
geeforr
336
30k
Docker and Python
trallard
27
1.5k
Rails Girls Zürich Keynote
gr2m
86
12k
Responsive Adventures: Dirty Tricks From The Dark Corners of Front-End
smashingmag
237
19k
What’s in a name? Adding method to the madness
productmarketing
11
1.5k
Transcript
You, latency and profiling Filippo Valsorda — @FiloSottile
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 milliseconds
A fast website… … can handle many requests at the
same time … or loads in a few milliseconds
A fast API… … can handle many clients at the
same time … or answers in a few milliseconds
Fast is… Throughput and Latency
CPU profiling -cpuprofile /debug/pprof/profile
CPU profiling SIGPROF
runtime/proc.go
CPU profiling http.Handler 1 Running on CPU http.Handler 2 I/O
I/O http.Handler 3 I/O http.Handler 4 I/O
CPU profiling Running on CPU I/O I/O I/O I/O http.Handler
1 http.Handler 2 http.Handler 3 http.Handler 4
CPU profiling I/O Observed latency http.Handler 1
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 execution events: • goroutine
scheduling, blocking • syscalls, network, I/O • garbage collection
The tracer • log files are BIG • 25% overhead
(after Go 1.7) • symbols are embedded (Go 1.7)
Trace vs. profile • Full event context • Goroutine metadata
and history • Discrete events, not samples
The tracer import "runtime/trace" import "net/http/pprof" /debug/pprof/trace?seconds=5
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
None
Writing 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) }
if _, ok := childG[ev.G]; !ok && !filterStack(ev.Stk, re) {
continue }
tracefocus tracefocus -filter=ServeHTTP trace.out > net.pprof github.com/FiloSottile/tracetools
None
None
Build more tools! • Focus on goroutine number • Aggregate
all blocking types • Visualizations • …
tracehist tracehist -filter=Close trace.out github.com/FiloSottile/tracetools
None
Build more tools! Profile latency!
Questions? Filippo Valsorda @FiloSottile filippo@cloudflare.com