とあるNode.jsアプリケーションをk8s化してパフォーマンスが劇的に悪くなったので、絵で見て分かるシステムパフォーマンスの仕組みを読んでボトルネックを探っています。その過程でこれは使える。。！と思ったコマンドをいくつか紹介します。
書名のとおりシステムパフォーマンスの基礎的な考え方や分析、チューニング、テストについて図を中心に詳しく解説されているのでとてもわかりやすいです。パフォーマンス改善やチューニングのお仕事するSREエンジニアは手元に1冊あると便利だと思います。(ステマではない
タイトなコンテナイメージだとこれらのコマンドは基本的にインストールされていないのでパッケージも探しました。すぐに使えなかったコマンドは後ほど詳細追加予定です。
typoの指摘やコマンドの修正/追加依頼は喜んで。
sar
パッケージのインストール
apt-get install -y sysstat
パフォーマンス情報の種類
サマリ形式
どこで測っているか
OSのカーネルから得られるOS情報
※OSレベルであるためアプリケーションから見たI/Oと異なる場合がある
わかること
- CPUの使用率、idle
- 読み書きI/Oの量
- メモリの使用状況
わからないこと
- プロセスごとの状況
- 瞬間的なパフォーマンストラブル
- 原因の候補となるプログラムやプロセス
- ハイパースレッドなどのCPUにおける実際のCPU使用状況
併せて見ると効果的なパフォーマンス情報
topコマンドなどのプロセスごとのスナップショット情報、各種アプリケーションのパフォーマンス情報、DBサーバのDBMSのスナップショット形式の情報など
使い方
sarコマンドの使い方
$ sar -r
Linux 3.10.0-862.2.3.el7.x86_64 (118-27-1-88) 10/01/2018 _x86_64_ (2 CPU)
12:00:01 AM kbmemfree kbmemused %memused kbbuffers kbcached kbcommit %commit kbactive kbinact kbdirty
12:10:01 AM 416372 599052 59.00 24524 434468 276164 8.87 371660 157708 0
12:20:02 AM 416544 598880 58.98 24568 434480 276164 8.87 371644 157756 0
12:30:01 AM 414176 601248 59.21 24668 434540 303108 9.74 373848 157596 0
12:40:01 AM 416288 599136 59.00 24716 434536 275948 8.87 371800 157632 0
12:50:01 AM 415956 599468 59.04 24780 434540 275948 8.87 371860 157688 0
01:00:01 AM 415772 599652 59.05 24984 434624 276052 8.87 373380 156556 4
01:10:01 AM 415680 599744 59.06 25052 434628 276052 8.87 373416 156600 0
...
以下のエラーになった場合は /etc/default/sysstat のENABLEDをtrueすると、10分に一回システムの情報をログに残すようになる
$ sar -r
Cannot open /var/log/sysstat/sa02: No such file or directory
Please check if data collecting is enabled
$ cat /etc/default/sysstat
#
# Default settings for /etc/init.d/sysstat, /etc/cron.d/sysstat
# and /etc/cron.daily/sysstat files
#
# Should sadc collect system activity informations? Valid values
# are "true" and "false". Please do not put other values, they
# will be overwritten by debconf!
ENABLED="false"
その他
sarは自動的に記録されているため大まかで良ければ過去にさかのぼって調べることができる。
情報の出力項目が比較的少なくかゆいところに手が届かないこともあるので vmstat や iostat なども併せて使うと良い。負荷も低いため本番環境で実行してもパフォーマンスに影響し辛い。
vmstat
パッケージのインストール
apt-get install -y sysstat
パフォーマンス情報の種類
サマリ形式
どこで測っているか
OSのカーネルから得られるOS情報
※OSレベルであるためアプリケーションから見たI/Oと異なる場合がある
わかること
- 実行待ちの平均プロセス数
- 何らかの理由で待たされている（ブロックされている）平均プロセス数
- CPU使用率、スワップへのI/O、通常のI/O、コンテキストスイッチの回数
わからないこと
- プロセスごとの状況
- 瞬間的なパフォーマンストラブル（期間を短くしていれば捕捉可能）
- 原因の候補となるプログラムやプロセス
- CPUコアの状況の違い（一部のトラブルではコアごとに状況が異なっていることがある）
併せて見ると効果的なパフォーマンス情報
topコマンドなどのプロセスごとのスナップショット情報、各種アプリケーションのパフォーマンス情報、DBサーバのDBMSのスナップショット形式の情報など
使い方
$ vmstat 1 10 #1秒ごとに10回取得
procs --memory- swap-- --io- -system-- cpu--
r b swpd free buff cache si so bi bo in cs us sy id wa st
4 0 59396 667232 260112 903312 0 0 3 5 10 13 0 1 99 0 0 #最初の行はOS起動後の平均のため無視する
0 0 59396 667224 260112 903312 0 0 0 0 269 521 0 0 99 0 0
0 0 59396 667224 260112 903312 0 0 0 0 231 420 0 0 99 0 0
2 0 59396 667224 260112 903312 0 0 0 0 220 425 0 0 100 0 0
0 0 59396 667224 260112 903312 0 0 0 0 197 405 0 1 99 0 0
0 0 59396 667224 260112 903312 0 0 0 0 192 401 0 1 99 0 0
0 0 59396 667224 260112 903312 0 0 0 0 234 449 0 0 100 0 0
0 0 59396 667224 260112 903312 0 0 0 0 270 525 0 1 99 0 0
0 0 59396 667224 260112 903312 0 0 0 0 295 600 0 1 99 0 0
1 0 59396 667224 260112 903316 0 0 0 0 303 584 0 1 98 0 0
その他
負荷が低く短期間で取得しても問題ないコマンド。数秒や数十秒レベルのトラブルも調査すべきシステムであれば秒単位で設定すべき。CPU使用率も実行待ちのプロセス数(r列)やブロックされているプロセス数(b列)に注目すると原因を特定しやすい。
ps
パッケージのインストール
apt-get install -y procps
パフォーマンス情報の種類
スナップショット形式
どこで測っているか
OSのカーネルから得られるプロセスの情報
わかること
- その瞬間に稼働しているプロセスの情報
- プロセスの状態(実行中/スリープなど)、名前、コマンド、番号、CPUの累積時間など
- 運良くパフォーマンストラブル中にpsコマンドが取れれば実行中のアプリケーションを特定し原因がわかるかも
わからないこと
- メモリやCPU使用率などOSの概況
- 実行中の各スレッドの情報はデフォルトだとわからない
併せて見ると効果的なパフォーマンス情報
sarやvmstatのなどサマリ形式の情報。psでプロセスを特定してスタックやトレースなど詳細を調査することも。
使い方
$ ps -elf
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
4 S root 1 0 0 80 0 - 8163 - 04:25 ? 00:00:00 nginx: master process nginx -g daemon off;
5 S nginx 6 1 0 80 0 - 8277 - 04:25 ? 00:00:00 nginx: worker process
4 S root 7 0 0 80 0 - 4547 - 04:25 pts/0 00:00:00 bash
0 R root 2046 7 0 80 0 - 9158 - 05:27 pts/0 00:00:00 ps -elf
その他
短時間に繰り返すのであれば、通常はtopコマンドを使用する。回数が少なくてもpsコマンドを定期的に取得しておくとプロセス情報を調査することができて便利。topと比較してスリープ状態のプロセスなどを調べることができる。
netstat
パッケージのインストール
apt-get install -y net-tools
パフォーマンス情報の種類
サマリ形式（パフォーマンス統計情報）、スナップショット形式（ルーティング情報など）
どこで測っているか
ドライバレベル。ケーブルを直接測っているわけではないのでネットワークの問題を必ず検出できるとは限らない
わかること
- aオプションでその瞬間のソケット（スナップショット形式）
- rオプションでその瞬間のルーティング情報（スナップショット形式）
- iオプションでインターフェースごとの統計（サマリ形式）
わからないこと
- ネットワークの通信で問題が起きているか
- リアルタイムでない情報
併せて見ると効果的なパフォーマンス情報
ネットワークのパフォーマンスがおかしいと感じる場合はそのネットワーク通信を使っているアプリケーションのパフォーマンスログ（特にイベント形式のログ）、パケットキャプチャでイベント形式のログを取得する。ドライバレベルでは困っていないように見えても、アプリケーションレベルでは困っていることも多い。
使い方
$ netstat -i
Kernel Interface table
Iface MTU RX-OK RX-ERR RX-DRP RX-OVR TX-OK TX-ERR TX-DRP TX-OVR Flg
eth0 1500 19602 0 0 0 6290 0 0 0 BMRU
lo 65536 0 0 0 0 0 0 0 0 LRU
その他
通信量やソケット一覧やルーティング情報などを確認したい場合に使用する。iで出力される通信量はデータ通信量は累積値なので注意、継続的に取得しておけば差分を計算することで該当時間の通信量を求めることができる。
iostat
パッケージのインストール
apt-get install -y sysstat
パフォーマンス情報の種類
サマリ形式
どこで測っているか
OSカーネル内部のブロックデバイスレベル。
※ファイルキャッシュといったOSのファイルシステムレベルの動作は記録されない
※OS上のアプリケーションから見たパフォーマンスのiostatレベルで見たパフォーマンスは差分が発生する
わかること
- ディスクのビジー率（使用率）
- xオプションでレスポンスタイムや各種キュー長
- tとx（Linuxの場合。tは時刻で、xは詳細を表示）のオプションがわかりやすくお勧め
- キュー長を見ることでどれだけI/Oが発行されたのか、もしくは待っているのかが分かる
わからないこと
- ビジー率を見ることでOSから見たディスクの稼働状況は分かるが、本当にディスクが限界に近いのかをOSからのビジー率から判定することは困難
- 上記の理由はストレージ側で仮想化や分割が進んでおり、OSから見たディスクの情報と実態が異なることが多いため
併せて見ると効果的なパフォーマンス情報
ストレージ側のパフォーマンス情報を調査するのがおすすめ。iostatレベルでパフォーマンス劣化が出ていればストレージ側でもなにか起きているはず。
使い方
【 iostat 】コマンド――I/Oデバイスの使用状況を表示する
$ iostat -xt 5 5
Linux 4.9.125-linuxkit (b51423efbd72) 07/02/19 _x86_64_ (4 CPU)
07/02/19 05:37:26
avg-cpu: %user %nice %system %iowait %steal %idle
0.16 0.00 0.66 0.01 0.00 99.18
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
scd0 0.00 0.00 0.01 0.00 0.92 0.00 152.70 0.00 0.36 0.36 0.00 0.29 0.00
scd1 0.00 0.00 0.00 0.00 0.00 0.00 35.43 0.00 0.00 0.00 0.00 0.00 0.00
scd2 0.00 0.00 0.03 0.00 1.94 0.00 147.57 0.00 0.33 0.33 0.00 0.20 0.00
sda 0.09 1.17 0.27 0.59 7.56 19.46 62.89 0.00 1.01 0.43 1.28 0.27 0.02
その他
最初の1回目の表示は起動時からの平均のためパス。iostatはデバイスが多い場合には少々負荷が高いため1秒といった間隔でとっているシステムは少ないはず。しかし1時間といった間隔でとると1,2分のトラブルに対応できないので1〜5分程度の間隔で取得するのがおすすめ。実際の分析のためにはIOPSという考え方とスループットという考え方を学ぶ必要がある。目安としてはどこかのキャッシュにヒットしていない状態で、1つのI/Oのレスポンスは数ミリ秒程度。十数ミリ秒以上になっている場合は何らかのレスポンス低下を疑うべき。
top
パッケージのインストール
apt-get install -y procps
パフォーマンス情報の種類
スナップショット形式
どこで測っているか
OSレベルの情報
わかること
- リアルタイムでOS全体の状況を把握するのに最適なコマンド
- 数秒おきにOS全体の状況を活動が活発な上位のプロセスから表示
- どんなプログラムやプロセスが活発に活動しているのかがわかるため原因の候補も調査しやすい
わからないこと
- リアルタイムで表示する場合は活発でないプロセスの情報はわからない
- 活発でないプロセスを調査する場合はpsコマンドを使う
併せて見ると効果的なパフォーマンス情報
- 怪しいプロセス(プログラム)のパフォーマンス情報。
- DBMSであればその時実行されているSQLなど
- 上記が取得出来ない場合はプロセスに対してのpstackによるコールスタック。
使い方
$ top
top - 19:43:14 up 7 days, 14:52, 0 users, load average: 0.03, 0.02, 0.00
Tasks: 2 total, 1 running, 1 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.0 us, 0.5 sy, 0.0 ni, 99.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 2046748 total, 842708 free, 211232 used, 992808 buff/cache
KiB Swap: 1048572 total, 989176 free, 59396 used. 1670044 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1 root 20 0 18136 3292 2800 S 0.0 0.2 0:00.15 bash
1892 root 20 0 41068 3324 2772 R 0.0 0.2 0:00.00 top
その他
topは少々負荷が高いコマンドなので念の為確認した上で使用する。
tcpdump(パケットダンプ)
パッケージのインストール
apt-get install -y tcpdump
パフォーマンス情報の種類
イベント記録形式
どこで測っているか
ドライバレベルの情報
わかること
- どんな通信をしているのか詳細に把握できる
- パケット情報を見ることでどちらが処理中なのか、また待機中なのか見れる
- 2つのサーバから挟み撃ちすることで測定しづらいネットワーク部分のパフォーマンスを特定可能
併せて見ると効果的なパフォーマンス情報
パケットを調査して怪しいアプリがわかった場合、どのアプリが処理しているのか、何を待っているのか調査する。スナップショット形式の情報などでどのような状態なのかなぜ遅いのかも調査する。
$ tcpdump
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes
05:54:36.253799 IP 172.17.0.1.38736 > b51423efbd72.http: Flags [F.], seq 266558858, ack 38955698, win 229, options [nop,nop,TS val 67011569 ecr 67009953], length 0
05:54:36.254035 IP b51423efbd72.http > 172.17.0.1.38736: Flags [F.], seq 1, ack 1, win 227, options [nop,nop,TS val 67011569 ecr 67011569], length 0
05:54:36.254070 IP 172.17.0.1.38740 > b51423efbd72.http: Flags [S], seq 1312229193, win 29200, options [mss 1460,sackOK,TS val 67011569 ecr 0,nop,wscale 7], length 0
05:54:36.254109 IP 172.17.0.1.38736 > b51423efbd72.http: Flags [.], ack 2, win 229, options [nop,nop,TS val 67011569 ecr 67011569], length 0
05:54:36.254109 IP b51423efbd72.http > 172.17.0.1.38740: Flags [S.], seq 2850403148, ack 1312229194, win 28960, options [mss 1460,sackOK,TS val 67011569 ecr 67011569,nop,wscale 7], length 0
05:54:36.254152 IP 172.17.0.1.38740 > b51423efbd72.http: Flags [.], ack 1, win 229, options [nop,nop,TS val 67011569 ecr 67011569], length 0
05:54:36.254652 IP b51423efbd72.48185 > 192.168.65.1.domain: 62986+ PTR? 1.0.17.172.in-addr.arpa. (41)
05:54:36.262968 IP b51423efbd72.35534 > 192.168.65.1.domain: 31494+ PTR? 1.65.168.192.in-addr.arpa. (43)
05:54:36.265671 IP 192.168.65.1.domain > b51423efbd72.35534: 31494 NXDomain 0/0/0 (43)
その他
rootユーザのみ実行可能なツール。OS上でパケットダンプを取得すると大きなパフォーマンス影響が出るので、パフォーマンス影響を許容するか開発環境などで再現させて取得する。パケットには個人情報やパスワードも入っている可能性もあるのでパケットデータの持ち出しには注意。
pstack
パッケージのインストール
apt-get install -y pstack
パフォーマンス情報の種類
スナップショット形式
どこで測っているか
OSから見たコールスタックの情報
わかること
- そのプログラム(プロセス)がその瞬間にどんな処理を実行しているのか
- あくまでスナップショットなので何度か実行して情報を取得する
- プログラムが何かを持っている場合何度実行しても同じコールスタックが見られるはず
わからないこと
- スナップショットなので同じ状態が継続しているとは言えない
- OSから
- 見たコールスタックであるためアプリケーションで呼び出している関数名と異なる可能性がある
併せて見ると効果的なパフォーマンス情報
イベント記録形式のツールとセットで使用すると待ち状態で勝つその状態から抜け出していないことを証明できる
使い方
$ ps aux
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.2 32652 5140 ? Ss 04:25 0:00 nginx: master process nginx -g daemon off;
nginx 6 0.0 0.1 33108 3212 ? S 04:25 0:00 nginx: worker process
root 7 0.0 0.1 18192 3340 pts/0 Ss 04:25 0:00 bash
root 3879 0.0 0.1 36632 2788 pts/0 R+ 05:59 0:00 ps aux
$ pstack 6 #dockerコンテナ上では使えなかったので後ほど更新
Could not attach to target 6: Operation not permitted.
detach: Operation not permitted
その他
一般的にpstackは負荷が低いと言われているのでパフォーマンスが劣化は気にしなくて良い。
pstackで関数名がわかったあとは自作アプリケーションについてはソースコードを見ながらどの関数で時間がかかっているのか調査する。ベンダ製品の関数名は非公開な場合が多いので調査できないが、コールスタックの上に表示されるOSの関数についてはインターネットで調べることができる。
strace
パッケージのインストール
apt-get install -y strace
パフォーマンス情報の種類
イベント記録形式
どこで測っているか
OSから見た特定のプロセスのシステムコール情報
わかること
- どんなシステムコールで待っているのか
- OSのなにの関数で時間を使っているのか
併せて見ると効果的なパフォーマンス情報
まずはtopコマンドなどでどのプロセスを疑うべきか特定する。特定後必要に応じてstraceを実行する(特にOSが怪しい場合に有効)。定期的なpstack情報もあるとひたすら待たされている場合はコールスタックも合わせてわかる。
使い方
$ ps aux
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.2 32652 5140 ? Ss 04:25 0:00 nginx: master process nginx -g daemon off;
nginx 6 0.0 0.1 33108 3212 ? S 04:25 0:00 nginx: worker process
root 7 0.0 0.1 18192 3340 pts/0 Ss 04:25 0:00 bash
root 3879 0.0 0.1 36632 2788 pts/0 R+ 05:59 0:00 ps aux
$ strace -p 6 #dockerコンテナ上では使えなかったので後ほど更新
strace: attach: ptrace(PTRACE_ATTACH, 6): Operation not permitted
その他
straceは他に調査方法がない場合に使用される。ベンダ製品に対して使用する場合にはサポートに確認したほうが良い。straceは負荷が高いためテスト環境でトラブルを再現させた上で取得することをおすすめする。
perf (プロファイラ)
パッケージのインストール
apt-get install -y linux-tools
パフォーマンス情報の種類
サマリ形式
どこで測っているか
OSから見たあるプロセスの各関数の処理時間
わかること
- どんな関数が何回呼び出されたのか
- どの関数で時間がかかっているのか
わからないこと
- 瞬間的なトラブルの原因の追求
併せて見ると効果的なパフォーマンス情報
イベント記録形式の情報と合わせて見ることで処理中にOSやI/O、ネットワークで待たされたかどうかがわかる
使い方
docker環境で使えなかったので後ほど更新
その他
プロファイラは開発者が開発環境においてプログラム全体のどこに時間かかっているのか調べるために有効。OSのプロファイラは対象プログラムのコンパイル時に-g(デバッグ)オプションが必要になるため、多くは自作アプリケーションの調査に使われる。プロファイラは環境によって名前が変わる(Linuxはperf、Gnuではgprofなど)。プロファイラはOS上のパフォーマンス情報を得るためのツールであるが、アプリケーションのパフォーマンス分析において便利なツールであるため言語ごとにプロファイラ機能やツールも存在する(JavaはPL/SQLなど)。OSのプロファイルに関してはpstackを連打してもほぼ同じ情報が取得できるためすぐにプロファイラが実行出来ない状況での回避策となる。