このサイトは24日の早朝2:23頃よりアクセスできなくなっていました。部分的に死んでいて、一部のファイルには引き続きアクセスできるという状況で、blogはDBサーバに繋がらなくなって何も表示されなくなってました。この間、メール受信に使っているsendmailとprocmailは生きていましたが、dovecotは死んでいたので結局メールの確認もできませんでした。さきほどようやく回復しました。

気づいたのは24日の17時過ぎです。blogの管理画面にアクセスしようとして気づきました。気づいてから復旧までに1日以上時間がかかったのは私の不徳の致すところです。昨晩は寝てしまったし、起きてからも子供に邪魔されてまともにPCを操作できなかったので…というのは言い訳です。

落ちている間、sshでログインもできない状況ではありましたが、不思議な方法でログファイルにはアクセスできていました。見ると、メモリ不足のようでした。VPSの管理画面から再起動させようと思ったのですが、なぜか管理画面もエラーになって、にっちもさっちも行かない状況でした。エラーの原因は分かってみれば他愛もないことで、少し前にクライアント(Firefox)のエクステンションを変えた関係でcookieのサイト設定が全部消えた(というか消しちゃった)んですけど、管理画面が使っているcookieがオフになっていたためという…まあ、管理画面も部分的に使えていたので思い当たるまでに時間がかかりました。

だいたい問い合わせフォームもエラーになるんで問い合わせもできなかった。まあ自分の問題でしたから、「しなくて良かった」という話になりますが。

回復としては、その管理画面から再起動させるというだけのもの。80日ぶりのリブートとなりました。100日超えならず。もうちょっと頑張りたいものですね。

メモリ不足のログというのは、例えば以下のようなものです。システムコールでENOMEMが出ていたんですね。

Jul 24 02:40:01 localhost crond[56391]: PAM audit_open() failed: Cannot allocate memory
Jul 24 02:40:01 localhost last message repeated 2 times
Jul 24 02:45:01 localhost crond[32242]: PAM audit_open() failed: Cannot allocate memory
Jul 24 02:45:01 localhost last message repeated 2 times
  :
Jul 24 12:35:44 localhost dovecot: socketpair() failed: Cannot allocate memory
Jul 24 12:35:46 localhost dovecot: imap-login: Can't connect to auth server at default: Cannot allocate memory

blogのエラーログは残っていませんでしたが、mysqldへのconnect()がENOMEMになっていたんでしょう。

しかしメモリ不足のログは連発していたにも関わらず、実際はメモリはスカスカなんですよ。契約では512MB～2GBのメモリが使えることになっている。で、muninも生きていたんですが、muninの描いたグラフが次の通りです。

20日にサービスが変更されて、タダで最大メモリが増えましたが(これを言うとどこのVPS使ってるのかバレますね)、結局ほとんどunusedでして、実際にこのサーバが使っているのは確保が保証されている512MB以下です。この状況はメモリ不足で落ちたと思っている24日早朝でも変わってません。微妙に上がってるけど、512MBよりも上には達していないように見える。

なんだかなぁ。

ひとまずmuninにmultimemory pluginを入れておきました。動きの怪しい奴がいたら毎日リスタートするようにしよう。