diary.sorah.jp

ISUCON5 で準優勝してきた #isucon

eventjournaltech

予選に引き続き、チーム白金動物園として rosylilly, mirakui と ISUCON 5 の決勝に参加した。

なんと 2 位を獲得した。やったぜ! いや fujiwara 組に負けたのは悔しいけど。

分担は予選とあんま変わってなくて、mirakui がインフラ・分析、rosylilly が実装 (あと博打)、わたしが実装とインフラを良い感じにやっていた。

やったこと

白金動物園の解答コードは予選含めて shirokanezoo/isucon5 に push したのでそれを見つつ、最終的に何が変化したかの話を書く。細かい試行錯誤とか、時系列での話は最後に「タイムライン」としてまとめてのせておきました。

利用言語は主に Ruby。補助的に Go で書いたフォワードプロキシサーバーを入れた。

diff 見る限り +2102 -54 lines なんだってさ。 app.rb に対しては +282 -34 であとはその他コードが +203 とか。

マシン構成

  • a: nginx, postgresql, redis-server, app (unicorn)
  • b: nginx, proxy.go, app (unicorn)
  • c: nginx, app (unicorn)

a をベンチ対象にして、nginx で a, b, c にロードバランスしていた。ロードバランス先も一旦 nginx (ポート違い) で受けて nginx 同士で keepalive していた。proxy.go は後述する、一部 API 向けのフォワードプロキシサーバー。

最初 nginx バランスした時は各サーバーの unicorn に 8080/tcp で直接刺しにいく形だったんだけど、当然これだと毎回 TCP セッションを張りにいくので黙って nginx → nginx → unicorn の形に書き換えたのだった。 0d0f8c67 そこそこ効果あった気がする。

unicorn の設定調整

https://github.com/shirokanezoo/isucon5/blob/master/5f/webapp/ruby/unicorn_config.rb

最終的に 1 マシンあたり 20 workers にしたのと、unix socket 化くらいしかしてない。

あとは export RACK_ENV=production を env.sh に書いたくらい。 51d68a58 みんな意外になめてるけど sinatra app なら env が production になるだけで大違いだからな! 感覚値で一番コスパ良いパフォーマンス改善だし 2 万くらい上がったはずだからな!

endpoints のハードコード

https://github.com/shirokanezoo/isucon5/compare/0d61b5371ad6d285777aadb1c60d35843cd13503...9c2c43e2e0d503b67d4f7dcb90a829a978dac399

endpoints に関しては増減ないからハードコードされた。こうする事でエンドポイント毎に挙動修正やりやすかったり手元からの挙動チェックとかも気楽になったりで便利だった。

subscriptions の Redis 化

気持ちの問題。これはあまり直接の効果はなかったけど、まあ subscriptions をいじるときに postgres で消耗しない (うちのチームが postgres 慣れてないっていうのもあったから)、みたいな感じ。

API リクエスト多重化

今回の課題は /data が API リクエストを発行するエンドポイントになっていた。初期実装では subscription により発生する API リクエストはシーケンシャルに実行されていた。一個の API レスポンスが遅いとどんどん遅くなってしまう。仕様としては最終的に結果が揃っていれば良いので API リクエストをさっさと発行して全部揃うのを待つという風にしたほうが高速化する。

cookpad/expeditor っていうまさにこういう microservices 時代のための便利 gem があってそれを使って良い感じにした。これは うちにインターンにきてた amutake_s さんの成果で、実際に cookpad.com の中で使われている。別チーム「 †空中庭園†《ガーデンプレイス》」の同僚 eagletmt も同じ手を使ってくるだろうと思ったけどやっぱり速攻で導入してたっぽいよ。

内部的には concurrent-ruby がやっていることだけどスレッドプールとかつかって良い感じにしてくれる。ほんとうはもうちょっと高度な機能使ってもいい気はした。というかこのへんの細かい 調整一切してなくて笑う。

Ruby は各スレッドがガンガン CPU 持っていく用途では厳しいのは確かだけど I/O 待ちが発生するスレッドがたくさんとかならそんな厳しくないと思う… Go は甘え… 甘えなんじゃ…というのが Ruby に留まった理由の一つ。とはいえ同時に受けられるリクエスト数が worker 数で頭打ちっていうのがあれだけど。

API レスポンスキャッシュ (Redis)

https://github.com/shirokanezoo/isucon5/compare/a172c130076bf3e94934486cda16ed58d004a193...344c7edd10334098aa4aa4fe2f22f6af4c6d28f0

ベンチがコケないで安定するまで最終的に全エンドポイント 1200ms まで短くした、が、、、長くする発想はなかったです…。

一部 API へのリクエスト排他制御

perfectsec, perfectsec_attacked API はそれぞれ X-Perfect-Security-Token ヘッダを渡すのだけど、その中身が同じリクエストを同時に 2 つ以上投げると 429 が帰ってくる仕様だったので、go でフォワードプロキシサーバーをざっと rosylilly に書いてもらって、その API だけそのフォワードプロキシサーバーを通すようにした。当然それは 1 プロセスだけどまあ全然問題はなかった。最初この 429 が出る仕様がよくわからなくてけっこうつらかったなあ。

その他

  • 初手で apparmor を潰した
  • JSON decoder, encoder は oj gem つかった 7592bc11
  • postgresql は a に置いてそれに向けるようにした。bind address の調整と pg_hba.conf いじりだけやった cc4c88df
  • あといくつか CREATE INDEX 1cf0deef
  • ngx_http_gzip_static_module による static file の gzip 配信 a241957f 2b5b6a53 552f67a0
  • static file の Cache-Control ただし意味はなかった a241957f
  • 最終的に無駄なログとか止めたよ c8322898 6927be04

やらなかったこと

  • puma 化
    • commit 7b6a4c13 900ed867 2ddfd24d 25af3197
    • たいして効果なかった…。メモリに困ってるわけじゃないし単純に unicorn worker 数をマシマシにするだけで十分だったっぽい。
  • MySQL 化
    • I/O 多重化の問題と断定した段階で必要ないと思ってやらなかった。一方 Redis に載せるとかはまあ気楽にできるので、効果ないけどやった (これは psql で消耗しなくてすむようにっていう感じの、ただの気休め)
  • C 拡張ライブラリで殴る
    • 問題性質上殴るところが無かった。用意だけはしてた。
    • nghttp2 とくっつけるとかは頑張ってもよかったかも。
  • stackprof とかのプロファイリング
    • 入れたけどほとんど /data じゃん時間かけてもしゃーないわってなった (入れてから無効化されるまで 10 分) 61b49c70 d4edace5

やりきれなかったこと

http/2

perfectsec, perfectsec_attacked は port 8443 に対して https でつなぎにいっていたのを見て即試したら nghttp で h2 使える事を確認した。わりとみんな試してなかったっぽくて意外だった。TLS きたら http2 はすぐ試すもんだと…。

これつかえば 429 絶対出ないんでは、という予想 (実際これは正しかったそう) を元に実装してたけど、どうも protocol_error な GOAWAY フレームが帰ってきたり、そもそも HEADERS フレームは返してくるけど DATA フレームを返してこないみたいな状態が続いてた。

後で聞いたところ nghttp2 と node の http2 ライブラリ(詳細不明) ならちゃんとやりとりできたらしい。ちなみに競技中は http2 起因でめっちゃサーバのプロセスが落ちてたそうな。

うちは http-2 gem つかった実装してたけど、これは低レベル API でしかも「任意のストリーム使えるようにフレーム送受信は自分でやる必要あるよ」というノリなので自分で SSLSocket と ALPN やって IO.select で待ち構えたりするみたいな実装をする必要があって大変だった。 具体的にはこんな感じの実装を書いてうーんうーんとなってました。とにかく GOAWAY (protocol_error) か HEADERS はくるが DATA フレームが永遠にこないみたいな感じ。(そもそも google.com とも稀に上手くいかなくてつらかった)

nghttp2 ならたぶん上手くやれたっぽいなので、tenderlove/ds9 ちょっと頑張って使ってみても良かったなあ。うううううああああああ… ってか今みるとこれ http-2 gem と対して実装量かわんないじゃん。ほんとつらい

rosylilly がちょっと go でためしてダメだった! っていうから完全に諦めたけど、h2-12 だと思い込んでたらしくて h2 に対応してる最新 go の net/http2 は試してないっていうのを今さっきしってなるほど〜ってなったけど、まぁいいや…。うん…準優勝までいったしね…。

キャッシュ戦略

3 秒でダメだから安定するまでとにかく縮めて全エンドポイントでおなじ expiry にしてた。長くすると落ちないという発想はなかった。つらい。

fujiwara 組はどうやら多重化してなくてキャッシュで殴ってたみたいで、つまり同じようにキャッシュ頑張ればもうちょっと得点伸びて優勝だったのではと思うと非常に悔しい。キャッシュ抜きの実装では奴らよ(ry

(まあでも一方で .dat はキャッシュしてなくてとにかく Go で多重化していただけで 18 万らしいので多重化極めたほうが速いのは事実なんだろうなぁ。そもそも言語の速度差もあるか。)

API に対する Conditional GET

Last-Modified な。。。。ごめんねちゃんと API のレスポンスもっと見るべきだった…。

スコアの履歴を取る (ブログ用)

これは対したことないけどスクショ取りそこねた。覚えてないけどなんか低空飛行しながら突然上位にドーンみたいな感じじゃなくてちゃんと線形にスコア伸ばしてたよ!

その他

  • systemctl 叩いてしょっちゅう怒られてた (本選は Ubuntu 15.04 じゃなくて 14.04 LTS)
  • 昼ごはんの選択に失敗して辛さに苦しむ
    • 辛いの食べられないことはないんだけどとにかく汗でてくるのがつらいから予想しない時に辛さ来るとつらい
  • どのタイミングかは忘れたけど開始 1 〜 2 時間時点でこれは I/O 多重化の問題だなぁと断定した。その時点で node.js か go が強い気がするなとはおもってたけど、まあ IO 多重化くらいならなんとかなるやろって Ruby でとりあえずやることにして頑張ってみた。もうちょっとがんばれた気がする。まあ、最終的に perfectsec の 429 問題があって部分的に golang 投入したんだけどね。

準優勝

自分たちが最後に出したスコアは 99996 でそれがランキングに採用されるんだと思ってた (最終計測時のスコアは無視) から、Go Bold が 8 万点台の後に 10 万が出てきて「あぁ FAIL したか…」と一瞬お通夜モードになってました。でも実際には最終計測スコアでランキングを取ってて 10 万点台に乗れた上、2 位で準優勝取れたのは良かった。

これはみんな言っていた事だけど、白金動物園は ISUCON 3 本選で FAIL している。そんな中 ISUCON 4 で出題をやる事になっていろいろありつつも出題をやりきっていた。そして今回の ISUCON 5 では、そんなチームがやっぱり勝てないみたい事が起こるともう業界で生きていくのがすごくつらくなりそうでめちゃくちゃプレッシャーがあった。今回は FAIL 回避でスコアを残した上、しかも 2 位にマークできたのは本当に成長を感じる。

成長に関してはやっぱり ISUCON 4 の出題を担当した事が大きいと思う。技術的に明らかにこれ! という点はわたしにはないけど、確実に何か効いてるな、という思いはある。し、チームワーク・信頼という点に関してはやはり準備期間の数ヶ月、予選本選運営時の諸々の対応でかなり強化されたと思う。人生の 1 ページを共にした経験はかなりでかい。

余談

結局これはなんのアプリケーションだったんだ

/data 周辺以外わたしは本当に何もいじってないせいで user.js とか users に grade という概念があったとかそういう事を懇親会で話題出たりしたけど自分が一切把握してなくて困った。全エンドポイントやスキーマを読み込まないで戦った ISUCON ははじめてかも。たぶんさすがに他のメンバーは把握してるような気がするけど…どうなんだろう。

チームワーク

自慢するけど mirakui はいいリーダーだし rosylilly は信頼できる実装力あるしみんな最高なんやでまじで

今年は二人が喧嘩しなかったので仲裁役は必要なくて良かったです。

— http://blog.mirakui.com/entry/2015/11/01/191848

sora_h と今年は喧嘩してないって mirakui が書いてたけど本当で、 mirakui が俺と sora_h の『喧嘩』と『言い合い』の違いがわかるようになったの、あきらかに ISUCON4 の準備中なのでやっぱり出題しといてよかったな！

— http://rosylilly.hatenablog.com/entry/2015/11/01/214424

自分は rosylilly に対しては何故か「はあ? なんでこんな事も分かんねえんだクズが」という空気感で会話をしていて (たぶん通信の最適化の一種だと思う)、それでも喧嘩にはならず仲良く会話ができる(つもりでいる)。っていうのがあってたぶん外からみると明らかに揉めてるようにしか見えないんだけど、年々 mirakui が慣れていってるのが本当うける。ISUCON 3 の時、何かあるたびにビクビクしながら「まぁまぁ」とか仲裁しようとしてくれてたよね…。今回は横で真顔で普通にやる事をやってるだけになってました。

なんだかんだこうやって まとめてると非同期に各々できることをやるだけやってた。下記タイムラインとかまとめてて思ったんだけど割と本当にみんな全然違うことしてたし、コミットログみてて「へ〜こんな事やってたんだ…。」ってなったりした。というレベルで御互いを信頼して、細かいレベルで何やってるか把握せず、何か指示を出すこともなく、各々で頑張ってた気がする。

なんか 公安9課 っぽい と評された。あまり覚えてないけど この記事 とかで 「我々の間にチームプレイなどという都合のよい言い訳は存在せん。あるとすればスタンドプレーから生じるチームワークだけだ。」 みたいなセリフが引用されてて、その事かしら。

いいチームだと思ってるのでこれからも仲良くしていきたいし来年こそ優勝したいところ。あと mirakui まとめてて思ったけど問題の分析役と仲裁役として非常にお前は大事だから無能とか思わないように。

タイムライン

https://github.com/shirokanezoo/isucon5/commits/master/5f も参考のこと。

開始前

  • 9:20am: sorah「余裕かと思ったけど出るの遅れて 10 時過ぎになりそう」mirakui「総武線が不穏、11 時には間に合うけど 10 時着無理」rosylilly「(応答がない)」
  • 10:11am: sorah 会場着。rosylilly に電話
    • sorah「もしm…」rosylilly「大丈夫起きてる!」「移動中? 今どこ」「(彼がすむ家の地名)」「なるほど!」「タクシー乗った」「なるほど〜〜〜」
  • 10:27am: mirakui 着。彼曰く「rosylilly が遅れるとかちょっとしたハンデなんでね…」とのこと。
  • 11:00am: rosylilly 着

競技

  • 11:06a: とりあえず全サーバーに入って各位の鍵を置いて便利 ssh_config を配る手オペした。あとdstat と htop を入れたりしれっと redis-server も入れておいた。 (sorah)
  • 11:12a: Deploy Key を GitHub の private repo に登録して webapp/ruby ディレクトリをコミットした (sorah) 3d20016d
  • 11:20a: rosylilly か mirakui が psql と睨めっこしてた
  • 11:23a: 「apparmor 消した」 (mirakui)
  • 11:26a: nginx mainline を PPA から入れた。なんかわたしの omnibar は development とタイプするだけで https://launchpad.net/~nginx/+archive/ubuntu/development のページに到達できるようになってて便利なんだよな。 (sorah)
  • 11:48a: ベンチとりあえず回してボトルネックを分析 (mirakui)
  • 12:04p: CREATE INDEX いくつか (mirakui) 1cf0deef
  • 12:09p: endpoints がハードコードされる (rosylilly) 49f7e823
  • 12:09p: unicorn worker 数を 12 に (sorah) d1e1c02e
  • 12:10p: rosylilly 「ローカルの pg に digest 関数ないとか言われるんだけど〜〜〜」 sorah「ググった感じだと CREATE EXTENSION pgcrypto; すればいいっぽい」
  • 12:09p: ハードコードされた endpoints に https がある事に気付いてとりあえず nghttp2 をビルド (sorah)
  • 12:11p: nghttp コマンドでの h2 ネゴシエーション・リクエスト成功を確認、歓喜する (sorah)
  • 12:14p: スコア 2721
  • 12:17p: とりあえず ~isucon/.local/nghttp2/ を全台に置いた (sorah)
  • 12:24p: ローカルで psql にスキーマ取り込んで繋ぐ方法が確立される (rosylilly, sorah)
  • 12:30p: API サーバー向けに ssh LocalForward でトンネルを掘る (sorah)
  • 12:36p: postgres の bind address 修正 (mirakui) 689670cd
  • 12:40p: nginx からの unicorn へのリクエストが 3 サーバーに分散するように (mirakui) cc4c88df f89547a5 82333ec9
  • 12:45p 頃: pg_hba.conf 修正 (sorah)
  • 12:48p: expeditor 導入 (sorah) d68baebb
  • 1:13p: nginx で static ファイル配るように (mirakui) 1078809b
  • 1:16p: subscriptions の redis 化実装完了 (rosylilly)
  • 1:17p: なんか 429 Too many requests でるぴょんということで expeditor 無効化 (sorah) b459b8e6
  • 1:20p: スコア 7797
  • 1:22p: subscriptions redis 化マージ (sorah, rosylilly) 582b185b
  • 1:29p: ngx_http_gzip_module, ngx_http_gzip_static_module の設定 (mirakui) 2b5b6a53
  • 1:45p: なりすましログインが実装される (デバッグ用) (rosylilly) 603f4116
  • 1:49p: js も gzip_type に入るように (mirakui) 552f67a0
  • 1:49p: Cache-Control (mirakui) c1d9d500
  • 1:49p: net-http-persistent による API に対するコネクションプールと expeditor の復活 (sorah) ac397bf0
  • 1:49p: API リクエストのログ取り (sorah) ac397bf0 e8cc6136 64897564
  • 1:49p: http2 の実装開始 (sorah)
    • とにかく苦しかった… いつ諦めたとかは覚えてない。途中から手があいたときに実装を進めて頭をかかえていた
  • 1:52p: キャッシュしていいやつっぽい API を分析提案 (rosylilly)
  • 2:21p: 429 がよくわからんので一旦 worker 数を 4 に (mirakui) a172c130
  • 2:24p: キャッシュの初期実装ができたのでマージ (rosylilly) bef304f4
  • 2:25p: 特別賞まーじかぁーーーってなる
  • 3:08p: token ごとにキャッシュしたりしてなかったのでなおした (rosylilly) 239e7c75 67be1ef3 344c7edd
  • 3:26p: 429 対策でリクエスト並列実行時、1 リクエスト中に含まれる perfectsec, perfectsec_attacked は 1 並列で実行するように (sorah) f47db23f
  • 3:34p: いったん perfectsecs のキャッシュやめてみる (sorah) b98a9f66
  • 3:35p: stackprof 入れた (sorah) 61b49c70
  • 3:43p: キャッシュの expiry 調整 1500ms (sorah) 341d6f13
    • あとやっぱ perfectsecs はキャッシュやめたら一気にスコア落ちたので戻した
  • 3:46p: stackprof 外した (sorah) d4edace5
  • 3:48p: キャッシュ expiry 2000ms (sorah) e0b4dcd3
  • 3:56p: unicornに対して keepalive とかつけようとしてた (実際には unicorn じゃダメ) (sorah) a19e5bff
  • 3:56p: unicorn worker を 6 に (sorah) a19e5bff
  • 3:58p: API リクエストログのフォーマットを集計しやすく直す (mirakui) 382d8a7a a83ab8a1 45358a65
  • 4:00p: nginx →(tcp + http/1.1 keep-alive)→ nginx →(unix domain socket)→ unicorn の形に修正 (sorah) 0d0f8c67 52c4da5d
  • 4:07p: unicorn worker 12 (sorah) 4bab1834
  • 4:14p: スコア 69273
  • 4:24p: puma 入れてみた (sorah) 7b6a4c13 900ed867
  • 4:30p: puma 設定調整 (cluster mode, 3 workers 12 threads) (sorah) 2ddfd24d
  • 4:33p: perfectsec 向けフォワードプロキシサーバー (proxy.go) の初期実装が完成 (rosylilly) 17ea1f97
  • 4:36p: unicorn に戻す (sorah) 25af3197
  • 4:33p: やっぱこの http2 サーバーの実装バグってるよ〜(となってたっぽい) (sorah)
  • 4:37p: なんか上の方にいるけどまだ fujiwara 組が 48k 点くらいなのを見て「この順位はなくなるなぁ」と思ってた
  • 4:42p: proxy.go を試すも Bad Request が出るよ〜〜〜とキレる (sorah) 323c0c9a
  • 4:50p 頃: ちゃんとコードレビューしてたらクエリストリングを捨ててそうだったのでキレる (sorah)
  • 4:56p: 直す (rosylilly) b328fc36 6a9ec521
  • 5:00p: unicorn worker 20 (sorah) 6f63d1ee
  • 5:12p: unicorn worker 32 (sorah) e2e3fc2c
  • 5:15p: proxy.go に GOMAXPROCS 入れわすれてたので入れる (rosylilly) 729d5d83
  • 5:16p: redis の maxclients を 10000 に (sorah) c1e24938
  • 5:20p: pg の max_connection を増やす (mirakui) fa588731
  • 5:23p: unicorn worker を 20 に。あと perfectsec の並列実行考慮を止めた (sorah) 62e4d51f 588d0dae
  • 5:30p: proxy.go において http.Client の使い回しをするように (rosylilly) f910cfc4
  • 5:38p: proxy.go のロック回りの修正 (rosylilly) af22acf3
  • 5:38p: 429 出たらちょっと待って一回だけリトライするように (sorah) 39c1a739
  • 5:38p: nginx の unicorn の手前にいる server で access_log off; (sorah) c8322898
  • 5:42p: API ログを失敗時のみに (sorah) 6927be04
  • 5:44p: RACK_ENV=production (sorah) 51d68a58
  • 5:50p: スコア 99996
  • 5:50p: この後終了までみんなふらふらしだす

まとめ

  • 悔しい
    • 落ち着いてログを見ると対したことやってなくてわたしは無能っぽい。
  • http2 相手がバグってたのほんとつらい
    • あとクライアントライブラリなさすぎて課題だなぁ、高レベル API 持ったクライアントライブラリ書いて一発当てるぞ! みたいな気持ちは持った
  • 今回そこそこ良いスコアだせたのはこういう形で傾向が変わった課題だったからだと思ってるんだけどどうなんだろう
    • とかいってると rosylilly あたりにはったおされる気がする。
  • まあとはいえ業界 2 位か〜っていうのと fujiwara, kazeburo と並べたのは普通に嬉しいし頑張って自己肯定したい。
  • 運営・出題チームのみんなお疲れ様でした、楽しい問題をありがとう!

関連エントリー

Published at