perf でアプリケーションのプロファイリングをする方法。
perf は Linux システム全体をモニタリングするのに使えるが、アプリケーションのプロファイリングにも使える。 アプリケーションのプロファイリングに特化したツールではないのでその目的では多少使いづらい(個人の感想です)が、Linux システムやCPUレベルでのプロファイリングもできるので、見ようと思ったらより詳細も見れるという意味で重宝する。
perf record & report
$ perf record python test.py
$ perf report
Samples: 3K of event 'cycles:pp', Event count (approx.): 750316952649597
Overhead Command Shared Object Symbol
18.02% python libopenblasp-r0.2.20.so [.] sgemm_kernel_HASWELL
7.47% python libopenblasp-r0.2.20.so [.] sgemm_beta_HASWELL
5.57% python [unknown] [.] 0xffffffff8184470a
? でヘルプを見れるが、カーソルキーで上下移動ができて、 a を押すとアセンブリが見れる。どこで負荷がかかったのか割合もみれる。
sgemm_beta_HASWELL /home/sonots/miniconda3/envs/myenv/lib/libopenblasp-r0.2.20.so
│ ↓ jle 1b0
│ test %rsi,%rsi
│ ↓ jle 1b0
│ ucomis %xmm1,%xmm0
│ ↓ jne b0
│ nop
│ 30: mov %rdx,%r8
0.67 │ lea (%rdx,%rcx,4),%rdx
│ mov %rdi,%rax
0.67 │ sar $0x3,%rax
│ ↓ jle 80
│ 40: movss %xmm0,(%r8)
│ movss %xmm0,0x4(%r8)
│ movss %xmm0,0x8(%r8)
│ movss %xmm0,0xc(%r8)
│ movss %xmm0,0x10(%r8)
│ movss %xmm0,0x14(%r8)
│ movss %xmm0,0x18(%r8)
│ movss %xmm0,0x1c(%r8)
│ add $0x20,%r8
│ dec %rax
│ ↑ jg 40
│ nop
│ 80: mov %rdi,%rax
0.67 │ and $0x7,%rax
│ ↓ jle a0
1.34 │ nop
82.55 │ 90: movss %xmm0,(%r8)
13.42 │ add $0x4,%r8
d で DSO (Shared Object) の絞込みができて、たとえば python を除いて特定の .so だけに絞り込んで見たい時に使える。
Overhead Comman Symbol
18.02% python [.] sgemm_kernel_HASWELL
7.47% python [.] sgemm_beta_HASWELL
2.78% python [.] blas_thread_server
0.00% python [.] sgemm_oncopy_HASWELL
0.00% python [.] inner_thread
perf mem record & peport
$ perf mem record python test.py
$ perf mem report
メモリアクセスに関して見れる。操作性はほぼ同じ。
Samples: 3K of event 'cycles:pp', Event count (approx.): 3446
Overhead Samples Local Weight Memory access Symbol
9.26% 319 1 N/A [.] sgemm_kernel_HASWELL
6.62% 228 1 N/A [k] 0xffffffff81064508
4.03% 139 1 N/A [k] 0x00007f6b6ec217f5
3.92% 135 1 N/A [.] 0xffffffff8184470a
2.84% 98 1 N/A [.] pthread_mutex_lock
a で sgemm_kernel を掘った様子
│ lea 0x80(%rsp),%rsi
│ mov %r12,%rax
0.31 │ shl $0x2,%rax
│ lea (%r8,%rax,4),%rbp
│ mov %rbp,%r8
│ mov %r12,%rax
│ nop
3.45 │ c0: vmovup (%rdi),%xmm0
6.27 │ vmovsd 0x0(%rbp),%xmm1
2.19 │ vmovup %xmm0,(%rsi)
1.25 │ vmovsd %xmm1,0x10(%rsi)
0.31 │ add $0x10,%rdi
│ add $0x10,%rbp
1.88 │ add $0x18,%rsi
0.31 │ dec %rax
1.57 │ ↑ jne c0
perf record -g & report -g
-g オプションをつけると call graph を見れる。 record 時に -g をつけていれば、report ではつけても付けなくても良い。
$ perf record -g python test.py
$ perf report
左側に + マークが出てるので、カーソルキー↑↓で選択して、Enter を押すと展開される。
- 18.92% 18.92% python libopenblasp-r0.2.20.so [.] sgemm_kernel_HASWELL
+ 18.92% 0x3f8000003f800000
- 0.00% sgemm_kernel_HASWELL
- 0.00% 0xffffffff818451a5
0xffffffff81003c16
0xffffffff810031f2
0xffffffff81840585
0xffffffff8183fed6
- 0xffffffff810a9d6e
- 0xffffffff81181aea
0xffffffff8117f8de
0xffffffff8117cb07
0xffffffff81006e41
0xffffffff8100af30
0xffffffff8100aebd
0xffffffff81064508
0.00% 0xffffffff81064508
+ 6.24% 6.24% python libopenblasp-r0.2.20.so [.] sgemm_oncopy_HASWELL
+ 0.00% 0.00% python libopenblasp-r0.2.20.so [.] sgemm_beta_HASWELL? で出てくるヘルプに書いてあるが、E を押すと全展開、C を押すと全部閉じられる。
$ perf report --stdio
とすると、全展開した状態で出力することもできる。
26.80% 0.00% python [unknown] [.] 0x3f8000003f800000
|
---0x3f8000003f800000
|
|--18.92%-- sgemm_kernel_HASWELL
| |
| |--0.00%-- 0xffffffff818451a5
| | 0xffffffff81003c16
| | 0xffffffff810031f2
| | 0xffffffff81840585
| | 0xffffffff8183fed6
| | 0xffffffff810a9d6e
| | |
| | --0.00%-- 0xffffffff81181aea
| | 0xffffffff8117f8de
| | 0xffffffff8117cb07
| | 0xffffffff81006e41
| | 0xffffffff8100af30
| | 0xffffffff8100aebd
| | 0xffffffff81064508
| |
| --0.00%-- 0xffffffff81064508
|
|--6.24%-- sgemm_oncopy_HASWELL
