前回は eBPF を利用するために bcc を導入しました。本来 bcc は自分でプログラムを書くことが前提ですが、標準で添付されているツール群だけでもかなり面白いことがわかります。ただ添付されているコマンドだけでも 100 以上あるので全部取り上げることはできませんが、bcc Tutorial に取り上げられているコマンドだけでも色々面白いことがわかるのでご紹介したいと思います。
execsnoop
このコマンドは前回の動作確認にも使用しました。プログラムの実行を記録するものです。
|
|
$ sudo /usr/share/bcc/tools/execsnoop PCOMM PID PPID RET ARGS dhclient-script 19826 2318 0 /usr/sbin/dhclient-script hostname 19828 19827 0 /bin/hostname cat 19830 19829 0 /bin/cat /proc/cmdline cat 19832 19831 0 /bin/cat /proc/cmdline |
bcc Tutorial にも記載がある通り、起動して直ぐ終了してしまうがたくさん起動されているコマンドが負荷の原因になっている場合は、ps や top などで見つけにくいため、こういうツールが必要になります。似たようなコマンドに psacct があります。
opensnoop
どのプロセスがどのファイルを開いているのかがわかります。意外とこれをながめているだけでわかることも多いです。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
$ sudo ./opensnoop PID COMM FD ERR PATH 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands 30697 opensnoop -1 2 /usr/lib64/python2.7/encodings/ascii.so 30697 opensnoop -1 2 /usr/lib64/python2.7/encodings/asciimodule.so 30697 opensnoop 12 0 /usr/lib64/python2.7/encodings/ascii.py 30697 opensnoop 13 0 /usr/lib64/python2.7/encodings/ascii.pyc 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands 1968 irqbalance 6 0 /proc/interrupts 1968 irqbalance 6 0 /proc/stat 1968 irqbalance 6 0 /proc/irq/24/smp_affinity 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands 29112 pickup 12 0 maildrop 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands 2513 amazon-ssm-agen 8 0 /proc/sys/kernel/hostname 2513 amazon-ssm-agen 11 0 /var/lib/amazon/ssm/localcommands |
xfsslower
ここでは、Amazon Linux 2 の標準ファイルシステムが xfs なので、xfsslower を取り上げますが、ext4 の ext4slower などもあります。
どんなコマンドかと言うと指定した時間以上IOに時間がかかった場合にそのコマンド名とファイル名を表示してくれるコマンドです。
なんかプロセスが遅いなぁという時にファイルIOがボトルネックになることがあるので、問題の切り分けにログを取っておくと有効かもしれません。
以下の実行例では dd コマンドで無理やり 10ms 以上のレイテンシを作っています。
|
|
$ sudo ./xfsslower Tracing XFS operations slower than 10 ms TIME COMM PID T BYTES OFF_KB LAT(ms) FILENAME 06:52:38 dd 29540 W 41943040 0 15.22 aa 06:53:10 dd 29541 W 41943040 0 15.20 aa 06:53:19 dd 29542 W 41943040 0 15.23 aa 06:53:24 dd 29543 W 41943040 0 15.13 aa 06:53:26 dd 29544 W 41943040 0 15.31 aa 06:53:29 dd 29545 W 41943040 0 15.16 aa 06:53:43 dd 29597 W 41943040 0 15.16 aa |
biolatency
diskio のレイテンシを表示してくれます。単純な iostat よりも詳細な情報を得ることができます。 レイテンシの分布状況から、ディスクアクセスの状況を知るのに役立ちます。
できれば、IOサイズとのクロス集計にすると面白いかもしれません。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
$ sudo ./biolatency Tracing block device I/O... Hit Ctrl-C to end. ^C usecs : count distribution 0 -> 1 : 0 | | 2 -> 3 : 0 | | 4 -> 7 : 0 | | 8 -> 15 : 0 | | 16 -> 31 : 1 | | 32 -> 63 : 1 | | 64 -> 127 : 0 | | 128 -> 255 : 0 | | 256 -> 511 : 21 |********** | 512 -> 1023 : 59 |****************************** | 1024 -> 2047 : 13 |****** | 2048 -> 4095 : 70 |************************************ | 4096 -> 8191 : 77 |****************************************| |
cachestat
ディスクキャッシュのヒット率がわかります。またダーティページの状況がわかります。ディスクキャッシュにヒットするかどうかは性能に大きく関わるので、とても有効です。
もしディスクIOが多くて、キャッシュヒット率が低いようならば、メモリの増強を検討するなどの施策が必要になります。
|
|
$ sudo ./cachestat HITS MISSES DIRTIES HITRATIO BUFFERS_MB CACHED_MB 0 0 0 0.00% 2 398 0 0 0 0.00% 2 398 0 0 0 0.00% 2 398 992 0 0 100.00% 2 398 0 0 0 0.00% 2 398 0 0 0 0.00% 2 398 0 0 0 0.00% 2 398 0 0 0 0.00% 2 398 1041 0 0 100.00% 2 398 0 0 0 0.00% 2 398 0 0 10240 0.00% 2 398 |
runqlat
プロセスがCPUを待っている時間の分布を表示してくれます。もしこの分布が長い時間の方に長くなっている場合は CPU の増強が必要かもしれません。また定常的に監視するのであれば runqslower の方が良いかもしれません。
|
|
$ sudo ./runqlat Tracing run queue latency... Hit Ctrl-C to end. ^C usecs : count distribution 0 -> 1 : 29 |******* | 2 -> 3 : 146 |****************************************| 4 -> 7 : 120 |******************************** | 8 -> 15 : 43 |*********** | 16 -> 31 : 4 |* | 32 -> 63 : 3 | | 64 -> 127 : 4 |* | |
とりあえず、このぐらいで。また実際に適用した事例などがあれば紹介したいと思います。
