OSレベルで sys のCPU使用率が高い場合に perf*1 を使って、何の処理の割合が高いか調べる方法です。
perf は
- 特定のプロセスだけでなくOS全体の統計を見れる
- カーネル(sys)とユーザー(user)の両方を見れる
ところが非常に便利だと思う*2。
準備
- ひたすら write システムコールを発行し続けるプログラムを作成する
$ cat write_loop.c #include <unistd.h> int main(void) { while(1) { write(1, "foo\n", 4); } }
- コンパイルする
$ gcc write_loop.c -o write_loop
- 実行権限を付与する
$ chmod u+x write_loop
検証
- ひたすらwriteシステムコールを発行するプログラムを実行する
$ ./write_loop > /dev/null & [1] 9188
- mpstat で CPU 毎の偏りを見る
$ mpstat -P ALL 2 3 Linux 2.6.39-400.17.1.el6uek.x86_64 (yazekats-linux) 12/07/2013 _x86_64_ (4 CPU) 01:02:23 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %idle 01:02:25 PM all 4.13 0.00 22.28 0.00 0.00 0.00 0.00 0.00 73.59 01:02:25 PM 0 12.06 0.00 87.94 0.00 0.00 0.00 0.00 0.00 0.00 <--CPU番号「0」の %sys が80%以上 01:02:25 PM 1 0.50 0.00 0.50 0.00 0.00 0.00 0.00 0.00 99.00 01:02:25 PM 2 1.50 0.00 0.50 0.50 0.00 0.00 0.00 0.00 97.50 01:02:25 PM 3 2.00 0.00 0.50 0.00 0.00 0.00 0.00 0.00 97.50 01:02:25 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %idle 01:02:27 PM all 4.12 0.00 22.62 0.12 0.00 0.00 0.00 0.00 73.12 01:02:27 PM 0 11.44 0.00 88.56 0.00 0.00 0.00 0.00 0.00 0.00 <--CPU番号「0」の %sys が80%以上 01:02:27 PM 1 2.50 0.00 0.00 0.00 0.00 0.00 0.00 0.00 97.50 01:02:27 PM 2 1.50 0.00 1.00 0.00 0.00 0.00 0.00 0.00 97.50 01:02:27 PM 3 1.51 0.00 0.50 0.00 0.00 0.00 0.00 0.00 97.99 01:02:27 PM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %idle 01:02:29 PM all 4.25 0.00 22.38 0.00 0.00 0.00 0.00 0.00 73.38 01:02:29 PM 0 11.50 0.00 88.50 0.00 0.00 0.00 0.00 0.00 0.00 <--CPU番号「0」の %sys が80%以上 01:02:29 PM 1 1.51 0.00 0.00 0.00 0.00 0.00 0.00 0.00 98.49 01:02:29 PM 2 1.51 0.00 0.50 0.00 0.00 0.00 0.00 0.00 97.99 01:02:29 PM 3 2.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 98.00 Average: CPU %usr %nice %sys %iowait %irq %soft %steal %guest %idle Average: all 4.17 0.00 22.43 0.04 0.00 0.00 0.00 0.00 73.36 Average: 0 11.67 0.00 88.33 0.00 0.00 0.00 0.00 0.00 0.00 <--CPU番号「0」の %sys が80%以上 Average: 1 1.50 0.00 0.17 0.00 0.00 0.00 0.00 0.00 98.33 Average: 2 1.50 0.00 0.67 0.17 0.00 0.00 0.00 0.00 97.66 Average: 3 1.84 0.00 0.33 0.00 0.00 0.00 0.00 0.00 97.83
- perf で CPU番号「0」でCPU使用率が高い関数を調べる
$ perf top -C 0 PerfTop: 1018 irqs/sec kernel:90.4% exact: 0.0% [1000Hz cycles], (all, CPU: 0) ----------------------------------------------------------------------------------------------------- samples pcnt function DSO _______ _____ ________________________ _________________________ 1020.00 13.1% vfs_write [kernel.kallsyms] <--writeシステムコールが大量に発行されている兆候が見られる 993.00 12.8% fget_light [kernel.kallsyms] 636.00 8.2% audit_syscall_exit [kernel.kallsyms] 607.00 7.8% system_call [kernel.kallsyms] 581.00 7.5% __write_nocancel /lib64/libc-2.12.so 476.00 6.1% system_call_after_swapgs [kernel.kallsyms] 461.00 5.9% rw_verify_area [kernel.kallsyms] 407.00 5.2% current_kernel_time [kernel.kallsyms] 376.00 4.8% audit_syscall_entry [kernel.kallsyms] 331.00 4.3% fsnotify [kernel.kallsyms] 276.00 3.5% sys_write [kernel.kallsyms] <--writeシステムコールが大量に発行されている兆候が見られる 172.00 2.2% sysret_check [kernel.kallsyms] 156.00 2.0% __srcu_read_unlock [kernel.kallsyms] 136.00 1.7% security_file_permission [kernel.kallsyms] 123.00 1.6% unroll_tree_refs [kernel.kallsyms] 119.00 1.5% __fsnotify_parent [kernel.kallsyms] 105.00 1.3% path_put [kernel.kallsyms] 95.00 1.2% __srcu_read_lock [kernel.kallsyms] 89.00 1.1% kfree [kernel.kallsyms] 88.00 1.1% __GI___libc_write /lib64/libc-2.12.so 87.00 1.1% auditsys [kernel.kallsyms] 78.00 1.0% sysret_signal [kernel.kallsyms] 64.00 0.8% dput [kernel.kallsyms] 56.00 0.7% cap_file_permission [kernel.kallsyms] 55.00 0.7% write_null [kernel.kallsyms] 53.00 0.7% main /home/yazekats/write_loop 44.00 0.6% mntput [kernel.kallsyms] 28.00 0.4% sysret_audit [kernel.kallsyms]
検証環境
$ cat /etc/issue Oracle Linux Server release 6.4 Kernel \r on an \m $ uname -a Linux ****** 2.6.39-400.17.1.el6uek.x86_64 #1 SMP Fri Feb 22 18:16:18 PST 2013 x86_64 x86_64 x86_64 GNU/Linux
参考
関連
追記(2014/04/29):
ソフトウェア開発に愛用している生産性向上ツールを教えてください。デスクトップでは何を使っていますか?
30人のLinuxカーネル開発者:Linus Torvalds
Web ブラウザ (メールや時間つぶし用) だけで、あとは git を使用する端末がいくつかあり、たまには "gitk" ウィンドウで git 履歴ビューを見ます。ふだんは e-メールを読んだり、e-メールで質問に答えたり、ツリーをマージしたり、その結果を調べたりしています。
そのほかによく使うツールは、いつも気にしている負荷 (主にカーネルのコンパイルとか git の作業負荷など) のパフォーマンス プロファイリングを行うための "perf" ツールです。
Linus Torvalds も perf を愛用しているようです。