Bonkura - Kenny

SIerで働く文系SEの記録

さくらVPSにSSHで繋げられない!→「OutOfMemory」が発生していた

いつも通りtera termからVPS(CentOS6.6)に繋ごうとした所、どうもうまく繋がらない。 pingは通るのでサーバが落ちたのではない模様。 コントロールパネルからコンソールを見てみると、
「Out Of Memory〜〜」というメッセージが。。。
これが噂に聞くOutOfMemoryか!

というわけで、人生初のOutOfMemoryの原因を特定し復旧するまでに行った一連の行動をメモしておきます。

再起動

コンソールも固まってるわSSHも繋がらないわなので、
一旦VPSのコントロールパネルから再起動をかけた。

ログ確認

まずはfreeコマンドでメモリの使用状況を確認

$ free -mt
             total       used       free     shared    buffers     cached
Mem:           996        378        617          0         72         87
-/+ buffers/cache:        218        778
Swap:         2047          0       2047
Total:        3044        378       2665

見るべきポイントはfree列の二行目。
再起動後なの大分free領域が多い。

次にvmstatコマンドでメモリの使用状況を確認したが、
こちらの問題なし(再起動してるので当たり前)

次に/var/log/messagesを見てみると。。

$ sudo cat /var/log/messages | grep oom

Oct  3 16:00:57 www12038uo kernel: ruby invoked oom-killer: gfp_mask=0x200da, order=0, oom_adj=0, oom_score_adj=0
Oct  3 16:00:58 www12038uo kernel: [<ffffffff81127782>] ? oom_kill_process+0x82/0x2a0
Oct  3 16:01:06 www12038uo kernel: [ pid ]   uid  tgid total_vm      rss cpu oom_adj oom_score_adj name
Oct  3 16:38:45 www12038uo kernel: ruby invoked oom-killer: gfp_mask=0x200da, order=0, oom_adj=0, oom_score_adj=0
Oct  3 16:38:45 www12038uo kernel: [<ffffffff81127782>] ? oom_kill_process+0x82/0x2a0
Oct  3 16:38:48 www12038uo kernel: [ pid ]   uid  tgid total_vm      rss cpu oom_adj oom_score_adj name
Oct  3 17:08:04 www12038uo kernel: ruby invoked oom-killer: gfp_mask=0x200da, order=0, oom_adj=0, oom_score_adj=0
Oct  3 17:08:05 www12038uo kernel: [<ffffffff81127782>] ? oom_kill_process+0x82/0x2a0
Oct  3 17:08:08 www12038uo kernel: [ pid ]   uid  tgid total_vm      rss cpu oom_adj oom_score_adj name

OOM-Killerrubyのプロセスが殺されまくってる!! この時点で原因を、一昨日くらいに実装したTwitterBotプログラムが原因ではないかと推測。

該当プロセスを特定

この調査中、別シェルでtopコマンドを打って横に配置して見ていたのだが、異変が。。。

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 1884 ********  20   0  444m  66m 6060 S  0.7  6.7   0:04.67 ruby
    1 root      20   0 19232 1504 1220 S  0.0  0.1   0:00.52 init

rubyプロセスが動き続けてる上に、
リアルタイムでメモリの使用領域がバンバン上がっていた。

そこで、当該プロセスIDから詳細を確認

ps -ef | grep 1884

ruby taikin_followback.rb

どうやら、cronで30分ごとに実行している自動フォローバックプログラムがブン回っているよう。。。

とりあえずkillコマンドで当該プロセスを停止し、
ログを確認してみると。。。

2015-10-03 20:40:39 +0900
#<Twitter::Error::TooManyRequests: Rate limit exceeded>

このメッセージが出力され続けている。
ググってみると、TwitterAPIの使用制限に引っかかっているので使えませんよ!
というメッセージ。

中身を確認すると、プログラムがこけた後に、sleep2秒の後にretryする作りだったので、「もうAPI使えないよ!」と言われてるのに、2秒毎に「使わせてくれや」と言い続けていたらしい。

retryではなく終了する様に修正したうえで様子を見た所、out of memoryの発生は収まった模様。
やはりコピペでプログラム書くのはダメだと痛感しましたとさ。