2014年11月

ISUCONでUnicornをRaptor(Phusion Passenger 5)化したときのパフォーマンス

現実的なWebサービス環境において、Raptor(Phusion Passenger 5)によるパフォーマンス向上がどの程度のものか調査するために、 ISUCON4 の予選問題のうち、Unicorn 部分を Raptor 化してベンチマークをとってみた。典型的なWebサービスシステムの3層構造(Proxy, App, DB)を構築し、ベンチマーカーにより高ワークロードを実現できるので、ISUCON の予選問題は適当な題材といえる。

EDIT: Unicornの2倍のパフォーマンスを実現したRackサーバ「Rhebok」をリリースしました - blog.nomadscafe.jp を参考に unicorn の worker_processes を 4 に調節しました。念のため、あわせて raptor の min-instances も 4 に調節して再計測しました (2014/12/19)

ベンチマーク条件

基本的に、ISUCON4予選のレギュレーションに則る。

インスタンスタイプ: m3.xlarge CPU: Xeon E5-2670 v2 @ 2.50GHz 4 vCPU メインメモリ: 16GB RAM ストレージ: EBS Magnetic volumes OS: Amazon Linux 3.14.19-17.43

* ここまで y_uuk1 テンプレ

  1. ISUCON4 予選のデフォルト状態(unicorn)
  2. ISUCON4 予選のデフォルト状態(raptor standalone に変更)
  3. kazeburo の術 を適用(unicorn)
  4. kazeburo の術 を適用(raptor standalone に変更)
  5. kazeburo の術 を適用(raptor on nginx に変更)

で比較する

kazeburo の術 Ruby 版

ISUCON4 予選でアプリケーションを変更せずに予選通過ラインを突破するの術 から以下の3つを除外した形

  • memcached
  • perl 関連 (cpanfile や app.psgi の変更)
  • /etc/supervisord.conf の変更

init.sh に以下を追加

$ cat init.sh 
cat <<'EOF' | mysql -h ${myhost} -P ${myport} -u ${myuser} ${mydb}
alter table login_log add index ip (ip), add index user_id (user_id);
EOF

/etc/sysctl.conf に以下を追加。

$ cat /etc/sysctl.conf
net.ipv4.tcp_max_tw_buckets = 2000000
net.ipv4.ip_local_port_range = 10000 65000
net.core.somaxconn = 32768
net.core.netdev_max_backlog = 8192
net.ipv4.tcp_tw_reuse = 1
net.ipv4.tcp_fin_timeout = 10
sudo /sbin/sysctl -p

で適用

/etc/nginx/nginx.conf の設定

$ cat /etc/nginx/nginx.conf
worker_processes  1;

events {
  worker_connections  10000;
}

http {
  include     mime.types;
  access_log  off;
  sendfile    on;
  tcp_nopush  on;
  tcp_nodelay on;
  etag        off;
  upstream app {
    server unix:/dev/shm/app.sock;
  }

  server {
    location / {
      proxy_pass http://app;
    }
    location ~ ^/(stylesheets|images)/ {
      open_file_cache max=100;
      root /home/isucon/webapp/public;
    }
  }
}

/etc/my.conf の設定

$ cat /etc/my.cnf
innodb_buffer_pool_size = 1G
innodb_flush_log_at_trx_commit = 0
innodb_flush_method=O_DIRECT
Ruby 専用の追加設定


env.sh に以下を追加

export RACK_ENV=production 

unicorn_config を以下のように変更(2012/12/19 追加)

worker_processes 4
preload_app true

Procfile を以下のように変更

unicorn: bundle exec unicorn -c unicorn_config.rb -l /dev/shm/app.sock

再起動して適用

$ sudo service mysqld restart
$ sudo supervisorctl restart isucon_ruby
$ sudo service nginx restart

Raptor への切り替え(standalone)

Gemfile

- gem "unicorn"
+ gem "passenger", "= 5.0.0.beta1"

Procfile (unicorn_config.rb で worker_processes 4 としたので --min-instances を 4 にしてみた)

- unicorn: bundle exec unicorn -c unicorn_config.rb -l /dev/shm/app.sock
+ passenger: bundle exec passenger start --min-instances 4 -S /dev/shm/app.sock 

Raptor on Nginx

passenger を nginxに組み込んで動かす

2.5. Generic installation, upgrade and downgrade method: via RubyGems の手順で

gem install passenger --pre -v 5.0.0.beta1

nginx を passenger module 付きでビルドしなおす。nginx は消さなくてもいいよ、と書いてあったがいちおう消しておいた

sudo yum remove nginx

g++ がない、と怒られたのでいれておく. インストール先ディレクトリも作っておく

sudo yum -y install gcc-c++
sudo mkdir /opt/nginx
sudo chmod a+w /opt/nginx

passenger gem に入っている以下のコマンドでビルド&インストール

$ passenger-install-nginx-module --auto

/opt/nginx/conf/nginx.conf を以下のように変更 (kazeburo の術仕様)

worker_processes  1;

events {
  worker_connections  10000;
}

http {
  passenger_root /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1;
  passenger_ruby /home/isucon/.local/ruby/bin/ruby;
  include     mime.types;
  access_log  off;
  sendfile    on;
  tcp_nopush  on;
  tcp_nodelay on;
  etag        off;

  server {
    listen 80;
    root /home/isucon/webapp/ruby/public;
    passenger_enabled on;
passenger_min_instances 4; location ~ ^/(stylesheets|images)/ { open_file_cache max=100; } } }

public ディレクトリが config.ru と同じ階層にないとダメなので、symbolic link をはってごまかす

ln -s /home/isucon/webapp/public /home/isucon/webapp/ruby/

起動

sudo /opt/nginx/sbin/nginx

ベンチマーク結果

  • benchmarker の workload 指定は全て 8 (一定)
構成スコア
unicorn(default)2433
raptor standalone(default)2483
unicorn(kazeburo)40983
raptor standalone(kazeburo)40359
raptor on nginx(kazeburo)40358

unicorn の場合は kazeburo の術で4万超えていなかったが Raptor で 4万超えの結果となった。Introducing Phusion Passenger 5 beta 1, codename “Raptor” の記事で彼らが「Hello World ベンチの結果なんてたいして意味がないんだよ」と言っていた通り現実に近いアプリで評価すると確かに4倍とはならなかったが、それでも ISUCON 民としてこの結果はうれしい。

(2014/12/19) unicorn とあまり変わらない結果となった。Introducing Phusion Passenger 5 beta 1, codename “Raptor” の記事で彼らが「Hello World ベンチの結果なんてたいして意味がないんだよ」と言っていたのでそんなものかもしれない。後述するが fail があったので、その影響は大きそう。

passenger module 組み込みの nginx をビルドして動かしてみたが、スコアは変わらなかった。

Raptor のエラー

なお、Raptor で以下のようなエラーが出ていた。こちらの Issue で対応中のようだ。

03:33:52 passenger.1 | App 6297 stderr: /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1/lib/phusion_passenger/config/system_metrics_command.rb:32:in `exec'
03:33:52 passenger.1 | App 6297 stderr: : No such file or directory - /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1/buildout/support-binaries/PassengerAgent (Errno::ENOENT)
03:33:52 passenger.1 | App 6297 stderr:         from /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1/lib/phusion_passenger/config/system_metrics_command.rb:32:in `run'
03:33:52 passenger.1 | App 6297 stderr:         from /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1/lib/phusion_passenger/config/main.rb:75:in `run!'
03:33:52 passenger.1 | App 6297 stderr:         from /home/isucon/.local/ruby/lib/ruby/gems/2.1.0/gems/passenger-5.0.0.beta1/bin/passenger-config:37:in `<main>'

また、これとはおそらく原因が別だと思われるが benchmarker では以下のような結果がでて、ちょくちょく fail していた。

04:57:45 type:fail      reason:Expected selector is not found: //*[@id='notice-message']        method:GET      uri:/
04:57:45 type:fail      reason:Expected html text is match: This account is locked., got Wrong username or password     method:GET      uri:/

画面を直接さわると正常に動いているように見えるので、並列で高負荷をかけた時の問題だろうか、と推測している。

04:45:33 type:score     success:185820  fail:5584       score:40141

stable 版になって、全てが success に転じるともっと得点が伸びる期待がある。

Isucon4 本戦に参加して17位でした (GoMiami)

ISUCON4 本戦 に参加した記録。 チーム名は GoMiami で、@Spring_MT、@niku4i、自分(@sonots) の三人で参戦してきました。 結果は ISUCON4 本戦結果 の通りで、 8位〜24位が 8000 ± 400 点の団子状態になってて 8017 点の 17 位という結果でフィニッシュでした

事前準備

予選は1台構成だったから、Golang 使えばプロセス間メモリ共有とかいらなかったけど、本戦だと複数台になって結局必要だから、慣れてる Ruby でよさそうって話してて、本戦は Ruby で出る事にした。

ということで、予選の問題をさらにチューニングしたり、Ruby で解き直したりして、cheatsheat のアップデートしたりしてた。

golang で sql, template, http リクエストのパフォーマンスメトリクスとるライブラリ作った #isuconの ruby 版も欲しいなぁと思ったので、sinatra-template_metrics とか、mysql2-metrics とかも作ってた。ruby だとメタプログラミングできるのでサクっと作れて簡単だった。(結局使えなかったけど)

あと、複数台構成になるから、複数サーバをさくっとセットアップできるように、niku4i に chef レシピ用意してもらって、それぞれのマシンで dstat とか top を同時に動かして見るの辛そうだから何かメトリクスツール欲しいなって話してたら、td-agent からデータを Google App Script に毎秒投げて、Google Spread Sheet でグラフ化するというものをさくっと作ってくれてた。これで帯域詰まってるの一目瞭然だったしすごい便利だった。GAS (Google App Script) 職人すごい。niku4i++

最初にやったこと

まず最初は予選の時と同じく、レギュレーションしっかり呼んで、アプリ動かしてメトリクス取ってみて、コード読んだり、アプリ触って動作把握したりという基本の作業をしてた。この最初の段階で取れたメトリクスはこちら

sum(sec)         count   avg(sec)
428.534019 358 1.197022402 GET /slots/:slot/ads/:id/asset 61.50906600 22 2.795866636 POST /slots/:slot/ads 14.64960199 86 0.1703442093 GET /me/report 7.29174599 358 0.02036800558 GET /slots/:slot/ads/:id/redirect 6.53089999 358 0.0182427374 POST /slots/:slot/ads/:id/count 4.072345000 358 0.0163805294 GET /slots/:slot/ad 3.499311999 358 0.00977461452 GET /slots/:slot/ads/:id 0.233793 5 0.0467586 GET /me/final_report 0.059209 1 0.059209 POST /initialize

明確に動画のPOSTとGETで時間かかってるかんじだった。あと、I/O負荷が高かった。

この時点で、1回ミーティング開いて、どういうアプリかシェアしたり、どういう戦略でいくか決めたりしてた。この時に出たアイデアはこんなかんじ

  1. 去年と同じく benchmarker のオプションに複数台指定して、分散アクセスしてくれる仕組みのようだったので、 フロントで帯域制限とかあった場合に、フロントを3台全部に分散させて受け取ったほうが絶対よさそう
  2. 動画は redis に保存されてるけど、それぞれのマシンのメモリ容量が1GBしかないので、スループットあげたら、 1台じゃメモリ足りなくなりそう。redis 3台に分散させたほうがよさそう(これ、benchmarker が投げて来る動画の種類は実際の広告と違って限られてるのでうまく再利用すれば気にする必要なかったかも => 後記: その戦略は利かないとのこと)
  3. 1番のマシンだけ CPU コア数が 2 じゃなくて 1 なので、その1台はあえて別の使い方をしたほうが良いのかも
  4. I/O負荷が高い。動画をPOSTされた時にデータを redis に突っ込前に、RackMultipart が一旦ディスクにファイルを吐き出してしまっているっぽい。tmpfs 使うようにしたほうがよさそう。
  5. 動画をGETする所で、Range ヘッダを見て、ruby で動画ファイルを分割して返しているっぽい?あらかじめ range で切った動画を作って保存しておいたほうがよさそう(これは、Range ヘッダのパターンを洗い出そうと思ってログ取ったら、benchmarker からのリクエストは常に空だったので関係なかった。コメント読むと Chrome 特別対応だったぽい)

とりあえず3台有効に使う分散構成取れるように実装しようって話して、分担して作業することにした。 お弁当並んでたから食べようと思ったら、13:00 までダメです!って言われてたのがこの辺。

実装作業

以下の作業を分担して実施した。

1. redis の書き込み/読み込みをシャーディングする (sonots)

key を適当なハッシュ関数(key.bytes.inject(:+) % 3)に通してどの redis に書き込み/読み込みするか決定することで分散するようにした。けっこうサクっと終わった。

2. final_report 用の log をどこか1つのサーバに保存 (SpringMT)

アプリを分散するとなると final_report 用の log をローカルファイルに書いていたのをやめて、 どこか1つに集約して保存する必要がありそうだった。ので、そこを改修。

3. Range のパターン洗い出しと、あらかじめ切ってキャッシュ (niku4i)

ログ取ってみたら、結局 Range 使われてなかったらしい。

4. rack の一時ファイル保存先を tmpfs にする。ファイルが残っても無駄に容量が使われるだけなのですぐ消す (sonots)

一時ファイルの保存ディレクトリを変更するやり方が分かってなかったので調べながら。オプションなどは提供されていないので、Rack のコードを直接いじる必要があった。rack/multipart/parser.rb#L104

5. その他ミドルウェアの設定変更とか (niku4i)

/ を nginx で返してもらおうと思ったけど、そこ benchmarker 使ってなかった。


分散構成自体では得点は伸びなくて(それはわかっていた)、Rack の一時ファイルを tmpfs にしたことで、ローカルで 11000 ぐらい出るようになったけど、remote では 3000 ぐらいしか出なくてうーん、って感じになってた。redis はシングルスレッドだから詰まっちゃってたのかな?要確認。

次にやったこと

これじゃ全然ダメだから構成変えようって話してて、 動画を redis にいちいち送りこむより、nginx で POST された動画をディスクに吐き出して、GET 時にローカルから読み込んだほうがよさそう、という話になったので構成を進化させた。 Range は全然使われてなかったし、気にせず動画を nginx から返すだけでよさそう。

それで、nginx で POST の動画部分だけ取り出して書き込んで、GET 時にそれを返すとかやりたかったんだけど、POST データのうちの一部(動画)だけ取り出すやり方がわからなかったので、 unix domain socket でつながっているローカル app に送り込んで、RackMultipart が吐いているファイルを nginx で指定している public ディレクトリ以下に mv するような形にした。この時点で tmpfs 対応は revert された。

フロント nginx 1台. app 三台. コア数が違うので host1 には weight1, host2 には weight2, host3 には weight2 で振る、という構成になった。

これでローカルでは 22000 ぐらい?うろおぼえ。remote では 8200 ぐらいでてて、remote では帯域で詰まっちゃってたからもう、わからんなーってかんじになった。

フロントを nginx 3台にして、動画ファイルがPOSTされたらアプリで他の2台にも scp で撒く、というアイデアも出たんだけど、みんな 8000 点台で止まってるし、そこを変えてもブレークスルーにはならない感じで、むしろ scp する分遅くなりそう、って話してて結局ちょっとパラメータチューニングして、レギュレーションクリアするための再起動動作確認したりとかしてフィニッシュしてしまった。

スコアが remote とローカルで全然違ってて、remote で試そうとすると queue 待ち10分とかで remote 側で全然検証できなかった。それができてたら scp 実装も試しにやってみてたかもしれない。もっと、remote benchmarker 走らせるマシンいっぱい用意してくれてたらうれしかったな。もしくは、benchmarker の実装に帯域制限いれて、ローカルでも似た挙動するようになってるとか。
 

懇親会で聞いた話

レスポンスの JSON の url を変更すると、どのホストに動画を GET しにいくか制御することができたらしい。なので、フロント nginx が3台でも、全ホストに動画を撒くなんてことをせずに、動画のあるホストを指定できたとのこと。 とはいえ、今回は benchamrker 実行ホスト側の帯域でつまってたから、その構成にしてもスコアはあんまりのびなかったらしい。けど、これがサーバ側の帯域で詰まっていたとしたら、三台構成取れてた他チームから大差でまけてたと思った。

あとは、redirect して返すエンドポイントは 200 で body つけて返せば1リクエスト減らせたし、 動画の配信順序も1度スロット全部返せばあとは1個固定でいいからサイズが小さいやつ(といっても、5.4M か 5.3M かの 5.3M のほうだけど)だけ返すようにしたり、動画自体は得点にはならないからエラーで返してしまえば減点にはなるけどひょっとしたら最終得点は上がるかもしれないと思って試したけど 25% 超えて FAILURE になってしまったからダメだった、とかモ○ス氏は言ってたし、そういうの全然試せてなかったな、と思った。キャッシュコントロールだけじゃない。

おわりに

benchmarker が賢いとか全然思ってなくて、benchmarker の挙動を追うことを全くしてなかったので完敗としか言えない。 リクエストヘッダすらみてなかったので、去年 RubyConf 行ってて本戦欠席してしまった経験値の低さが露呈された。 とりあえずリクエストヘッダをログを出すようにして、benchmarker の気持ちでチューニングできるようになろう。

運営の皆様お疲れさまでした!  

Mobage を支える Ruby の技術 ~ 複数DB編 ~

Rails 複数DB Casual Talks で話した資料です。これで君も複数DBだ!!(変なテンション

 
追記:質問をみつけたので答えておきます


これに関しては「コネクションプーリング都市伝説」論争というのを調べるとたくさん情報が出てくるのだけど、MySQL の場合新規接続コストが安いのでリクエストごとに接続してもパフォーマンスにあまり影響がなかったりします。実際、mobage はこの方式で大量アクセスを捌いているのでそのぐらいのパフォーマンスは出ると思って良いでしょう。

ただし、AR が実際にやっているのは mysql2 の新規接続だけではないので、それよりはコストが高く、モデルの数が 1000 個とかいう特殊な環境になると、 それなりのコストになりそうです。

ということで、某ク社の若者に、何リクエスト毎に接続を切るのか指定できるオプションを追加する PR を受けているので、そちらの機能がご利用頂けます。
Introduce max_requests parameter to clear connections per some requests. #1

コストが高い場合は、この max_requests オプションを利用すると良いでしょう。モデル数が常識的な範囲内であれば気にする必要はないと思いますけどね :D

cf. Rails(ActiveRecord)でデータベースへのコネクション 
cf. RDBMSでコネクションプールが必要な理由、わからない。 - Togetterまとめ 

rblineprof-report released!

RubyKaigi 2014 で tmm1 氏が話してた rblineprof ですが、普通に

require 'rblineprof'

target = /./
profile = lineprof(target) do
  sleep 0.1
end
puts profile

みたいな感じで使うと、

{"example.rb"=>[[102941, 0, 0, 87, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [102941, 87, 1, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0], [0, 0, 0, 0]]}

とか出て来て意味不明である。

ということでそれをラップしていい感じに表示してくれる rack-lineprof なんてものがあるのだが、それだと rack アプリでしか使えないので、普通の ruby アプリでも使えるように rblienprof-report というものを作った。基本的にやってることは rack-lineprof と同じ。

使い方は簡単で、lineprof の出力結果を食わせるだけ。

require 'rblineprof'
require 'rblineprof-report'

target = /./
profile = lineprof(target) do
  sleep 0.1
end

LineProf.report(profile)

これで以下のように出力される。

[LineProf] ===============================================================

example.rb
               |   4  target = /./
               |   5  profile = lineprof(target) do
 102.9ms     1 |   6    sleep 0.1
               |   7  end
               |   8

profile 結果を食わせているだけなので、rblineprof 側にオプションが増えるとか API のインターフェースが変わるなどしても profile のデータ構造さえ変わってなければ追随の必要がない。

端末にバイナリを表示してしまって壊れた場合の直し方

まずは reset コマンドを試す

$ reset

それでもダメだったら以下。 ^vは Ctr-v、^[ は Ctrl-[ または Esc キー

$ echo ^v^[c

それでもダメだったら端末再起動

A Ruby and Fluentd committer working at DeNA. 記事本文および記事中のコード片は引用および特記あるものを除いてすべて修正BSDライセンスとします。 #ruby #fluentd #growthforecast #haikanko #yohoushi #specinfra #serverspec #focuslight
はてぶ人気エントリー