Heroku環境にunicorn-worker-killerを入れてみた

Herokuの環境が、メモリが余っているにも関わらずなぜかスワップが発生しているので、パフォーマンスの見直しも兼ねてunicorn-worker-killerを入れてみました。
Unicornがメモリを大量に消費したら、workerを再起動させるというやつです。アクセス数に応じても再起動させることができます。

参考サイト

今まで、スワップが発生するからわざとworker数を少なめ（1Dynoにつき2とか）にしていたのですが、どっちにしてもスワップが発生していたし、これを使えば4とかにできそうなので、応答速度も向上しそうです。うちの場合、Standard-2Xを使っているので、メモリは1GBあるのに、600MB程度しか使えてませんでした。

とりあえずHerokuの環境で動作検証をしてみましたので、そこまでのメモを載せます。

ちなみに私の開発環境は以下の通り。

PC: Mac OSX Yosemite
Ruby: 2.2.3(RVM経由)
Rails: 4.2.4

unicorn-worker-killerのインストール

Gemfileに追加しましょう！

gem 'unicorn-worker-killer'

そしてbundle installしましょう。

config.ruの修正

以下を追加します。

# Unicorn self-process killer
require 'unicorn/worker_killer'

max_request_min =  ENV['UNICORN_MAX_REQUEST_MIN'].to_i || 3072
max_request_max =  ENV['UNICORN_MAX_REQUEST_MAX'].to_i || 4096

# Max requests per worker
use Unicorn::WorkerKiller::MaxRequests, max_request_min, max_request_max

oom_min = ((ENV['UNICORN_OOM_MIN'].to_i || 200) * (1024**2))
oom_max = ((ENV['UNICORN_OOM_MAX'].to_i || 250) * (1024**2))

# Max memory size (RSS) per worker
use Unicorn::WorkerKiller::Oom, oom_min, oom_max

これは、
require ::File.expand_path(‘../config/environment’, __FILE__)
よりも前に書く必要があるようです。

ここまでやったらgitでcommitしておきましょう。
お試しでやってみたい場合はブランチを適当に切ってください。

Herokuに反映させる

じゃあHerokuにとりあえず反映させておきましょう。
remoteはheroku、ブランチはfeature-unicorn-worker-killerを作っていたとします。

git push -f heroku feature-unicorn-worker-killer:master

Herokuで検証する

Heroku Labs: log-runtime-metricsを参考に、log-runtime-metricsを有効にします。これは、Dynoのメモリ使用量などをログに出してくれるようになります。メモリ使用量の増減を見張るために入れます。
–appで指定するアプリ名は適宜変更してください。

heroku labs:enable log-runtime-metrics --app sample-app
heroku restart

次に、ログを垂れ流しにしときます。その際に、余計なログがでてきても困るので、grepします。2つターミナルを立ち上げます。

まず1つめは、Unicornという文字を見張ります。

heroku logs -t --ps web --app sample-app | grep Unicorn

2つめは、memoryという文字を見張ります。

heroku logs -t --ps web --app sample-app | grep memory

config.ruにて、環境変数で設定を変更できるようにしてあるので、これをいろいろ変えてみましょう。

アクセス数に応じて再起動するのを確認

heroku config:set WEB_CONCURRENCY=2 --app sample-app
heroku config:set UNICORN_MAX_REQUEST_MIN=3 --app sample-app
heroku config:set UNICORN_MAX_REQUEST_MAX=5 --app sample-app

Herokuにデプロイしているアプリのworkerに3回以上リクエストがあるとworkerが再起動する設定です（workerが2つなので実際には6回程度）。メモリ使用量(memory_rss)の増減と、workerにkillシグナルが送られているのを確認しましょう。

2015-10-16T07:10:55.935856+00:00 app[web.1]: W, [2015-10-16T07:10:55.935740 #312]  WARN -- : #<Unicorn::HttpServer:0x007f7e19d1a148>: worker (pid: 312) exceeds max number of requests (limit: 5)
2015-10-16T07:10:55.935866+00:00 app[web.1]: W, [2015-10-16T07:10:55.935841 #312]  WARN -- : Unicorn::WorkerKiller send SIGQUIT (pid: 312) alive: 1 sec (trial 1)

ちゃんとシグナルが送られています。

2015-10-16T07:13:40.243479+00:00 heroku[web.1]: source=web.1 dyno=heroku.20197221.f034b862-2494-4332-973f-22341abde3e9 sample#memory_total=223.88MB sample#memory_rss=223.61MB sample#memory_cache=0.01MB sample#memory_swap=0.26MB sample#memory_pgpgin=1231227pages sample#memory_pgpgout=1173982pages
2015-10-16T07:14:00.232265+00:00 heroku[web.1]: source=web.1 dyno=heroku.20197221.f034b862-2494-4332-973f-22341abde3e9 sample#memory_total=202.09MB sample#memory_rss=201.82MB sample#memory_cache=0.01MB sample#memory_swap=0.26MB sample#memory_pgpgin=1500092pages sample#memory_pgpgout=1448424pages

そして、workerが再起動したのでメモリの使用量も減っています。いい感じですね。

さて、これはあくまで確認のためなので、この設定は上限値をあげるか、環境変数を削除しておきましょう。
Unicornのworkerのプロセス数は、Dynoのサイズやアプリのサイズによって適切な値は異なるので、適当に決めてください。
このあたりを参考に。
Heroku Dev Center: Optimizing Dyno Usage

heroku config:set WEB_CONCURRENCY=4 --app sample-app
heroku config:set UNICORN_MAX_REQUEST_MIN=500 --app sample-app
heroku config:set UNICORN_MAX_REQUEST_MAX=1000 --app sample-app

メモリ使用量の変化で再起動するのを確認

あとは、workerのメモリ使用量でちゃんと再起動するかどうかです。とりあえずメモリをたくさん使いそうなページに連続してアクセスしながら、メモリの増減を確認します。

2015-10-16T07:28:50.539770+00:00 heroku[web.1]: source=web.1 dyno=heroku.20197221.dd2b019e-a946-4973-9b1a-16dd7fe0c02f sample#memory_total=695.95MB sample#memory_rss=695.95MB sample#memory_cache=0.00MB sample#memory_swap=0.00MB sample#memory_pgpgin=224829pages sample#memory_pgpgout=46666pages
2015-10-16T07:29:07.142475+00:00 app[web.1]: W, [2015-10-16T07:29:07.142369 #20]  WARN -- : #<Unicorn::HttpServer:0x007f118b0181c0>: worker (pid: 20) exceeds memory limit (229944832.0 bytes > 213930009 bytes)
2015-10-16T07:29:10.431747+00:00 heroku[web.1]: source=web.1 dyno=heroku.20197221.dd2b019e-a946-4973-9b1a-16dd7fe0c02f sample#memory_total=631.29MB sample#memory_rss=631.28MB sample#memory_cache=0.00MB sample#memory_swap=0.00MB sample#memory_pgpgin=262182pages sample#memory_pgpgout=100573pages

workerのメモリが200MB以上になったのでworkerが再起動され、Dynoが695.95MBのメモリを使っていたのが、631.28MBに減りました。

この設定ですが、200MBを超えたら即killされるわけではないので、カツカツに設定するとスワップが発生する可能性もあるので、とりあえず200〜250MBの間にしておきました。この実験中は850MBくらいまでメモリを使った事もあったので、これくらいがいいのかなと思います（あくまでもうちの環境では、の話だけれど）。

まとめ

unicornのworkerの再起動が多すぎても少なすぎてもよくないと思うので、そこらへんは探り探りやっていきましょう。まぁそれでも、わりとworkerを再起動させる設定にしてアクセスしてみましたが、そこまでめちゃくちゃ遅くなるということはありませんでした。なので、アクセス回数もだけれど、メモリの使用量は大雑把に指定していてもいいかなと思います。
これでHerokuのサーバーの性能が安定するといいなぁ。