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 @ GolangUK 2017
Filippo Valsorda
August 17, 2017
Programming
0
830
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
1.6k
Le note cifrate di Antonio Marzi
filosottile
1
210
Why cgo is slow @ CapitalGo 2018
filosottile
2
3.3k
Squeezing a key through a carry bit @ 34c3
filosottile
0
1.3k
Calling Rust from Go, without cgo @ GothamGo 2017
filosottile
1
1.9k
Encrypting the Internet with Go @ GopherCon 2017
filosottile
9
2.3k
You, latency and profiling @ GopherCon India 2017
filosottile
13
3.2k
TLS 1.3 @ 33c3
filosottile
4
5.9k
Stealing Bitcoin With Math - HOPE XI
filosottile
13
29k
Other Decks in Programming
See All in Programming
Amebaブログの会員画面システム刷新の道程
ryotasugawara
1
200
「自律型開発組織」を目指すCTOの、試行錯誤の記録
ar_tama
1
200
Git Rebase
bkuhlmann
10
1.2k
ECテックカンファレンス2023
kspace
1
160
ちょうぜつ改め21世紀ふつうのソフトウェア設計
tanakahisateru
7
5.9k
社会人 20 年目エンジニア、発信で技術学びなおしてる話
e99h2121
1
130
Swift Observation
shiz
3
240
【DevFest & ADS JP 22】チームで導入する
[email protected]
おいしい健康
kako351
0
210
10年以上続くプロダクトの フロントエンド刷新プロジェクトのふりかえり
yotahada3
2
290
ECS Service Connectでマイクロサービスを繋いでみた
xblood
0
510
Above All, Make It Fun! #fjordbootcamp / make it fun
kakutani
6
550
Amazon QuickSightのアップデート -re:Invent 2022の復習&2022年ハイライト-
shogo452
0
200
Featured
See All Featured
Embracing the Ebb and Flow
colly
75
3.6k
Build The Right Thing And Hit Your Dates
maggiecrowley
22
1.4k
Understanding Cognitive Biases in Performance Measurement
bluesmoon
2
390
In The Pink: A Labor of Love
frogandcode
132
21k
Unsuck your backbone
ammeep
659
56k
Designing on Purpose - Digital PM Summit 2013
jponch
108
5.9k
How STYLIGHT went responsive
nonsquared
89
4.2k
XXLCSS - How to scale CSS and keep your sanity
sugarenia
236
1.1M
Dealing with People You Can't Stand - Big Design 2015
cassininazir
351
21k
Responsive Adventures: Dirty Tricks From The Dark Corners of Front-End
smashingmag
239
19k
実際に使うSQLの書き方 徹底解説 / pgcon21j-tutorial
soudai
44
14k
How To Stay Up To Date on Web Technology
chriscoyier
779
250k
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
[email protected]
filippo.io