概要:
とあるサーバで使用されているメモリが90%を超えているというアラートが発生。
調査依頼が来たために対応した際のログと反省点になります。
原因:
結論から言ってしまうと原因はslabにありました。
このslabという存在が恥ずかしながら初耳だったのでなにを行っているものなのか把握していなかったのですがこのslabが持つdentry cacheに問題がありました。
やったこと
当たり前ですがサーバに入ってどういう状態かを確認します。
ロードバランサから対象のサーバを切り離し
作業が影響してしまうといけないのでロードバランサから対象サーバを切り離します。
その際のメモリの使用量を確認したところ確かに危険域にあり、リクエスト由来でメモリを使うなにかが影響してはいないように見えました。
topコマンド
まず最初にtop -aでメモリ使用量の多い順にソートしたプロセス一覧を表示します。
ところがphp-fpmが複数立ち上がってこそいるもののメモリ使用量はそれぞれ0.x%と非常に少なく、MySQLなども問題ないレベルの使用量でどうやっても90%使っていそうなプロセスは見つかりませんでした。
freeコマンド
free -tmでスワップや物理メモリの合計も表示するようにして確認。
スワップはなしでbuffers/cacheがメモリを圧迫しているのを確認。
Meckerelを確認
ここ1ヶ月ほどのメモリ使用量などを確認、インスタンス起動から徐々にメモリ使用量が上昇していることを確認。
問題となる日付前のデプロイで影響がありそうな日時を確認、3GBほど増加しているがその後は多少の増減はあるがほぼ横ばい傾向であることを確認。
ミス1:
今にして思えばここで大きなミスをしてしまいました。
徐々にメモリ使用量が増加していたという点に着目してしまい、アプリケーション側がキャッシュしすぎているのではないか？
もしくはミドルウェアかアプリケーション側にメモリリークするような実装があるのではないか？と疑ってしまいます。
疑い自体はいいのですがそのせいで視野狭窄に陥ってしまったと感じていてそれが原因究明の妨げになってしまったと考えています。
ミス2
ぼくはtopコマンドの結果とfreeコマンドのusedの値がほぼ同一だったこと。
そして上記の考えに囚われてしまっていたためPHP側で使用しているAPC(OPCache)のメモリ解放方法を検索していました。
その間に同僚氏がproc/meminfoを実行します。
結果、slabがメモリの大半を使用しているという結果が出ます。
この情報をチーム全体に共有したことでこのslabがなにをしているものか、キャッシュデータを削除しても問題のないものか、キャッシュ削除するにはどうすればいいのか？という具体的な行動に移ることができるようになりました。
実行
今回はページキャッシュは残して、slabオブジェクト(dentryとinodeを含む)だけを消すという方針を取ることが決定したため以下のコマンドを実行しました。
実行を行う前に実行前のfreeコマンドとmeminfoコマンド、slabtopコマンドを実行して内容をログとして残しておくことをオススメします。
# slabオブジェクト(dentryとinodeを含む)の解放(ページキャッシュは残す)
$ sync; echo 2 > /proc/sys/vm/drop_caches
実行後に再度freeコマンドなどの確認作業を行います。
メモリがきちんと開放されていればOKです、お疲れ様でした。
参考:
- サーバーのメモリが少しずつ圧迫される原因と対策を調べてみた
- プロセスのメモリ使用量が少ないのにメモリ使用量が増加していた時に調査、対応したこと
- slab肥大化とdentry_cacheに辿り着くまでの話
今回の反省点:
反省ポイント1
当日中に対応完了が必須なタスクが別であったことから焦っていたのがまずかったと考えています。
障害だ！と思い、作業を中断して最優先で対応していたのですがクライアントに後ほど確認したところ今のところ問題は問題だが作業中のタスクを止めて対応するほどでないということを確認、調査開始前に一度どれくらい緊急かを確認しておくべきだったと思っています。
平常心で対応していれば、後述する反省ポイントも回避できた可能性があるなと思っています。
反省ポイント2
topとfreeで同じ結果だったからproc/meminfoをみてもどうせ対して変わらないだろうと勝手に判断してしまい、実行をスキップしていたのが最大の反省点だと考えています。
そもそもproc/meminfoがどういうものかをきちんと理解していなかったのも駄目だったと思っていてプロセスのメモリ使用量が少ないんだからその情報をみても意味がないと勝手に判断していました。
実際にはしっかりと答えがのっており、思い違いも甚だしかったわけですが。
障害児は愚直なまでに一つ一つの作業内容を確認していくことが最重要だということを改めて思い知りました。
反省ポイント3
今回と同様のslab問題が実は過去に別案件で発生していたらしく、もっと広く障害状況を報告しておけばよかったと思っています。
こういうときに分報のような仕組みがあると見てくれている人からヒントが貰えるかもしれないなと思いました。
障害対応というチャンネルがあれば誰がなにを対応していて、どういう状況か把握しやすくいいのかもしれないと感じました。
良かった点:
メンバーを巻き込んだ
障害発生時にまずチームメンバーに「このような障害が発生している、あわせてこちらでも調査するが緊急度が比較的高いので優先的になにが原因か調べてほしい」と共有したことは良かったことかなと思っています。
当たり前といえば当たり前なのですが結果としてそれが原因究明に繋がったという意味では良かったと思います。
逆に言うとそれくらいしか良かった点がない。
まとめ:
障害対応時にもっとも必要なことは冷静さ、そして1つ1つの作業を確認し現在の状態をしっかりと把握する、その際に憶測でものを考えない愚直さが必要ということを改めて学ぶことになりました。
定期的に障害対応を行わないと焦ってしまって、大事なことをすっ飛ばしてしまうのだなと反省しています。
カオステストはそういう意味では非常に理にかなったテスト手法なのかもしれないと思いました。