パフォーマンス分析のススメ

Transcript

1. パフォーマンス分析のススメ strace/perf/bpftrace の使い方
2. パフォーマンス分析
3. パフォーマンス分析の目的 • システムやアプリケーションがどのようにコンピュータ資源 （CPU、メモリ、ディスク、ネットワークなど）を使っているか 測定・可視化・理解するため ◦ ボトルネックの特定 ◦ システムやアプリケーションの最適化 ◦ スケーラビリティの評価 ◦ 運用や保守の安定化 ◦ コスト削減 • なぜ重要か？ ◦ 限られたリソースで効率よく動かすには、どこを改善すべきか客観的 事実で判断する必要がある ◦ 勘や経験だけでは最適化ポイントを見誤る危険がある
4. パフォーマンス分析のプロセス • 現状計測 → 問題点特定 → 改善案実施 → 再計測 • 目的に合ったツールを選ぶ ◦ e.g. ボトルネックを知るために top を眺めているだけ では不十分 • 成功のためのポイント ◦ 数値や事実ベースでアプローチする重要性 ◦ 1回きりでなく「継続的」な計測・改善が大事 ◦ 開発段階・運用段階どちらでも有効
5. パフォーマンス分析 まとめ • パフォーマンス分析はシステムの現状把握と最適化のために不 可欠 ◦ ボトルネックの特定 → 効率的な対策 → 品質向上・安定運用 につながる ◦ 効率的な対策を打つためにも分析が必要 • 各種ツール（perf, strace, top, sar など）を目的に応じて活用する ◦ 現代だと prometheus などでメトリクスを集めることも大事 • 数値や事実に基づいて“継続的に”改善に取り組むことが大切 ◦ 勘や経験での改善が効果的であったかの測定にも有用
6. コマンド解説
7. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
8. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
9. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
10. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
11. strace の使い方 (1) • コマンドの実行をトレースできる ◦ strace CMD ◦ kernel がどのようなシステムコールを 実行しているのかわかる • さらに詳細のトレースができる ◦ strace -v CMD $ strace ls -l /tmp execve("/usr/bin/ls", ["ls", "-l", "/tmp"], 0x7fff240e0340 /* 27 vars */) = 0 brk(NULL) = 0x651f23c14000 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3c58f8000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=61535, ...}) = 0 mmap(NULL, 61535, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb3c58e8000 close(3) = 0 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832 fstat(3, {st_mode=S_IFREG|0644, st_size=174472, ...}) = 0 mmap(NULL, 181960, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb3c58bb000 mmap(0x7fb3c58c1000, 118784, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7fb3c58c1000 mmap(0x7fb3c58de000, 24576, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0x7fb3c58de000 mmap(0x7fb3c58e4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x29000) = 0x7fb3c58e4000 mmap(0x7fb3c58e6000, 5832, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb3c58e6000 close(3) = 0
12. strace の使い方 (2) • 既に動作しているプロセスにアタッチできる ◦ strace -p PID ◦ 既存のプロセスが何をやっているかをトレースできる $ sudo strace -p 7938 strace: Process 7938 attached ppoll([{fd=4, events=POLLIN}, {fd=4, events=0}, {fd=11, events=POLLIN}, {fd=7, events=POLLIN}], 4, NULL, [], 8) = 1 ([{fd=11, revents=POLLIN}]) rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0 read(11, "strace: Process 7938 attached\r\np"..., 32768) = 228 getrandom("\x44\x68\x6c\xac\x9d\x90\xa5\x7d\x08\x88", 10, 0) = 10 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 ppoll([{fd=4, events=POLLIN}, {fd=4, events=POLLOUT}, {fd=11, events=POLLIN}, {fd=7, events=POLLIN}], 4, NULL, [], 8) = 2 ([{fd=4, revents=POLLOUT}, {fd=11, revents=POLLIN}]) rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0 read(11, "read(11, \"strace: Process 7938 a"..., 32768) = 405 write(4, ">O\300sT@\265[\24\274Q\336\225\232m\333j\376\222\2328:\343\251,\23`#\2523J\366"..., 268) = 268 getrandom("\xe5\x4f\xed\x03\xd0\x0a\x8f\xf5\xd1", 9, 0) = 9 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 ppoll([{fd=4, events=POLLIN}, {fd=4, events=POLLOUT}, {fd=11, events=POLLIN}, {fd=7, events=POLLIN}], 4, NULL, [], 8) = 2 ([{fd=4, revents=POLLOUT}, {fd=11, revents=POLLIN}]) rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0 read(11, "read(11, \"read(11, \\\"strace: Pro"..., 32768) = 504 write(4, "m\36\274\202\321\246c\243\330\305t\333\376u\311B&,Z#\220\216]\366i\332\3244q\37\315\34"..., 444) = 444 getrandom("\xaf\x3c\x36\x18\xf6\x38", 6, 0) = 6 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
13. strace の使い方 (3) • 特定のシステムコールに絞る ◦ strace -e SYSCALL CMD ◦ 特定の命令がどのくらいされたのか観測できる • 例： ◦ ls コマンドに対して openat が呼ばれたときを出力 $ strace -e openat ls openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, ".", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 +++ exited with 0 +++
14. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
15. perf とは？ • パフォーマンス計測ツールの1つ • システムやアプリケーションの挙動を 詳細に分析するためのツール • strace との違い ◦ 強力なパフォーマンスカウンタ機能 ◦ 解析・可視化 ▪ e.g. フレームグラフの作成 • その他のパフォーマンスツール ◦ top/htop ◦ vmstat/iostat/mpstat ◦ strace/ltrace ◦ blktrace/bpftrace
16. よく使われる perf サブコマンド • perf stat ◦ パフォーマンスカウンタをまとめて表示する • perf record ◦ どの関数や命令に CPU 時間が消費されたかという詳細な プロファイルデータを記録 • perf report ◦ perf record で取得したデータを解析・可視化する • perf script／flamegraph ◦ perf データをテキストに変換／フレームグラフ化 • perf top ◦ top コマンドのようなインタフェースでプロファイルデータをリ アルタイム表示する
17. perf stat • 指定したコマンドの実行中に、CPUサイクル数、命令数、 キャッシュミスなど、システム全体のパフォーマンスカウンタを まとめて計測して表示するコマンド ◦ perf stat CMD ◦ perf stat -p PID $ sudo perf stat -p 7938 ^C Performance counter stats for process id '7938': 0.08 msec task-clock # 0.000 CPUs utilized 1 context-switches # 12.120 K/sec 0 cpu-migrations # 0.000 /sec 0 page-faults # 0.000 /sec 78,543 cycles # 0.952 GHz 31,233 stalled-cycles-frontend # 39.77% frontend cycles idle 44,931 instructions # 0.57 insn per cycle # 0.70 stalled cycles per insn 9,590 branches # 116.228 M/sec 1,072 branch-misses # 11.18% of all branches 1.206650298 seconds time elapsed $ sudo perf stat ls Performance counter stats for 'ls': 1.81 msec task-clock # 0.643 CPUs utilized 0 context-switches # 0.000 /sec 0 cpu-migrations # 0.000 /sec 90 page-faults # 49.791 K/sec 2,586,280 cycles # 1.431 GHz 908,649 stalled-cycles-frontend # 35.13% frontend cycles idle 2,033,136 instructions # 0.79 insn per cycle # 0.45 stalled cycles per insn 419,010 branches # 231.812 M/sec 46,308 branch-misses # 11.05% of all branches 0.002813227 seconds time elapsed 0.000983000 seconds user 0.001967000 seconds sys
18. perf record • システムの実行中に、どの関数や命令にCPU時間が消費さ れたかという詳細なプロファイルデータを記録する ◦ perf record -F 99 -a --call-graph dwarf -o FILE -- sleep 30 ▪ -F 99: サンプリング頻度 1秒間に99回 ▪ -a: 全 CPU 上の全プロセスを対象 ▪ --call-graph dwarf: スタックトレースを DWARF デバッグ 情報を使って記録 ▪ -o FILE: 記録結果を FILE というファイル名で保存 • ファイル名を指定しない場合は perf.data ▪ --: ここ以降は実行コマンド指定 ▪ sleep 30: 30秒間記録させるために sleep 30 を実行
19. perf report • perf record で取得したプロファイルデータを 解析・可視化するコマンド ◦ perf report -i FILE --call-graph=graph,5 (--stdio) (-C CPUID) ▪ --call-graph=graph,5: 5階層までの呼び出しグラフ ▪ --stdio: インタラクティブではなく標準出力にテキストで出力 ▪ -C CPUID: 特定のコアの perf のみを出力
20. perf script • perf record で取得したプロファイルデータをテキスト形式に 変換するコマンド ◦ フレームグラフを作成する際には必須 ◦ perf script -i FILE > out.txt $ perf script -i FILE perf 11529 [000] 167559.583061: 16 cycles:P: ffffffff8a3986cd [unknown] ([kernel.kallsyms]) ffffffff8a3a61b0 [unknown] ([kernel.kallsyms]) ffffffff8a3a657f [unknown] ([kernel.kallsyms]) ffffffff8a3a6698 [unknown] ([kernel.kallsyms]) ffffffff8a3a6cd6 [unknown] ([kernel.kallsyms]) ffffffff8a3a6f23 [unknown] ([kernel.kallsyms]) ffffffff8a39d20e [unknown] ([kernel.kallsyms]) ffffffff8a3993f7 [unknown] ([kernel.kallsyms]) ffffffff8a22db81 [unknown] ([kernel.kallsyms]) ffffffff8a22dd73 [unknown] ([kernel.kallsyms]) ffffffff8a39ddea [unknown] ([kernel.kallsyms]) ffffffff8a39def6 [unknown] ([kernel.kallsyms]) ffffffff8a3983b0 [unknown] ([kernel.kallsyms]) ffffffff8a3adc26 [unknown] ([kernel.kallsyms]) ffffffff8a3ae218 [unknown] ([kernel.kallsyms]) ffffffff8a50fc93 [unknown] ([kernel.kallsyms]) ffffffff8a006b63 [unknown] ([kernel.kallsyms]) ffffffff8b23e9ef [unknown] ([kernel.kallsyms]) ffffffff8b400130 [unknown] ([kernel.kallsyms]) 7c4a02124ded ioctl+0x3d (/usr/lib/x86_64-linux-gnu/libc.so.6) 6115abdad37a perf_evsel__ioctl+0x7a (/usr/lib/linux-tools-6.8.0-60/perf) 6115abdad3bb perf_evsel__run_ioctl+0x3e (/usr/lib/linux-tools-6.8.0-60/perf) 6115abdad41a perf_evsel__enable_cpu+0x2d (/usr/lib/linux-tools-6.8.0-60/perf) 6115abc830d1 __evlist__enable.constprop.0+0x111 (/usr/lib/linux-tools-6.8.0-60/perf) 6115abbc2463 __cmd_record.constprop.0+0x2803 (/usr/lib/linux-tools-6.8.0-60/perf)
21. flamegraph • perf データをフレームグラフに変換できるツール ◦ https://github.com/brendangregg/Flamegraph $ git clone https://github.com/brendangregg/Flamegraph $ cd Flamegraph // Flamegraph 形式に変換 $ ./stackcollapse-perf.pl ../out.txt > ../out.folded // SVG 画像としてフレームグラフを生成 ./flamegraph.pl ../out.folded > ../flamegraph.svg
22. perf top • top コマンドのようなインタフェースでプロファイルデータをリアルタ イム表示するコマンド ◦ perf top (-p PID) ▪ -p PID: 特定のプロセスに関するものだけを可視化
23. 今回紹介するコマンド • strace ◦ プロセスがどんなシステムコールを実行しているのかを追跡 するツール • perf ◦ プログラムやシステム全体のパフォーマンスを分析するため のツール • bpftrace ◦ eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール
24. bpftrace とは？ • eBPF を利用して、kernel やアプリケーションの挙動をリアルタ イムにトレースできるツール • 利用シーン ◦ パフォーマンスチューニング ▪ e.g. なぜこの処理が遅い？ ◦ トラブル調査 ▪ e.g. 謎の I/O 遅延を解明したい ◦ セキュリティトラッキング ▪ e.g. • root 以外からの /etc/shadow アクセスを監視 • setuid/setgid を頻繁に変更するプロセスの検出
25. bpftrace: eBPF とは？ • Linux カーネル内で任意のプログラム安全・高速に動かすため の機構 • カーネルを再起動せずに動的な拡張・観測・制御が可能 • eBPFの使われている主な例 ◦ ネットワークパケットのフィルタリング・監視 ▪ kubernetes CNI Cilium ▪ Katran (Facebook の L4 SW LB) ◦ 性能モニタリング・トレーシング ◦ セキュリティ ▪ システムコール監視・Sandbox・攻撃検知 ◦ オブザーバビリティ（分散トレーシングとか） ◦ Linuxカーネルの新機能・強化 ◦ コンテナやクラウド基盤での高度な制御
26. bpftrace: probe と action • probe: 観察したい「場所・イベント」を指定 ◦ 関数の入口や出口 ◦ システムイベント • action: その時に実行する処理 • bpftrace スクリプトの基本構文 ◦ 構文は AWK に似ている ◦ probe {action} ▪ e.g. • kprobe:vfs_read { printf("read! pid=%d\n", pid); }
27. bpftrace: 代表的な probe プローブ 例 主な用途 kprobe kprobe:vfs_read カーネル関数入口 kretprobe kretprobe:vfs_read カーネル関数出口 tracepoint tracepoint:syscalls:sys_enter_openat カーネルイベント uprobe uprobe:/bin/bash:main ユーザバイナリ関数入口 uretprobe uretprobe:/bin/bash:main ユーザバイナリ関数出口 software software:faults:1 ソフトウェアイベント hardware hardware:cache-misses:100000 ハードウェアイベント interval interval:s:5 一定間隔ごとに発動
28. bpftrace: 代表的なビルドイン変数 変数 例 説明 pid 75919 プロセスID tid 75919 スレッドID cpu 2 CPU ID uid 1000 ユーザーID comm sshd コマンド名 nsecs 699003134725209 カーネル起動からのナノ秒数 args /etc/hostname (args->filename) トレースポイント引数構造体
29. bpftrace: 代表的なビルドイン変数 変数 例 説明 pid 75919 プロセスID tid 75919 スレッドID cpu 2 CPU ID uid 1000 ユーザーID comm sshd コマンド名 nsecs 699003134725209 カーネル起動からのナノ秒数 args /etc/hostname (args->filename) トレースポイント引数構造体 対応するトレースポイント引数は -lv でトレースポイント指定することで確認できる （対応しているのは tracepoint probe のみ） # bpftrace -lv 'tracepoint:syscalls:sys_enter_openat' tracepoint:syscalls:sys_enter_openat int __syscall_nr int dfd const char * filename int flags umode_t mode
30. • kprobe で vfs_read が呼ばれたときの comm, pid, tid • tracepoint で openat されたときの pid, filename bpftrace: 実行例 (1) $ sudo bpftrace -e 'kprobe:vfs_read { printf("comm=%s pid=%d tid=%d\n", comm, pid, tid); }' Attaching 1 probe... comm=sshd pid=75788 tid=75788 comm=sudo pid=77360 tid=77360 comm=sudo pid=77360 tid=77360 ^Ccomm=sudo pid=77360 tid=77360 $ sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("pid=%d filename=%s\n", pid, str(args->filename)); }' Attaching 1 probe... pid=77246 filename=/etc/ld.so.cache pid=77246 filename=/lib/x86_64-linux-gnu/libc.so.6 pid=77246 filename= pid=77246 filename=/etc/hostname
31. • kprobe で cat のとき • / を使ったフィルタ構文でも書ける bpftrace: 実行例 (2) $ sudo bpftrace -e 'kprobe:vfs_read / comm == "cat" / {printf("comm=%s pid=%d tid=%d\n", comm, pid, tid);}' Attaching 1 probe... comm=cat pid=77357 tid=77357 comm=cat pid=77357 tid=77357 comm=cat pid=77357 tid=77357 comm=cat pid=77357 tid=77357 comm=cat pid=77357 tid=77357 $ sudo bpftrace -e 'kprobe:vfs_read { if (comm == "cat") {printf("comm=%s pid=%d tid=%d\n", comm, pid, tid);}}' Attaching 1 probe... comm=cat pid=77387 tid=77387 comm=cat pid=77387 tid=77387 comm=cat pid=77387 tid=77387 comm=cat pid=77387 tid=77387
32. bpftrace: マップ関数 (1) • bpftrace の「マップ」は、観測したデータの集計・統計や、特定 の条件ごとの値の記録・可視化に使われる ◦ プログラミングでいうハッシュマップ・連想配列に近い • @[key] = 関数や演算; ◦ マップ @[key] に対して値を代入・加算・集計できる
33. bpftrace: マップ関数 (2) マップ関数 説明 avg 平均を計算 clear 値をクリア、マップのリセットに使う count カウント hist 対数ヒストグラム lhist 線形ヒストグラム stats count, avg, sum を呼び出し sum 合計を計算
34. bpftrace: マップ関数の例 (1) • プロセス名ごとに vfs_read 回数をカウント ◦ bpftrace -e 'kprobe:vfs_read {@[comm] = count();}' $ sudo bpftrace -e 'kprobe:vfs_read {@[comm] = count();}' Attaching 1 probe... ^C @[systemd-network]: 2 @[sudo]: 2 @[bash]: 5 @[cat]: 5 @[sshd]: 8
35. bpftrace: マップ関数の例 (2) • プロセスIDxファイルディスクリプタごとに read 時のサイズを合 計 ◦ bpftrace -e 'kprobe:vfs_read {@[pid, arg0] = sum(arg2);}' $ sudo bpftrace -e 'kprobe:vfs_read {@[pid, arg0] = sum(arg2);}' Attaching 1 probe... ^C @[77793, -114411036765696]: 65536 @[77793, -114411036769536]: 65536 @[75872, -114410773869312]: 262144 @[75788, -114410665909504]: 262144
36. bpftrace: マップ関数の例 (3) • read のバイト数の分布をヒストグラム化 ◦ bpftrace -e 'kprobe:vfs_read {@dist = hist(arg2);}' $ sudo bpftrace -e 'kprobe:vfs_read {@dist = hist(arg2);}' Attaching 1 probe... ^C @dist: [8, 16) 9 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ | [16, 32) 0 | | [32, 64) 0 | | [64, 128) 0 | | [128, 256) 0 | | [256, 512) 5 |@@@@@@@@@@@@@@@@@@@@ | [512, 1K) 13 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@| [1K, 2K) 6 |@@@@@@@@@@@@@@@@@@@@@@@@ | [2K, 4K) 0 | | [4K, 8K) 6 |@@@@@@@@@@@@@@@@@@@@@@@@ | [8K, 16K) 0 | | [16K, 32K) 5 |@@@@@@@@@@@@@@@@@@@@ | [32K, 64K) 0 | | [64K, 128K) 2 |@@@@@@@@ | [128K, 256K) 0 | | [256K, 512K) 5 |@@@@@@@@@@@@@@@@@@@@ |
37. bpftrace: マップ関数の例 (4) • ページフォールトを10秒ごとにコマンド, pid 表示 ◦ (100 で 1 count としている) ◦ bpftrace -e 'software:faults:100 { @[comm, pid] = count(); } interval:s:10 { print(@); clear(@); printf("---------------\n");}' $ sudo bpftrace -e 'software:faults:100 { @[comm, pid] = count(); } interval:s:10 { print(@); clear(@); printf("---------------\n");}' Attaching 2 probes... @[bash, 77894]: 1 @[bash, 75873]: 1 --------------- @[cat, 77903]: 1 @[bash, 77905]: 1 @[cat, 77901]: 1 @[cat, 77908]: 1 @[cat, 77898]: 1 @[bash, 77895]: 1 @[cat, 77904]: 1 @[bash, 77897]: 1 @[cat, 77907]: 1 @[cat, 77900]: 1 @[cat, 77902]: 1 @[cat, 77906]: 1 @[cat, 77899]: 1 @[bash, 75873]: 10 ---------------
38. bpftrace: マップ関数の例 (5) • LLC(L3) キャッシュミスを10秒ごとにコマンド, pid 表示 ◦ (100k で 1 count としている) ◦ bpftrace -e 'hardware:cache-misses:100000 { @[comm, pid] = count(); } interval:s:10 { print(@); clear(@); printf("---------------\n"); }' $ sudo bpftrace -e 'hardware:cache-misses:100000 { @[comm, pid] = count(); } interval:s:10 { print(@); clear(@); printf("---------------\n"); }' Attaching 2 probes... @[rcuop/1, 29]: 1 @[swapper/1, 0]: 1 @[CPU 2/KVM, 12009]: 2 @[CPU 1/KVM, 12009]: 2 @[swapper/0, 0]: 38 --------------- @[CPU 3/KVM, 12009]: 1 @[swapper/5, 0]: 1 @[swapper/94, 0]: 1 @[CPU 2/KVM, 12009]: 1 @[CPU 0/KVM, 12009]: 1 @[ksmd, 724]: 1 @[swapper/35, 0]: 1 @[kworker/75:1, 69795]: 1 @[swapper/84, 0]: 1 @[swapper/0, 0]: 42 ---------------
39. bpftrace: カリキュラム内のコマンドについて • bpftrace -e 'tracepoint:kvm:kvm_exit,tracepoint:kvm:kvm_entry { @[probe,comm,tid] = count(); } interval:s:1 { print(@); clear(@); }' ◦ bpftrace -e ◦ 'tracepoint:kvm:kvm_exit,tracepoint:kvm:kvm_entry ▪ トレースポイントに kvm_exit, kvm_entry を指定 ◦ { @[probe,comm,tid] = count(); } ▪ probe(kvm_exit,kvm_entry), コマンド, スレッド ID でマッ プ ◦ interval:s:1 ▪ 1秒ごとに ◦ { print(@); clear(@); }' ▪ マップの内容を表示、マップをクリア
40. bpftrace まとめ • bpftraceは強力な動的トレーシングツール ◦ シンプルなスクリプトでイベントを素早く取得・集計 • 主な特長 ◦ 豊富なプローブ（kprobe, tracepoint, software, hardware, interval など） ◦ ビルトイン変数＆マップ（@[]）で強力な集計・分析が可能 ◦ パフォーマンス解析・トラブルシュート・観察に活躍 • 基本の使い方 ◦ 「監視したいイベントにフック」→「マップで情報取得」 →「printfや集計で可視化」 ◦ わからないことがあったらマニュアルへ ▪ https://github.com/bpftrace/bpftrace/blob/master/man/ad oc/bpftrace.adoc
41. EOP
42. 参考資料 • Linux perf Examples ◦ https://www.brendangregg.com/perf.html • bpftrace(8) Manual Page ◦ https://github.com/bpftrace/bpftrace/blob/master/man/ado c/bpftrace.adoc