サーバーが高負荷状態になったときのプロセス一覧を自動で出力させておく

趣味でお世話をしているサーバーインスタンスのうちのひとつが、最近以下のような事象を時折起こしておりまして。

深夜に一時的に高負荷状態に陥る
朝起きてみたらそれに気づく（終息している）

さすがに趣味の範疇なので、深夜に飛び起きて対応できるようなアラート通知設定はしておらず、とはいえ起きてからその理由を探ろうとするのだけど、終息したあとに見られるものといったらせいぜい以下のようなことくらい？

モニタリングツール（Mackerel）のその当時のグラフの様子
アプリケーションログを見る
/var/log とかに出力されてるログを見る

今回の場合だとCPU使用率とLA（ロードアベレージ）が高騰していたことくらいしかわからずで、そのときにどういうプロセスがリソースを食ってたんだろう、みたいなことは把握することができなかった。

f:id:a-know:20180520211911p:plain

こんなかんじ。diskはちょっとハネてるかな...。。

対象のサーバーには Mackerel（mackerel-agent）を導入している。そこで、この原因を突き止めるための施策として、チェックプラグインとそのアクション機能を使って「そのサーバーが高負荷状態に陥ったときのプロセスリスト」を自動で出力させるように仕込んでみた。

高負荷状態になったときのプロセス一覧を自動で出力させる

「高負荷状態」をチェック監視するためには、 check-load を使う。

github.com

check-load の Synopsis としては以下で、

check-load [-r] -w <WL1>,<WL5>,<WL15> -c <CL1>,<CL5>,<CL15>

LAの1分間平均値・5分間平均値・15分間平均値のそれぞれに対して、Warning/Critical の閾値を設定できるようになっている。ちなみに -r オプションを使うことでCPUコア数でLAを割った値に対してチェックできる、が、あいにく僕はそんなリッチなインスタンスを使っているわけではない......。

設定する閾値はそのうちブラッシュアップしていくとして、今回は以下のようなプラグイン設定を mackerel-agent の conf に追記する。

[plugin.checks.la]
command = "check-load -w 3,2,1 -c 3,2,1"
action = { command = "bash -c '[ \"$MACKEREL_STATUS\" != \"OK\" ]' && date >> /home/a-know/ps-auxf.txt && ps auxf >> /home/a-know/ps-auxf.txt", user = "a-know" }
memo = "LAをチェックし、高騰したときにはそのときの ps auxf の結果を出力します"

チェックプラグインの一般的な利用方法についてはチェック監視に公式チェックプラグイン集を使う - Mackerel ヘルプやチェック監視項目を追加する - Mackerel ヘルプを見て欲しいんだけど、今回のキモは action オプションのところ。

チェック監視コマンド check-load -w 3,2,1 -c 3,2,1 を毎分実行する
- ちなみにこのコマンドを手動実行すると↓みたいな結果が得られる

$ check-load -w 3,2,1 -c 3,2,1
LOAD OK: load average: 0.71, 0.52, 0.51

チェック監視の結果、ステータスが OK 以外の場合に、
- date >> /home/a-know/ps-auxf.txt && ps auxf >> /home/a-know/ps-auxf.txt を実行し、そのときの日時とプロセスリストを /home/a-know/ps-auxf.txt に出力させる

といったようなことをおこなうような指定となっている。さらにもう少しだけ、以下に解説する。

action
- ここに指定した内容を、チェック処理の都度、実行する
action.command
- チェック処理後に実行されるコマンド文字列。
- 上述のとおり、このコマンド自体はチェック処理の都度、実行されるため、チェック監視結果に応じて実行可否を制御したい場合は、環境変数 MACKEREL_STATUS MACKEREL_PREVIOUS_STATUS の値をチェックするような記述もおこなう必要がある
  - 上記の環境変数には OK, WARNING, CRITICAL, UNKNOWN のいずれかがセットされている
action.user
- ここで指定したユーザーとして action.command に指定したコマンドが実行される

動作確認

上記の設定がされた mackerel-agent が動作しているサーバー上で、動作確認をしてみる。

手っ取り早くLAを高騰させるため、以下のコマンドをサーバー内で実行する。

$ yes > /dev/null

少し待つと、Mackerelからアラートが上がってくる。

f:id:a-know:20180520212552p:plain

f:id:a-know:20180520212715p:plain

はい。

action が実行されているかどうかを確認するため、yes コマンドを止め、出力されているであろうファイルの中身を確認する。

$ cat ps-auxf.txt 
Sat May 19 10:13:50 JST 2018
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         2  0.0  0.0      0     0 ?        S    Jan13   0:01 [kthreadd]
root         3  0.0  0.0      0     0 ?        S    Jan13   0:42  \_ [ksoftirqd/0]
root         5  0.0  0.0      0     0 ?        S<   Jan13   0:00  \_ [kworker/0:0H]
root         7  0.0  0.0      0     0 ?        S    Jan13   0:00  \_ [migration/0]
（中略）
root      1072  0.0  0.2 105996  4112 ?        Ss   Jan13   1:46 /usr/sbin/sshd -D
root      9863  0.1  0.3 147764  5284 ?        Ss   10:10   0:00  \_ sshd: a-know [priv]
a-know    9866  0.0  0.1 147764  2340 ?        S    10:10   0:00  |   \_ sshd: a-know@pts/0
a-know    9867  0.0  0.1 115532  2056 pts/0    Ss   10:10   0:00  |       \_ -bash
a-know    9966 96.6  0.0 107908   612 pts/0    R+   10:11   2:08  |           \_ yes
root     10243  0.0  0.2 105996  4056 ?        Ss   10:13   0:00  \_ sshd: [accepted]
sshd     10244  0.0  0.1 105996  2168 ?        S    10:13   0:00      \_ sshd: [net]
...

よさそうですね。

というわけで、今度似たような状況が発生したら、少なくともそのときどういうプロセスが動いていたか、ということは突き止められそう。それで根本原因がわかるかもしれないし、もしこれだけでわからなければさらに出力を増やすように設定を見直していく感じになりそう。

今回は ps コマンドの結果しか出力させていないけれど、こうした高負荷はネットワークやディスクなど様々な要素がボトルネックになり得るので、id:y_uuki さんの Linuxサーバにログインしたらいつもやっているオペレーション - ゆううきブログの記事内で紹介されているようなコマンドも組み込んでおくと良さそうだと思ってます。