ISUCON5で優勝してきました
毎回素晴らしいイベントを主催されているLINE株式会社様、毎回ホスピタリティあふれる運営に尽力されている@941さん、出題の@tagomorisさん@kamipoさん、その他協賛企業や運営スタッフの皆様に感謝申し上げます。
ということで、ISUCON5に出場し、優勝してきました。
ISUCON1の優勝チームの再結成で @fujwiara, @sugyanと僕というメンバー構成です。4年前のISUCON1の時にチーム名を「fujiwara組にしよう」と強く言ったのは実は僕で、そのまま僕が代表者として申し込んだのですが、まさかここまでfujiwara組ブランド(?)が定着するとは思いませんでした。今年もfujiwaraさんの力が大きい勝利ですが、僕も大分貢献できたと思います。
ということで当日を振り返ります。
お題
外部APIを叩くネタで驚いた。可能性は考えていましたが、まさか来るとは思っていなかった。ブラックボックスなサブシステム作るのは問題作成側のリスクが大きい。実際、毎回ベンチマーカー作成であれだけ苦労してるのに、まさか別のサブシステムとしてAPIサーバーを用意してくるとは、問題作成チームに脱帽です。
環境構築 (11:00-12:00)
ちょっと時間がかかったが、ローカルでアプリケーションがちゃんと動く環境を整えた。時間はかかったが結果的にはここをしっかりやったので後続の開発はスムースだった。
- Squidでhttp proxyを立てて、APIをローカルから叩けるように
- fujiwaraさんがサクッとやってくれた
- Postgresのextension読み込んでdigest関数が動くように
- sugyanがやり方調べてくれた
sugyanはサクッとローカル開発環境を整えていんだけど、僕はポスグレのユーザー権限とか、HTTP_PROXYに設定する値を間違えてたりする凡ミス連発でハマり大分時間がかかってしまった。ドツボにはまりかけてるところでsugyanに見てもらって設定ミスを指摘してもらってなんとかなった。ただ、ここで20分くらい無駄にしたので申し訳なく思う。
ポスグレに関しては、最近業務で使っているので、 psql シェルの使い方とかでハマることは無かったのでこれは完全に良かった。
作戦 (12:00-13:20)
とりあえず、ベンチを回してアクセスパターンを調べてみたら、案の定 /data が支配的。以下について作戦会議。
- キャッシュ戦略
- 言語をどうするか
エンドポイント一覧を見る限り、7つ中4つ(県と名前)のAPIはかなりキャッシュが効きそうだったが、残りの3つ(天気とperfectsec系)に関しては細かい調整が必要であるように感じた。
キャッシュをプロキシ側で頑張ろうとfujiwaraさんがしてたんだけど、あまりうまくいかないから撤退。アプリ側でキャッシュしようということに。
その場合、言語をどうするかで議論になった。具体的にはPerlにするかGoにするか。
APIリクエストを平行に処理できたほうが有利に決まっているので、Goで行くのは良さそうである。ただ、そんな言語特性に依存した問題や、「APIリクエストを平行に処理したら優勝出来ました」みたいな安直な問題がISUCONで出るはずがない。最後の方では外部APIに応じた細かいキャッシュの調整が肝になるだろうという予感があったので、その辺の調整が素早くやりやすそうなPerlにした。この辺は言語特性と言うよりかは慣れの話です。
ここの方針策定が二転三転し、結果的にアプリの改修に手を付け始めたのが13時20分頃になってしまった。遅すぎである。この時点では、3万点くらいは行ってるチームがあるにもかわらず、こっちはまだ初期スコアなので焦り始める。
キャッシュ実装 (13:20-14:30)
キャッシュさせる内容はシンプルだったので、Redisじゃなくてmemcachedでよかろうということに。
第一手として、DBに入ってるAPIのエンドポイント一覧を変数化したのがよかった。DBから引いたハッシュの配列をData::Dumperで雑に変数化。先にも書いたとおり、APIのエンドポイント一覧は不変であり、エンドポイント毎のキャッシュ調整が最終的には重要になる予感があった。なので、これはDBにアクセスが行かなくなる以上の効果があった。初動は遅れたが、この初手はかなりいい手が打てたと個人的に思っている。
とりあえず最初は愚直に全部キャッシュするようにした。ここで、URLとパラメーターをJSON化したものをmemcachedのキーにするということを思いつきでやったがうまくいった。(最終的にはヘッダもキーに含めた)
これだと案の定ベンチが安定しなかったので、指定したserviceだけcacheを使うという変更をsugyanが入れてくれて、その後でエンドポイント毎にキャッシュ秒数を制御できる設定も入れた。ここまでの実装の流れは想定内。指定されたserviceだけcacheを使う変更に関しては、僕がまさしく全く同じ修正をしようと考えており、それをsugyanがシュッとやってくれたので「我が意を得たり」という息の合い方だった。
この時間内で他にやったこととして、user.jsをアプリケーションで生成してるの無駄だなーという感じだったので、ダミーファイル返すようにした ら、これはちゃんとベンチマーカーが中身を見ていてfailしてしまったので、Revertした。GithubのRevert機能便利。
この時点でGoBoldは10万点超えで特別賞獲得。こっちはまだ複数台構成で満足にベンチも通せてない状態。焦る。
複数台構成やインフラ調整 (14:30-15:15)
一旦インフラ側とアプリ側の作業を結合して、この辺で複数台構成で動くように。
- 複数台構成
- 静的ファイルのNginx配信とgzip
- キャッシュ秒数調整
ベンチが安定しないので悩んでいたら、/initialize がsystemで手元のpsqlを呼び出しているから、ちゃんと本番DBに向くとは限らないということに気づいた。/initialize の処理を書きなおそうとしたら、fujiwaraさんが一瞬でNginxの設定で、/initializeの処理はDBが入ってるサーバーにしか振り分けられないようにしていて流石であった。
キャッシュの秒数は、perfectsec系はキャッシュせず、天気は10秒、残りは無期限とした。それで6万点前後はfailせずコンスタントに出るようにはなった。ただまだ6万点だし、キャッシュがどれくらい安定しているのか確信が持てない状態。トップを走るGoBoldは遠いが伸び悩んでいるので、キャッシュ調整に苦労している様子が伺える。
迷走 (15:15-16:00)
まだアプリは安定しているとはいえずスコアも低い。初動が遅れて他のチームに差をつけられていることもあってチームはかなり焦っていた。
この時点で細かいキャッシュの秒数調整をしても良かったんだけど、もうちょっと次の一手を打ちたい雰囲気だった。特別賞が10万点で14時過ぎにはGoBoldがそこを突破している。なので優勝スコアは20万を超えてくることが予想される。それに引き換えまだ6万点しか出せてないのだ。ここでキャッシュ秒数を調整するだけで優勝できるとは到底思えなかった。もう一個大きな手を打つ必要性を感じていた。
この判断はあまり正しくなかった。少なくともキャッシュ秒数の調整はこの時点でもう少しやっておくべきだった。結果的にはキャッシュ秒数の調整で優勝できたし、その優勝スコアも15万点にとどまった。ただ、 .dat チームがfailしなかったら18万点なので、そうなるとやはりキャッシュ調整だけでは勝てなかったことになる。なので全て結果論でしか無い。
この時間帯にやったことは、予選のように /initialize 時点でキャッシュを載せることも検討したので、キャッシュをRedisに差し替える実装を書いたりしていたが、それは結局捨てた。
結局出てきた方針としては、fujiwaraさんがサーバー間のレイテンシがバカにならないことを指摘、memcachedのラウンドトリップタイムにも結構時間がかかってるので、memcachedへのmulti get/setを使うことを提案。これはかなり良い方針だったのでやはりfujiwaraさんが流石だよなーと今にしても思う。
それに加えて、飛び道具としてmemcachedプロトコルをしゃべるサーバーをGoで書き、そこでキャッシュの制御もしてしまおうという話になった。どうしてもPerl側でAPIリクエストを並列化するのは難しいので、そこをGoに任せてしまうという発想。fujiwaraさんがmemcachedプロトコルをしゃべるサーバーはGoで書いたことがあるということだったので(マジか)、そこはfujiwaraさんが実装することに。キャッシュのキーがJSONだったことも偶然だが功奏で、キーに応じたキャッシュ制御を組みやすかった。
Go側の実装ができればPerl側ではキャッシュサーバーの向き先を変えるだけで良いという非常に綺麗な作戦だった。
ただ、もう16時でとにかく時間がない。この実装が終わるか終わらないかに勝負が委ねられたがギャンブルに近い。その時はそう思っていたし、正直それが完成しても劇的にスコアは上がらないのではないか、もうこれは惨敗かもしれない、とか僕は少し絶望的な気分になっていた。
キャッシュ改善実装とペアプロ (16:00-16:30)
16時くらいからキャッシュのmulti get/setの実装を始めたが、焦っていて全然頭が働かない。これはヤバイと思ってsugyanに横から見てもらいペアプロした。これはメチャクチャ助かった。バグりそうなところで的確に指摘してくれたし、より良い実装のアドバイスももらった。結果的に15分程度でバグなく実装することができ、一発でベンチも通った。これはかなり大きかった。
Goのキャッシュサーバーの実装待ちと細かい調整 (16:30-17:40)
あとは、fujiwaraさんのキャッシュサーバーの実装待ちになった。sugyanはfujiwaraさんのサポートでペアプロ、僕はやることがなくなってしまったので、ちょっとでも改善できない所はないかと必死で探した。この時間帯にデプロイのやり方とか教えてもらってキャッシュの秒数調整できれば良かったなーと後から思う。ただ、fujiwaraさんもこの時間帯は大分熱くなっていたので、信じて待つしかないような状態だった。
この時間帯に僕がやったことは以下の2点。
後者の修正はそこそこ有効だったように思う。「サーバー間のレイテンシが結構あるからなるべく通信を発生させないようにしたい」というオーダーをfujiwaraさんから受けていたので、なんとか改善出来て良かった。 / へのアクセスなどはDB一発しかクエリが飛んでないにも関わらず、 35msecかかっているような状態だったので、これが入ったことでDBアクセスは皆無になり改善された。この時点では大きなスコアアップにはならなかったが、最終スコアを爆上げできたのはこの変更はかなり寄与しているように思う。
この辺りの修正は相当慎重におこなったが、バグなくベンチも一発で通ったのでだいぶ嬉しかった。しかし、スコアは相変わらず6万点前後であり、fujiwaraさんに運を任せる状態には変わりはない。
fujiwaraさんはとにかく苦戦していた。普段冷静なfujiwaraさんが大分熱くなって焦っているところを見て「fujiwawraさんにコード書かせたら負け」みたいな負け口上が頭をよぎってしまい、それを振り払うのにも苦労した。本来はsugyanと僕がコードを書く分担なので。
17:30も過ぎ、最終調整をした方がいいんじゃないかという時間になったのだが、fujiwaraさんはまだ実装を続けていた。「コレは完全にヤバいな」という感じであったが、17:40にやっと実装を諦めてキャッシュ秒数の調整をすることに方針転換することになるのである。
残り20分。スコアはまだ5万点台。完全に負けムード。
キャッシュ時間の調整と再起動確認、そして競技終了 (17:40-18:00)
もう打てる手はキャッシュ時間の調整しか残されていない。perfectsec系のAPIのキャッシュを全くしていない状況だったので、ここを片方とりあえず10秒キャッシュしたら、スコアがなんと10万点まで伸び、もう一つのAPIも10秒キャッシュにしたらなんと15万点が出た。
しかし、これが最適なキャッシュ時間なのかは全く確信が持てないし確率的にはfailするかもしれない。しかし、調整している時間ももう無い。また、キャッシュの実装が雑だったので、不正なJSONをキャッシュしてしまったら500エラーが出る状態だということにも気づく。修正ブランチは作ったものの、残り10分切ったところでこれを入れる勇気はなかった。それよりも、再起動確認もやりたいというのもあった。
それで再起動してアプリケーションの動作を確認しようとしたら、なんと500エラー。軽くパニックになって悲鳴にも近い声が上がります。残り3分。
これはサーバーの起動順の問題で、全部のサーバーが起動しきっていない状態でアプリにリクエストが行くとポスグレへの接続の関係でエラーになる可能性があるというものだった。
もうこれは直している余裕はないので、運を天に任せるしか無い。変なアクセスが飛ばないようにブラウザやターミナルは全部落としたものの、とにかく全部のサーバーがちゃんと起動してから、運営チームに最終本番計測をかけてもらえることを祈るしか無い。
そして競技が終了した。
競技終了と優勝
終了直後は、完全に負けた気分だった。以下のような要因がありアプリが正しく動く動くとは到底思えなかったからです。
- APIサーバーがエラーを返した時に変な値をキャッシュしてしまうとエラーを乱発する可能性がある
- キャッシュ秒数はエイヤで決めた値なので最適なのかが確信が持てていない
- 古いコンテンツを返して失格になるかもしれない
- 再起動直後にエラーが出てしまうかもしれない
- キャッシュが温まってない状態でどれくらいのスコアが出るかはわからない
僕としても、APIサーバーのエラーハンドリングとか、キャッシュ秒数の調整とか僕一人でもなんとかできる余地がまだあったのに、それをやりきれずに手を止めてしまった時間があって「あの時こうしてればよかったんじゃないか」とか後悔ばかりで、競技が終わってしまったことに悔しくて泣きそうだった。
少し時間が経つと少し冷静になって「よくよく考えると失格になる可能性はそんなに高くなさそうなので、もしかしたら上位に食い込めるかもしれない。でも失格になったらダサいなー」とか思っていました。
順位発表で3位がGoBold、2位が白金動物園ときたときに、「これは1位は .datか、もしかしたらfujiwara組なのでは？」とか思い、そして、151,509点というスコアを見た時に「あれ、コレはもしかして優勝したんじゃないか」となんとなく思いつつも確信は持てなかったので、優勝発表の瞬間は本当に嬉しかった。
まとめ
かつて無い薄氷の勝利だったとか思ってたのですが、第1回で優勝した時も、最後までキャッシュ秒数を調整して、最後の最後ではベンチ通るかどうか確信が持てない状況だったなーというのを思い出しました。あの時に比べると、fujiwaraさんと組む以上は負けてはいけないというプレッシャーが今はすごい。
今回は初動が遅かったのが大きな反省点ですが、初手は結構良かったこととなんとかfailさせず完走させられたところがなんとか勝てた理由かな、と思います。キャッシュ戦略が偶然ハマったという、運の要素も強かった気がします。
今回のfujiwara組は元同僚とは言え、今の所属はバラバラです。そして同僚じゃないチームが優勝したのはISUCON史上初めてのことです。「同僚じゃないとISUCONは勝てない」と言われて久しいし、実際そのとおりだと思いますが、今回このメンバーで優勝できたことを嬉しく思います。fujiwaraさんの統率力とsugyanの無敗力の賜物な気がします。