WordPressサイトでメモリリーク?

事故

前々回前回でこのWordPressサイトが、wp-login.phpに対する連続攻撃で不安定になっていたのでBasic認証追加により対応したことを紹介しました。

ところがこれらの対策を施しても、しばらくするとサイトがダウンしてしまい、さらに調査することにしました。

何が起こっているのか?

これは前々回に紹介した状況が継続していました。

減少としてはサーバを起動して20時間ほど経つとディスクがフルになって停止してしまうのですが、状況としては「メモリ不足発生?」→「Nginx/PHP-FPM/MySQLの各サーバでエラーが発生しログ記録」→「ログが膨大になりディスクフル」とという状況です。

下記が各サーバのログに残されていたエラーメッセージです。

  • Nginxのログ(WordPressサイト)
    accept4() failed (12: Cannot allocate memory) 
    (何度も繰り返す)
  • Nginxのログ(静的なサイト)
    accept4() failed (12: Cannot allocate memory)
    (何度も繰り返す)
  • MySQLのログ
    mysqld: 130821 13:38:28 [ERROR] Error in accept: Cannot allocate memory
    (何度も繰り返す)
  • PHP5-FPMのログ
    pre class=”accesslog”>NOTICE: [pool www] child 54787 started NOTICE: [pool www] child 54787 exited with code 0 after 0.001766 seconds from start
    (何度も繰り返す)

したがって「メモリ不足発生」の原因をつけとめなければいけません。

“メモリ不足”の原因調査

“メモリ不足”減少が発生するまで20時間ほどかかるため、原因を突き止めるのはかなり時間がかかりました。

本当にメモリ不足か?

まずは本当にメモリが不足しているのかどうかを確認するために、2分ごとに「freeコマンド」や「cat /proc/meminfo」を実行してメモリの増減状況を確認しました。

私が使っているのはServersMan@VPSのスタンダードプランなので保証メモリは2GB(最大4GB)あります。メモリの使用状況を確認すると800MB~900MBで安定的に推移していました。

しかし、それでもあるとき突然、「メモリ不足」が発生してしまいました。

何度も計測したのですが、メモリ使用量が急上昇することはなく、本当はメモリ不足ではないのではないか?と疑うにいたりました。

ソケット不足?

次に疑ったのはソケットのリソース不足です。ログを見ると「accept failed」ということなので、ネットワーク周りにリソースが不足してソケットの生成ができなくなっているのではないか?と疑いました。

こちらも2分ごとに「netstat -n」で有効になっているソケットの状況を確認しましたが、同時に有効になっているソケットはせいぜい数十個でリソース不足とはいえない状況でした。どうも違うようです。

VPS(OpenVZ)固有の現象か?

どうも本当にメモリ不足になっているとは思えません。

ほかに可能性がないか調査していたところ、/proc/user_beancountersというところに使用可能なリソースの上限が記載されていることがわかりました。

cat /proc/user_beancounters
Version: 2.5
       uid  resource          held   maxheld   barrier    limit  failcnt
    xxxxx:  kmemsize      11559744  27299652  71130480 73660496        0
            lockedpages          0       256       256      256      743
            privvmpages     206066    245186   1048576  1114112        0
(以下省略)

調べてみると、どうやらOpenVZ(ServersMan@VPSで使っているVPSシステム)の設定状況を示していて各ユーザ(各サーバ)が使用しているリソースの現状(heldの列)と上限(barrierとlimitの列)を示していることがわかりました。

ここで表示される値を継続的に確認したところ「dcachesize」という値が増え続けることがわかりました。原因に近づいて来た気がします。

dcachesizeとは?

こちらもググって見ます。OpenVZ.orgのWikiでは次のように説明されていました。

The total size of dentry and inode structures locked in memory.

Dcachesize parameter controls filesystem-related caches, such as directory entry (dentry) and inode caches. The value accounted into dcachesize is also included into kmemsize.

(以下省略)

どうもメモリ上にロックされている「dentry(ディレクトリ情報)」と「inode(各ファイルの情報)」の合計サイズのようです。

ファイル関係の処理が続くと増える可能性がありそうです。ただ、「キャッシュ」というぐらいなので、上限に近づいてきたら破棄して欲しいのですが・・・

このサイトのdcachesizeの状況

怪しいとわかったらdcachesizeの増減傾向を確認してみます。再び2分ごとに記録してみます。その結果が下記のグラフです。

image

横軸は記録を開始してからの経過時間です。次の例外を除きほぼ単調増加であることがわかりました。

  • 記録を開始してから約3時間後に一度大きく減少すること
  • 記録を開始してから約3時間後から7時間後の間は増減を繰り返すこと

そして、記録開始から約22時間後に上限を突破し、サイトがダウンしました。

まだ調査する必要はありますが、dcachesizeの増加がサイトダウンの原因であることは確かなようです。

まとめ

今回はこのサイトで発生したメモリ不足の原因が、OpenVZの管理している値である「dcachesize」が増加し、上限を超えているために発生していることを突き止めました。

次回はdcachesizeの増加をとめる方法を検討します。