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
Diving into the Details with DTrace! (RubyConf ...
Search
Colin Jones
November 10, 2016
Programming
2
460
Diving into the Details with DTrace! (RubyConf 2016 edition)
Colin Jones
November 10, 2016
Tweet
Share
More Decks by Colin Jones
See All by Colin Jones
A Bug's Life: What if `select` is Broken After All?
trptcolin
0
150
Underestimated costs of microservice architectures
trptcolin
3
1.5k
FP vs. OOP: Beyond the Bikeshed
trptcolin
0
410
Diving into the Details with DTrace
trptcolin
3
510
Adopting FP: the good, the familiar, and the unknown
trptcolin
0
230
Finding out what's *really* going on, with DTrace!
trptcolin
1
370
Beyond top: Command-Line Monitoring on the JVM (ClojureRemote)
trptcolin
0
130
Beyond top: Command-Line Monitoring on the JVM (JavaOne 2015)
trptcolin
1
670
ZooKeeper: Wait-free coordination for Internet-scale systems
trptcolin
2
180
Other Decks in Programming
See All in Programming
iOSエンジニア向けの英語学習アプリを作る!
yukawashouhei
0
160
CSC305 Lecture 03
javiergs
PRO
0
230
ポスターセッション: 「まっすぐ行って、右!」って言ってラズパイカーを動かしたい 〜生成AI × Raspberry Pi Pico × Gradioの試作メモ〜
komofr
0
930
iOSDC.pdf
chronos2500
2
650
大規模アプリのDIフレームワーク刷新戦略 ~過去最大規模の並行開発を止めずにアプリ全体に導入するまで~
mot_techtalk
0
370
育てるアーキテクチャ:戦い抜くPythonマイクロサービスの設計と進化戦略
fujidomoe
1
150
Serena MCPのすすめ
wadakatu
4
880
CI_CD「健康診断」のススメ。現場でのボトルネック特定から、健康診断を通じた組織的な改善手法
teamlab
PRO
0
170
プログラマのための作曲入門
cheebow
0
530
複雑化したリポジトリをなんとかした話 pipenvからuvによるモノレポ構成への移行
satoshi256kbyte
1
750
Web フロントエンドエンジニアに開かれる AI Agent プロダクト開発 - Vercel AI SDK を観察して AI Agent と仲良くなろう! #FEC余熱NIGHT
izumin5210
3
370
AI Coding Meetup #3 - 導入セッション / ai-coding-meetup-3
izumin5210
0
390
Featured
See All Featured
Practical Tips for Bootstrapping Information Extraction Pipelines
honnibal
PRO
23
1.5k
Building a Modern Day E-commerce SEO Strategy
aleyda
43
7.7k
YesSQL, Process and Tooling at Scale
rocio
173
14k
GitHub's CSS Performance
jonrohan
1032
460k
Building Better People: How to give real-time feedback that sticks.
wjessup
368
20k
Visualization
eitanlees
148
16k
Creating an realtime collaboration tool: Agile Flush - .NET Oxford
marcduiker
32
2.2k
How To Stay Up To Date on Web Technology
chriscoyier
791
250k
The Success of Rails: Ensuring Growth for the Next 100 Years
eileencodes
46
7.6k
Statistics for Hackers
jakevdp
799
220k
Keith and Marios Guide to Fast Websites
keithpitt
411
22k
RailsConf & Balkan Ruby 2019: The Past, Present, and Future of Rails at GitHub
eileencodes
140
34k
Transcript
Diving into the details with DTrace! Colin Jones @trptcolin
systems applications
problems solutions
problems solutions
What even is DTrace?
DTrace is… strace
DTrace is… strace++
strace++ $ sudo dtrace -qn ' syscall:::entry { @[probefunc, execname]
= count(); } dtrace:::END { trunc(@, 10); printa(@); }'
strace++ $ sudo dtrace -qn 'syscall:::entry { @[probefunc, execname] =
count(); } dtrace:::END { trunc(@, 10); printa(@); }' ^C read Slack 1993 select Slack 2017 kevent_qos Slack 2660 kevent_qos WindowServer 2801 psynch_cvsignal Box Sync 2873 psynch_cvwait Box Sync 2873 select Box Sync 4780 madvise Slack 5783 bsdthread_ctl Slack 6910 workq_kernreturn Slack 10622
DTrace is… strace++ system resources
system resources $ sudo dtrace -qn ' vminfo:::maj_fault { @[execname]
= sum(arg0); }'
system resources $ sudo dtrace -qn 'vminfo:::maj_fault { @[execname] =
sum(arg0); }' ^C 2BUA8C4S2C.com.a 1 mdworker 2 Google Chrome 12 mds_stores 116 Google Chrome He 252
DTrace is… strace++ system resources statically-defined tracing
statically-defined tracing $ sudo dtrace -qn ' mysql*::: { @[probename]
= count(); } dtrace:::END { trunc(@, 10); printa(@); }'
statically-defined tracing $ sudo dtrace -qn 'mysql*::: { @[probename] =
count(); } dtrace:::END { trunc(@, 10); printa(@); }' ^C query-exec-start 3 query-parse-done 3 query-parse-start 3 query-start 3 select-done 3 select-start 3 net-read-done 18 net-read-start 18 net-write-done 18 net-write-start 18
DTrace is… strace++ system resources statically-defined tracing dynamic tracing
Dynamic tracing $ sudo dtrace -qn ' fbt:mach_kernel::entry { self->in
= timestamp; } fbt:mach_kernel::return /self->in/ { @ = quantize(timestamp - self->in) self->in = 0; }'
Dynamic tracing $ sudo dtrace -n 'fbt:mach_kernel::entry { self->in =
timestamp; } fbt:mach_kernel::return /self->in/ { @ = quantize(timestamp - self->in); self->in = 0; }' dtrace: description 'fbt:mach_kernel::entry ' matched 24482 probes ^C value ------------- Distribution ------------- count 256 | 0 512 |@@@@@@@@@@@@@@@@@@ 13521 1024 |@@@@@@@@@@@@@@@@@@@ 14961 2048 |@@@ 2172 4096 | 79 8192 | 71 16384 | 7 32768 | 3 65536 | 3 131072 | 2 262144 | 0
DTrace is… strace++ system resources statically-defined tracing dynamic tracing
Weird slowness… it happens
Slooooooooow tests (…sometimes)
Multiple tests, multiple machines
Affects some teammates worse than others
annoying productivity-sapping stressful
Hypotheses?
Use DTrace!
Rule out the usual suspect(s)? ruby*:::gc-mark-begin { self->mark_begin = timestamp;
} ruby*:::gc-mark-end /self->mark_begin/ { self->duration = (timestamp - self->mark_begin) / 1000000; self->phase = "mark"; self->mark_begin = 0; } ruby*:::gc-*-end /self->duration/ { printf("%-8d %-8d %-8s\n", pid, self->duration, self->phase); }
Garbage collection? $ sudo ruby-gc.d PID TIME(ms) PHASE 30152 7
mark 30152 33 mark 30152 7 mark 30152 9 mark 30152 38 mark 30152 17 mark 30152 16 mark 30152 17 mark 30152 22 mark 30152 71 mark 30152 22 mark 30152 6 sweep 30152 3 sweep 30152 4 sweep 30152 1 sweep 30152 23 mark
System resources CPU Memory Disk Network
CPU? $ sudo dtrace -qn ' profile-997 { @[execname] =
count(); } '
CPU? $ sudo dtrace -qn 'profile-997 { @[execname] = count();
}' ^C [...] Box Sync 3 Google Drive 3 ruby 3 Google Chrome 9 systemstatsd 11 iTerm 14 Google Chrome He 24 WindowServer 25 hidd 26 Box Sync Monitor 47 kernel_task 9527
CPU? $ sudo dtrace -qn ' profile-997 /execname=="kernel_task"/ { @[stack()]
= count(); } '
CPU? $ sudo dtrace -qn 'profile-997 /execname=="kernel_task"/ { @[stack()] =
count(); }' ^C [...] kernel`0xffffff80010f3d30+0x358 kernel`0xffffff800158d890+0x793 kernel`kevent+0x44 kernel`unix_syscall64+0x251 kernel`hndl_unix_scall64+0x16 116 kernel`processor_idle+0x107 121 kernel`machine_idle+0x2e0 kernel`call_continuation+0x17 82967
CPU $ sudo dtrace -qn 'profile-997 { @[execname] = count();
}' ^C [...] Box Sync 3 Google Drive 3 ruby 3 Google Chrome 9 systemstatsd 11 iTerm 14 Google Chrome He 24 WindowServer 25 hidd 26 Box Sync Monitor 47 kernel_task 9527
System resources CPU Memory Disk Network
Network connections https://github.com/brendangregg/DTrace-book-scripts/blob/master/Chap6/soconnect_mac.d
Network connections https://github.com/brendangregg/DTrace-book-scripts/blob/master/Chap6/soconnect_mac.d $ sudo soconnect_mac.d PID PROCESS FAM ADDRESS
PORT LAT(us) RESULT 88161 ruby 2 127.0.0.1 5432 144 Success 88161 ruby 2 127.0.0.1 5432 171 Success 88161 ruby 2 127.0.0.1 5432 150 Success 114 AirPlayXPCHelper 2 192.168.1.27 7000 1762 In progress 88161 ruby 2 127.0.0.1 5432 141 Success 88161 ruby 2 127.0.0.1 5432 179 Success 88161 ruby 2 127.0.0.1 5432 137 Success 88161 ruby 2 72.52.4.119 80 29977 Success 88161 ruby 2 72.52.4.119 80 42121 Success 88161 ruby 2 72.52.4.119 80 29471 Success 88161 ruby 2 72.52.4.119 80 29360 Success 88161 ruby 2 72.52.4.119 80 34731 Success 88161 ruby 2 72.52.4.119 80 28824 Success
DNS pid$target::getaddrinfo:entry { self->start = timestamp; self->host = copyinstr(arg0); }
pid$target::getaddrinfo:return /self->start/ { this->now = (timestamp - timezero) / 1000000; this->time = (timestamp - self->start) / 1000000; printf("%-8d %-8d %s\n", this->now, this->time, self->host); self->start = 0; self->host = 0; }
DNS $ sudo dns_latency.d -p 41161 Password: TICK ms HOST
74450 274 redclay.local 74734 0 redclay.local 105006 30075 someplace.com 145171 30075 someplace.com 145191 1 redclay.local 145192 0 redclay.local 177055 0 example.com 252314 2 redclay.local 252315 0 redclay.local 284392 0 example.com
Now we know what to fix!
What did we learn?
Specific vs. General
DTrace is… strace++ system resources statically-defined tracing dynamic tracing
You can do it!
Where can we learn more?
Brendan Gregg's blog: http://www.brendangregg.com/dtrace.html The DTrace guide http://dtrace.org/guide DTrace: Dynamic
Tracing in Oracle Solaris, Mac OS X, and FreeBSD http://amzn.to/2bqBczw Read
Scripts that ship with OS X find /usr/bin -name "*.d"
more DTrace scripts https://github.com/brendangregg/DTrace-book-scripts Examples
DTrace: not just performance performance: not just DTrace Extrapolate
Try it out!
DTrace & SIP on El Capitan: http://internals.exposed/blog/dtrace-vs-sip.html Julia Evans' strace
zine: http://jvns.ca/blog/2015/04/14/strace-zine/ Jeff Hodges "Notes on Distributed Systems for Young Bloods": http://bit.ly/2b2mxLf Brendan Gregg's blog: http://www.brendangregg.com/dtrace.html The DTrace guide: http://dtrace.org/guide DTrace book: http://amzn.to/2bqBczw DTrace Toolkit: https://github.com/opendtrace/toolkit DTrace book scripts: https://github.com/brendangregg/DTrace-book-scripts SystemTap (Linux): https://sourceware.org/systemtap/ bcc: https://github.com/iovisor/bcc Resources
Thanks! Colin Jones @trptcolin
[email protected]