perf使ってみた

# 概要
CentOS6.9でperfコマンドを使ってみたメモ

# 参考
* [Linux Performance](http://www.brendangregg.com/linuxperf.html)
* [perf Examples](http://www.brendangregg.com/perf.html)
* [perf-tools](https://github.com/brendangregg/perf-tools)
* [perf wiki](https://perf.wiki.kernel.org/index.php/Main_Page)
* [Systems Performance: Enterprise and the Cloud](https://www.amazon.co.jp/Systems-Performance-Enterprise-Brendan-Gregg/dp/0133390098/ref=sr_1_sc_1?s=books&ie=UTF8&qid=1492582490&sr=8-1-spell&keywords=systemperformance)

# perf is 何
* Performance analysis tools for Linux
* 参考のリンクがとても詳しい

# なぜ使うのか
システムコールから先のカーネルのどこでボトルネックになっているかなどを知りたい場合

# 導入
yumでサクッとインストールできる。

```sh
yum install perf
```

# 使い方
* プロファイルの実行
    - `perf record -ag`

* 結果を保存
* 結果の確認
    - `perf report -g -G --stdio`

# コマンド
perf [サブコマンド]


# サブコマンド
```sh
perf-stat(1), perf-top(1), perf-record(1), perf-report(1), perf-list(1)
```
`man perf-サブコマンド`でmanが見れる

# コマンド使ってみる
## perf top
* 関数単位でcpu使用率を閲覧
* 共有ライブラリのシンボルは16進数で読めない。`kernel-debuginfo`などインストールしていないがカーネルシンボルが読める。共有ライブラリもシンボルが見れるものがある、なぜでしょうか＞＜？？？？？

```sh
Samples: 72K of event 'cpu-clock', Event count (approx.): 2471353254
Overhead  Shared Object             Symbol
   3.76%  [kernel]                  [k] find_vma
   3.56%  [kernel]                  [k] __d_lookup
   2.44%  [kernel]                  [k] avc_has_perm_noaudit
   2.42%  [kernel]                  [k] __link_path_walk
   2.39%  libjvm.so                 [.] 0x00000000004743a3
   1.89%  [kernel]                  [k] prof_syscall_enter
   1.72%  [kernel]                  [k] inode_has_perm
   1.64%  libc-2.12.so              [.] mkfifo
   1.34%  [kernel]                  [k] selinux_inode_permission
   1.23%  [kernel]                  [k] finish_task_switch
   1.04%  [kernel]                  [k] kmem_cache_alloc
   0.87%  [kernel]                  [k] system_call
   0.84%  [kernel]                  [k] syscall_trace_enter
   0.80%  [kernel]                  [k] strncpy_from_user
   0.74%  [kernel]                  [k] __do_softirq
   0.66%  [kernel]                  [k] acl_permission_check
   0.61%  [kernel]                  [k] do_lookup
   0.54%  libjvm.so                 [.] 0x000000000065af65
   0.53%  libc-2.12.so              [.] memcpy
   0.51%  [kernel]                  [k] follow_managed
   0.47%  [kernel]                  [k] audit_syscall_entry
   0.44%  libjvm.so                 [.] 0x00000000009ff88c
   0.43%  [kernel]                  [k] dput
   0.43%  libjvm.so                 [.] 0x00000000006c1c56
   0.42%  [kernel]                  [k] _atomic_dec_and_lock
   0.41%  perf                      [.] hists__output_resort
   0.41%  libjvm.so                 [.] 0x000000000032ef1e
```

## perf list
* 調査可能なイベント一覧
* 出力されたイベントは他のサブコマンドの-eオプションで指定できる

```
# perf list | more

List of pre-defined events (to be used in -e):

  alignment-faults                                   [Software event]
  context-switches OR cs                             [Software event]
  cpu-clock                                          [Software event]
  cpu-migrations OR migrations                       [Software event]
  dummy                                              [Software event]
  emulation-faults                                   [Software event]
  major-faults                                       [Software event]
  minor-faults                                       [Software event]
  page-faults OR faults                              [Software event]
  task-clock                                         [Software event]

  rNNN                                               [Raw hardware event descriptor]
  cpu/t1=v1[,t2=v2,t3 ...]/modifier                  [Raw hardware event descriptor]
   (see 'man perf-list' on how to encode it)

  block:block_bio_backmerge                          [Tracepoint event]
```
* 他のコマンドで`-e block:block_bio_backmerge `みたいに指定してパフォーマンスを測定できる。
* `perf stat -e block:block_bio_backmerge -p プロセス番号`
* [perf Examples](http://www.brendangregg.com/perf.html) にイベントの詳しい一覧図がある
* イベントをピンポイントで計測可能。負荷調査などで大体のボトルネックの箇所がわかっていて、ピンポイントで調べたいときに便利そう
* 詳しく使ってないのでなんともですが、他のコマンドでは測定できない箇所を調べられるのがよさそう

## perf stat
`perf-stat - Run a command and gather performance counter statistics`
システムコールをイベント指定して使ってみた

```sh
$ perf stat -e 'syscalls:sys_enter_gettimeofday' -p 3887
^C
 Performance counter stats for process id '3887':

               592      syscalls:sys_enter_gettimeofday

       0.772927115 seconds time elapsed
```
ハードウェアイベント関連

```sh
perf stat -e cycles,instructions,cache-references,cache-misses,bus-cycles -a sleep 10

 Performance counter stats for 'system wide':

    12,660,287,860      cycles                                                        (100.00%)
     6,503,412,662      instructions              #    0.51  insns per cycle          (100.00%)
       239,947,605      cache-references                                              (100.00%)
         9,235,423      cache-misses              #    3.849 % of all cache refs      (100.00%)
       435,088,963      bus-cycles

      10.000614024 seconds time elapsed
```
* 利用できるカウンタは、プロセッサのアーキテクチャによって決まり、プロセッサのマニュアル(たとえば、Interlの「ソフトウェアデベロッパーズ・マニュアル」にドキュメントされている。)

KVM上のハードウェア関連のイベントをいくつか試したが`not supprot`。なぜだろう？

```sh
$ perf stat -e cycles,instructions,cache-references,cache-misses,bus-cycles -a sleep 10

 Performance counter stats for 'system wide':

   <not supported>      cycles
   <not supported>      instructions
   <not supported>      cache-references
   <not supported>      cache-misses
   <not supported>      bus-cycles

      10.011931754 seconds time elapsed

```

# Linuxパフォーマンスを記録してみる
システム全体を調査

```sh
perf record -ag
```

```sh
-a, --all-cpus
          System-wide collection from all CPUs.
-g, --call-graph
          Do call-graph (stack chain/backtrace) recording.
```
* デフォルトだとカレントディレクトリに`perf.data`として保存される

### コマンドも指定できる
個々のプロセスを対象にすることもできる

```sh
perf record -- [コマンド]
```

# 結果の確認

```sh
perf report -g -G --stdio
```

* -Gをつけないと関数名が16進数表示になる
* --stdioで標準出力
* -gは今回だと特につけてもつけなくても変わらないように見えた。値を指定すると変わるのか、今度試す。

結果

```sh
# To display the perf.data header info, please use --header/--header-only options.
#
# Samples: 5K of event 'cpu-clock'
# Event count (approx.): 59969696370
#
# Children      Self  Command          Shared Object       Symbol
# ........  ........  ...............  ..................  .......................................
#
    48.02%    48.02%  swapper          [kernel.vmlinux]    [k] native_safe_halt
                    |
                    ---native_safe_halt

     6.30%     0.35%  java             libc-2.12.so        [.] mkfifo
                       |
                       ---mkfifo
                          |
                          |--16.04%-- __d_lookup
                          |
                          |--12.83%-- avc_has_perm_noaudit
                          |
                          |--9.09%-- __link_path_walk
                          |
                          |--5.88%-- inode_has_perm
                          |
                          |--4.01%-- acl_permission_check
```

# フレームグラフ
* perf実行結果からスタックフレームをグラフにできる。視覚化され、CPUの使用状況を素早く明確に理解できる
* グラフの見方など [perf + Flame Graphs で Linux カーネル内のボトルネックを特定する](http://d.hatena.ne.jp/yohei-a/20150706/1436208007)

![image](https://qiita-image-store.s3.amazonaws.com/0/91729/4bfb792e-407a-69a6-055a-3f1ba2a68e16.png)

### フレームグラフ作成方法
以下にperfとsystemtapでのCPUフレームグラフの作成方法が載ってた
[CPU Flame Graphs](http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html)

```bash
# git clone https://github.com/brendangregg/FlameGraph  # or download it from github
# cd FlameGraph
# perf record -F 99 -a -g -- sleep 60
# perf script | ./stackcollapse-perf.pl > out.perf-folded
# ./flamegraph.pl out.perf-folded > perf-kernel.svg
```
# まとめ
`vmstat`などで負荷調査。SystemのCPU使用率高いー
↓
`strace`でシステムコールみてみる。あーなんか沢山時間使ってるシステムコールあるー。でもシステムコールから先のカーネルのどこで時間使ってるかわからないー。でも知りたいー。
↓
私には`perf`がある!!
↓
`perf top`でどのカーネル関数がCPU上で沢山使われてるのかー
↓
`perf record`と`perf repot`で詳しいコールグラフみて、どの流れでCPU沢山つかっているんやろーを把握。問題となる関数を把握。
↓
カーネルソース見ながらもくもく`静的解析`して原因究明。対策実施。

次はSystemTap