ablog

不器用で落着きのない技術者のメモ

perf + Flame Graphs で Linux カーネル内のボトルネックを特定する

Linux perf

Linuxでddで1GBのファイルを作成し perf でプロファイリングし、Flame Graph (炎のグラフ？)にして可視化したものです。
Flame Graphs は perf(Linux)、SystemTap(Linux)、DTrace(Solaris、Oracle Linux(UEK)、Mac OS X、FreeBSD)、XPerf.exe(Windows) などでのプロファイリング結果を可視化して最も使われているコードパスを早く正確に特定することができます。実体はプロファイリング結果をグラフ(SVG)に変換する Perl スクリプトです。
下から上に行くほどコールスタックが深く、左から関数名のアルファベット順でソートされています。一番上で横幅が広い関数がCPUを長く使っています。今回は "_aesni_enc1" つまり暗号化がボトルネックになっていることがわかります。

  • システム全体の情報を取得してグラフにしているので、dd 以外にLinuxのカーネルスレッド（kworker）などが見えます。
  • dd で書込みしているが、カーネルスレッド（kworker）で暗号化してそうで "_aesni_enc1" で最もCPUを使っていることがわかります。
  • 合計して上位を見つけるアプローチのため、瞬間的なスパイクを見つけるのには向いていません。


Flame Graphs の作者の Brendan Gregg は Sun、Oracle、Joyent でカーネル、パフォーマンスのエンジニアとして活躍し、現在は Netflix(北米のインターネットのトラフィックの32.3%を占める。YouTubeは17.1%)*1 のシニア・パフォーマンス・アーキテクトです。ZFS L2ARC や DTrace Toolkit の開発者で、Solaris Performance and Tools、DTrace: Dynamic Tracing in Oracle Solaris, Mac OS X and FreeBSD の著者で、LinuxCon、FreeBSD Summit、Oaktable World、AWS re:Invent などのイベントで幅広く活動されています。是非 Brendan Gregg's Homepage をご覧ください。

Flame Graphs の見方

P.35

  • 関数名で左から右にソートされています。
  • コールスタックは上に行くほど深くなります。


P.40

  • 1番上(d()、f()、h())がCPUを使っている関数で、横幅が長いほど長時間CPUを使っています。
  • 下の例ではf()が最もCPU時間を使っている関数です。

手順

$ wget https://raw.githubusercontent.com/brendangregg/FlameGraph/master/stackcollapse-perf.pl
$ wget https://raw.githubusercontent.com/brendangregg/FlameGraph/master/flamegraph.pl
  • root 以外でも perf を使えるようにする
# echo 0 > /proc/sys/kernel/perf_event_paranoid
# cat /proc/sys/kernel/perf_event_paranoid
0
  • dd コマンドを実行し、perf でプロファイリングする(pid指定も可能です)。
    • -g: コールスタック(コールグラフ、バックトレース)を記録
    • -a: 実行コマンドだけでなくOS全体の情報を収集
    • -F: 100,000Hz(秒間100,000回)サンプリング
$ perf record -a -g -F100000 dd if=/dev/zero of=/tmp/test.dat bs=1024K count=1000
  • perf で取得したデータをテキストに変換する。
$ perf script> perf_data.txt
  • Flame Graph を生成して可視化する。
$ perl stackcollapse-perf.pl perf_data.txt|perl flamegraph.pl --title "Flame Graphs - dd if=/dev/zero of=/tmp/test.dat bs=1024K count=1000" > flamegraph_dd.svg

環境

$ cat /etc/issue
Oracle Linux Server release 6.6
Kernel \r on an \m
$ uname -r
2.6.39-400.17.1.el6uek.x86_64

参考

Flame Graphs

Systems Performance: Enterprise and the Cloud

Systems Performance: Enterprise and the Cloud

Perf

関連


追記(2015/07/07):

いつもperfの結果は"perf report"するだけだったわ……。/"/proc/sys/kernel/kptr_restrict"に"0"を書き込むと警告とunknownが消えるはず。

いつもperfの結果は"perf report"するだけだったわ……。/"/proc/sys/kernel/kptr_restrict"に"0"を書き込むと警告とunknownが消えるはず。 - richard_rawのコメント / はてなブックマーク

本検証結果は /proc/sys/kernel/kptr_restrict = 0 (デフォルト)で実行した結果です。

$ cat /proc/sys/kernel/kptr_restrict
0

カーネルのコールスタックが [unknown] で /proc/sys/kernel/kptr_restrict が 0 以外の時は 0 にすることでカーネルのコールスタックが表示されると思いますが、上記検証で [unknown] になっているのはユーザープロセスのコールスタックなので、関係ないと思われます。/proc/sys/kernel/kptr_restrict が 0 以外だと /proc からカーネルのポインタが参照できなくなるようです。

Add the %pK printk format specifier and the /proc/sys/kernel/kptr_restrict sysctl.

The %pK format specifier is designed to hide exposed kernel pointers,specifically via /proc interfaces. Exposing these pointers provides an easy target for kernel write vulnerabilities, since they reveal the locations of writable structures containing easily triggerable function pointers. The behavior of %pK depends on the kptr_restrict sysctl.

If kptr_restrict is set to 0, no deviation from the standard %p behavior occurs. If kptr_restrict is set to 1, if the current user (intended to be a reader via seq_printf(), etc.) does not have CAP_SYSLOG (which is currently in the LSM tree), kernel pointers using %pK are printed as 0's. If kptr_restrict is set to 2, kernel pointers using %pK are printed as 0's regardless of privileges. Replacing with 0's was chosen over the default "(null)", which cannot be parsed by userland %p, which expects "(nil)".

kptr_restrict for hiding kernel pointers [LWN.net]

CAP_SYSLOG (since Linux 2.6.37)

  • Perform privileged syslog(2) operations. See syslog(2) for information on which operations require privilege.
  • View kernel addresses exposed via /proc and other interfaces when /proc/sys/kernel/kptr_restrict has the value 1. (See the discussion of the kptr_restrict in proc(5).)
capabilities(7) - Linux manual page

/proc/sys/kernel/kptr_restrict (since Linux 2.6.38)

The value in this file determines whether kernel addresses are exposed via /proc files and other interfaces. A value of 0 in this file imposes no restrictions. If the value is 1, kernel pointers printed using the %pK format specifier will be replaced with zeros unless the user has the CAP_SYSLOG capability. If the value is 2, kernel pointers printed using the %pK format specifier will be replaced with zeros regardless of the user's capabilities. The initial default value for this file was 1, but the default was changed to 0 in Linux 2.6.39. Since Linux 3.4, only users with the CAP_SYS_ADMIN capability can change the value in this file.

proc(5) - Linux manual page

This post is already over a year old, but since it came out at the top of my Google search results when I had the same problem, I thought I'd answer it here. After some more searching around, I found the answer given in this related StackOverflow question very helpful. On my Ubuntu Raring system, I then ended up doing the following:

1. Compile my C++ sources with -g (fairly obvious, you need debug symbols)
2. Run perf as

record -g dwarf -F 97 /path/to/my/program

This way perf is able to handle the DWARF 2 debug format, which is the standard format gcc uses on Linux. The -F 97 parameter reduces the sampling rate to 97 Hz. The default sampling rate was apparently too large for my system and resulted in messages like this:

Warning:
Processed 172390 events and lost 126 chunks!

Check IO/CPU overload!

and the perf report call afterwards would fail with a segmentation fault. With the reduced sampling rate everything worked out fine.

3. Once the perf.data file has been generated without any errors in the previous step, you can run perf report etc. I personally like the FlameGraph tools to generate SVG visualizations.
4. Other people reported that running

echo 0 > /proc/sys/kernel/kptr_restrict

as root can help as well, if kernel symbols are required.

linux - How can I get perf to find symbols in my program - Stack Overflow

*1:http://wazanova.jp/post/62392993571/30-netflix-amzazon