ISUCON初参加に向けてやったこと(ISUCON11予選)

8/21に開催されたISUCON11の予選に参加してきました。チームは大学のサークルの同期2人 (rkoike・cojiro) と3人で出場しました。

結果は77704点で41位でした。残念ながら本選出場は叶いませんでしたが、それなりに練習の成果は出せたのかなと思い満足しています。何より開会のムービーや中継などもありお祭り気分で楽しんで参加させてもらうことができました。

さて、僕自身ISUCON初参加にあたって最初は何から始めていいかわからない状態で、そのことが参加へのハードルの一つになっていました。この記事では初参加に向けてどういう対策や準備をしたか、どういうツールを用意して臨んだかを共有し、より多くの人にISUCONに参加してもらう敷居を下げる手助けになればいいなと思います。

リンク

予選当日のレポジトリ

GitHub - isucon-kuolc38th/isucon11-qualify

デプロイ・ログ収集ツール

GitHub - isucon-kuolc38th/isucon11-qualify-util

TODOマニュアル

ISUCON11予選 - HackMD

事前練習

事前練習としてはひたすら予選の過去問を解いていました。過去問だけでも相当なボリュームがあるので、まずはこれらを解いて予選通過レベルのスコアを出せるようになること・関連エントリなどを読んで+αまでやり込むことを目標にしました。また、過去問を解きながら徐々に必要なツールやマニュアルを整えていきました。

6月頃から本格的に練習を始め、予選当日までには個人でISUCON3と4、チーム練で7〜10を解きました。

過去問は@matsuuさんが用意してくださっているAMIイメージを使いました。AWSのAMIでisucon*で検索すると出てきて、それを立ち上げるだけで動くので、始める前思っていたほど過去問の環境構築には苦労しませんでした。今回ISUCON初参加でしっかり練習を積むことができたのもひとえにこのおかげです。

github.com

6月

本格的に練習を始めたのは6月頭くらいからでした。ありがたいことに運営の方が座学とハンズオンを開催してくださり、最初の一歩の雰囲気を掴む上で非常にためになりました。

isucon.net

その後はいきなりチーム練をしてもグダグダになる可能性が高かったので、当面は個人練習をメインに情報収集・共有をしていこうということになりました。僕自身はハンズオンとISUCON3を解いて、初期セットアップのノウハウやチューニングの雰囲気を掴むことを目指しました。

この頃はとりあえず座学でお勧めされたALPやnetdataを使って手探りで自分たちのスタイルを模索しているような感じでした。

7月〜8月

7月頃から2週に1回くらいのペースでチーム練を始め、当日までに7〜10を解きました。基本的に本番と同様8時間みっちり使って臨みました。

次の練習までの2週の間に各自もう一度環境を再現して復習し、ツールとマニュアルを整備してまた次の練習に臨むというサイクルを繰り返していきました。

最初は用意していたツールの使い方もおぼつかず、メイン構成のNginx+Go+MySQLに載せ替えるだけで4時間使うといった有様でしたが、回を重ねスタイルが確立してくるにつれて徐々にスコアも出るようになってきました。結局どの回も時間内に予選ボーダースコアを出すことはできませんでしたが、あと一歩うまくハマればワンチャンというところまでは見えてきた感じです。

過去問に取り組むにあたって一番苦労したのはベンチの再現でした。CPUやメモリの設定はマニュアル等に記載されているのを見てできるだけ揃えるようにしましたが、AMIがあってもやはり本番と全く同じ環境を再現するのは難しく苦労しました。具体的には、

  • AMIを起動したそのままの状態でベンチを回してもFAILする(タイムアウトが原因で互換性チェックに落ちるなど)
  • Goに切り替えるとFAILする
  • スコアが上がった時にベンチ側と思われる原因のエラーが大量に出る
  • インスタンス間・グローバルの帯域接続がちゃんと設定されているかわからない

などがありました。対策としては、

  • 特に指定のない限りベンチは別インスタンスで立てる
  • ベンチのインスタンスはある程度強いものにしておいて良い
    • 多少点数が上振れするかもしれないが、基本的にはアプリ側がボトルネックになるので問題ないはず
    • 弱すぎるとFAILしたりメモリが足りなくてフリーズしたりする
  • 接続数が多くなってくる場合、ベンチのファイルディスクリプタ上限も上げる (ulimit -nなど)
  • 最悪の場合ベンチ側のコードを書き換えてタイムアウトを伸ばす
  • セキュリティグループ、ファイアウォールの設定を確認する
  • GOは最新版を入れてgo.modを使うようにする

などの処置を取ってなんとかしました。(帯域については最後までちゃんと制限されているのかわからなかった...)

また昔のコンテストだとsystemdがなくinit.dというのを使わないといけない、Goのバージョンが1.1とかでそもそもgo.modが使えないなどの落とし穴もあり、過去問をやる中でその辺の腕力も身についたと思います。

当日に向けての準備

ツール

ツールとして当日使用したものを書きます。

マニュアル

各種ミドルウェアの初期設定の手順、競技開始後・終了前の流れ、大まかなスケジュール間、よくあるエラーへの対処法など、練習時に躓いたことや学んだことを全てこのマニュアルに書き、練習を通じてブラッシュアップしていきました。練習の成果が全てここに詰まっているといっても過言ではありません。

ISUCON11予選 - HackMD

ALP

nginxのアクセスログを解析し、それぞれのエンドポイントへのリクエスト数やレスポンスタイムを集計してくれる定番ツールです。アプリの解析含め静的ファイルへのアクセスや、400/500のレスポンス、304が正しく返っているかなどリクエスト周りの傾向を把握するのに利用しました。

muttan1203.hatenablog.com

najeira/measure

こちらはGo向けのツールになりますが、導入してからは欠かせないツールになりました。

github.com

1行書くだけで関数ごと、セグメントごとの呼び出し回数・所要時間を計測することができます。ALPではエンドポイントごとのレスポンスタイムしか取得できないのに対し、こちらは関数ごとに集計してくれるので、ベンチマークの特定はもちろんアプリの全体の構造を把握するのにも非常に役立ちます。例えば同じ回数呼ばれている関数とエンドポイントがあれば、その関数はそのエンドポイントでしか使われていないことがわかるし、逆に多くのエンドポイントから利用されている重要な関数の特定にも便利です。

僕らの戦略の主軸はこのツールで、この出力を見てSUMの多い関数のタイムを見て削っていくのが基本的な流れでした。CSVで出力されるのでスプレッドシートにそのまま貼り付けて利用していました。

pprof

こちらもGo向けのツールで、CPUやメモリなどの占有状況を可視化することができます。こちらはメインではなくCPUやメモリの状況を確認したい際に補助的に使うという立ち位置でした。最初に一度は確認しておく予定でしたがすっかり忘れておりISUCON11で利用することはありませんでしたが...

こっそりCPUを占有しているケースの発見に便利なので、最初にパッと目を通すか目に見えるボトルネックは改良したけどなんか遅いって時に使うと良いと思います。

christina04.hatenablog.com

netdata

各種リソースのモニタリングをし、CPU or メモリ or ネットワークといったレベルでの大まかなボトルネックの把握に利用しました。多機能な割にコマンド一発でインストールできるのもいいところです。¥

dev.classmethod.jp

なお、本番はセキュリティグループとNginxのルーティングの設定がうまくいかずこちらも日の目を見ることはありませんでした。

pt-query-digest

MySQLのスロークエリを解析するツールです。ALPなどと同様に占有率の高いクエリのレスポンスタイムや、読み込み行数に対して実際に送信した行数なども集計してくれるので、こちらを参考にヒット率の低いもの、レスポンスタイムの長いものを中心にEXPLAINを使いながらインデックスを貼る・クエリを改善していくということをしていました。

thinkit.co.jp

util

ログの管理についても考えるところは多いと思います。僕たちの場合は、ベンチを実行した後スクリプトインスタンスssh接続し、各種ログをローカルに取って来れるようにしていました。また、

  • 案1:メインレポジトリと同じレポジトリで管理→ベンチを回すたびに大量のプルやマージが必要になる
  • 案2:別レポジトリで管理→ベンチを回した後にプッシュするのが面倒

という経緯を経て、最終的にutil専用のインスタンスを立ててRemote VSCodeで接続してログを共有するようにしました。(もはやレポジトリは不要ですが、一応gitで管理していました)

また、ブランチを指定してデプロイするスクリプト・ログを消すスクリプトも用意し、コマンド一つで簡単にベンチを回す前のセッティングができるようにしていました。これはrkoikeが一晩で用意してくれたものですがこれのおかげで開発の効率が大きく向上し、またヒューマンエラーを防ぐ上で欠かせないものでした。

GitHub - isucon-kuolc38th/isucon11-qualify-util

以上のツールを使い、utilのコマンドでブランチをデプロイ→ベンチを回し、ALP(アクセス系)・measure(アプリ)・pt-query-digest(SQL)の解析結果を出力して確認という流れがスムーズに行えるようにしました。

戦略

本番に向けて考えていたことはおおよそ以下の通りです。

  • 役割分担
    • rkoike: インフラ(構成の変更・初期セットアップ)、Nginxのチューニング、モニタリング
    • cojiro: SQLのチューニング、アプリ補助
    • 僕: アプリ全体の仕様把握、アプリ改善(主にキャッシュ)
  • 初期構成はNginx+Appで1台、DBで1台の2台構成
    • 過去問でもこの構成である程度対応できることがほとんどだったため
    • 3台目をどうするかはボトルネックの解析をある程度進めないとわからないことが多いため
  • 競技開始後の動き
    • できるだけ早くmeasureを入れて結果を取得し、アプリ仕様の把握に活用
    • rkoikeが初期構成をセットアップしている間に他の二人でアプリを手で動かしたりコードを読んだりして仕様把握を進める
    • 最初1時間半〜2時間程度は初期構成の載せ替えと仕様把握に使い、改善には着手しない
    • DBの載せ替えとログの出力が完了し、最初にある程度ボトルネックの候補を洗い出してから作業開始
  • インデックスはコスパが良いので積極的に活用
  • キャッシュは強力だがコストが高いので慎重に検討
    • 大量のレコードの集計結果など、計算にコストのかかる値
    • 直近の1件のみ保持していれば良い場合
    • 複数のエンドポイントで繰り返し使われるレコード
    • 逆に、検索や複数のレコードを返す処理はSQLの方が得意なことが多いので無理にキャッシュでやらない
  • Redisは使わずオンメモリで対応
    • 検討はしていたが、過去問でも結局使わずに何とかなってしまったため
    • 通信のオーバーヘッドや接続数への負担を考慮
    • その代わりAppを2台構成にするのは難しくなるが、DBを分ける、キャッシュを使わない一部のエンドポイントだけ分ける、静的ファイルへの接続が多い場合はNginxだけ分けるなど他の分割方法を検討する
  • 基本方針はSQL+オンメモリキャッシュ
    • サーバー起動時とinitializeでDBのデータを積み込み、更新や追加の都度DBの書き込みと並行してキャッシュも更新する
    • 無駄はあるものの、DBにデータを残すことでリスクを抑えつつキャッシュの良さを生かせる(うまくいかなければ戻せば良い)
  • 1時間前には手が空いた人が後片付けの準備をする
    • ベンチが空いている時に再起動試験
    • ログの無効化、不要なサービスの停止
    • 再起動後にデータが保持されているかの確認

当日

当日はレンタルスペースを借り、車でモニター等を積み込んで作業環境を整えました。 車ではるばる運んできたデスクトップPCがまさかのフリーズして予備のノートPCに切り替えるというアクシデントが発生し、冷や冷やしながら競技開始を迎えることになりました。

f:id:ey_nosukeru:20210828203530j:plain
競技会場の様子(手前のモニター3台はデスクトップPCが逝ったためこの後撤去される)

やったこと

競技開始

  • [x] isu_uuid, timestampにインデックスを貼る
  • [x] 最後のISUコンディションをキャッシュする
  • [x] generateIsuGraphResponseのtimestampをクエリで絞る
  • [x] getTrendのISUキャッシュ

3時間経過時点くらい

  • [x] postISUConditionのバルクインサート
  • [x] getJIAServiceURLキャッシュ
  • [x] postIsuの変なトランザクション消す
  • [x] unixソケット

7時間経過・延長以降

  • [x] ISUの存在判定をキャッシュでやる
  • [x] getUserIDFromSessionのSQL消す

未完了・着手しなかったこと

  • [?] http2対応・keepalive
  • [ ] 接続周りのカーネルの設定
  • [ ] 静的ファイルのNginxキャッシュ
  • [ ] 画像をファイルに移す
  • [ ] 完成したグラフをキャッシュする?
  • [ ] コンディションデータが文字列で入ってるのをなんとかする

作業開始前の作戦会議で洗い出した改善候補と、その完了状況の一覧です。競技開始後の諸々のセットアップは比較的順調に終わり、仕様把握に余裕を持って時間が取れたので十分に改善点を洗い出すことができました。

作戦会議時点

最初にマニュアルの読み込みをしましたが、まずその情報量の多さに面食らいました。これまでの過去問のマニュアルはほとんどが定型文で重要なのはスコア計算・減点や失格の方法と禁止事項くらいなことが多かったですが、今回は別途でアプリのドキュメントが用意されているなど情報の多さが特徴だったと思います。

その中でも完成したグラフ・当日前日のグラフなどの仕様がかなり複雑だったので、ここをキャッシュするなどして高速化するのがキーポイントになるのかなと思いました。 またマシンのスペックが比較的高いこと、現実の1秒=アプリ世界の30000秒という仕様、postISUConditionで9割のリクエストを弾くようになっているなど、大量のリクエスト数を捌ききることが求められそうな雰囲気があったので、接続周りの設定や静的ファイル(特に画像)のキャッシュにはあたりをつけていました。

他には典型的にキャッシュできそうな部分が多く、DBにボトルネックが来ることは少なそうだなー、画像系とAppで分けるかーなど構成についてもある程度考えていたと思います。

この時点では対処方法の検討もつかないようなボトルネックもなく、過去問で見たようなケースが多かったので完全に「進研ゼミでやったやつだ!」状態になっていました。 上げたボトルネックを順調に潰していけば予選通過も狙えるのではないかと思っていました。そう、この時までは。。。

3時間経過ぐらい

競技開始後の流れはスムーズで、作業開始してからもSQLの改善・キャッシュなど順調に進みスコアを着実に伸びていきました。この時点で40000点程度で、一時は6位を記録するなど思った以上の手応えでテンションもブチ上がっていました。

f:id:ey_nosukeru:20210828203431p:plain
全盛期(その後彼らの姿を見たものはいなかった...)

事件は突然起きました。getTrendでキャラクターごとにISUをグルーピングして状態を取得しているところが明らかに遅かったので、ISUごとキャッシュしてDBを使わないようにしました。実装を終えベンチを回したところ、検証フェーズもパスしてホッとしたのも束の間、以下のようなエラーが大量に出てベンチがFAILするようになりました。

ERR: load: http: Get "https://54.199.41.247/api/isu/43a2ea8f-3f1f-4fc4-90bc-942870e355c9/icon": http2: client connection force closed via ClientConn.Close

ERR: load: http: Get "https://54.199.41.247/api/isu": http2: server sent GOAWAY and closed the connection; LastStreamID=1999, ErrCode=NO_ERROR, debug=""

初めて見るエラーで戸惑いましたが、getTrendは明らかに早くなっており、またアプリも正常に動いていたので、最初に想定していた通りアプリが早くなって大量にリクエストが来たのが原因で接続を張れなくなっているのだろうと思い、そこまで焦ってはいませんでした。進研ゼミでやった通りに以下の対応を取りました。

しかしこれらを試しても状況は一向に改善されず、時間だけが過ぎていきました。 アイコンが帯域を食っているのかと考え、アイコンの304なども試しましたがベンチ側のヘッダーが設定されていないのかうまく304が返りませんでした。

getTrendを速くしたことで大量のユーザーが流れ込みサーバーの処理し切れない数のリクエストが飛んでくることが原因である可能性が高かったので、仕方なくgetTrendにsleepを入れるとFAILせずにスコアが出るようになりました。(60000点程度)

ここからpostISUConditionのdropProbability (リクエストの一部を無視する) の割合とgetTrendのsleep時間を調整し、FAILせずにリクエストを捌き切れるギリギリを目指すという闇のパラメータチューニングが始まります。

7時間経過・延長以降

ここでポータルサイトがダウンしベンチが回せなくなるという事件が発生します。闇のパラメータチューニングもできなくなってしまったので、仕方なく他のキャッシュできるところをキャッシュし尽くしたりしてベンチの復活を待っていました。

質問の欄を見て例のエラーがベンチ側のバグであることに気づいたのは確かこの頃で、ベンチを回す時間もほぼ残っていませんでした。

ベンチが再開され、全力キャッシュの変更を入れてみると意外にもスコアが80000点程度まで伸びたので、最後の足掻きでダメ押しのパラメータ調整をした後ログなども削除し、15分前には最後の再起動試験とアプリの動作確認を終え、競技終了となりました。

振り返って

「本番は練習でやったことしかできない」というのはまさにその通りで、序盤の流れやSQL・キャッシュについては練習で何回も手を動かした甲斐もあって順調に進めることができた一方で、初めての本番、TLS/http2環境での見たことないエラーに対応できなかったのが敗因となりました。あと一歩と言えばそうですが、これまでの過去問の結果も全てあと一歩という感じだったので、まあ実力通りの順当な結果ではあると思います。

今思えばエラーを見ればhttp2が原因のエラーであることは明らかなので、http2を切って試してみればよかったなあと思いますが、その時は「接続数が多い時にはhttp2を使う!」という思い込みに邪魔されてhttp2を切るというアイデアは浮かんできませんでした。こういうアドホックな対応の部分でやはり地力の差、経験の差が出たなと思います。

ただ、ISUCONは過去にもベンチのバグなどもちょいちょいあるにせよ「当日のベンチが最終的な採点基準」という前提があってこそのものだと思っていたので、事前予告なしにバグ修正版のベンチがスコア計算に使われることになったというのは、最終的な結果は変わらなかったにせよ、若干もやっとする結末になってしまったなあと思い残念です。

事前準備でできたらよかったこと

  • Redisをちゃんと使う練習をしておく
    • 使う必要に迫られたことがなかったにせよできることは多い方が良い
  • Nginxのチューニングにもう少し慣れておく・各設定項目の使い所を理解しておく
  • 過去問は常にポート全開のセキュリティガバガバ状態でやっていたので、もう少しちゃんとしている状態で練習しておくべきだった
  • セッション情報をトレースしてベンチのアクセス傾向を把握する仕組み

最後に

残念ながら本選に進むことはできませんでしたが、ボトルネックを見つけてスコアが上がっていくという競技性そのものにどハマりし、良質な過去問を含め問題を解くこと自体がとても楽しかったです。加えてWebサーバー・アプリの並列処理・SQLの知識・インフラなど幅広い知識が要求されるこの競技に取り組むことで、自然と知識が広がっていったのも自分にとって貴重な収穫でした。

後半は自分語りがメインになってしまいましたが、この記事がこれからISUCONを始めたいという人の役に少しでも立てば幸いです。

運営・作問者の皆さんをはじめ、改めてこの機会を提供してくださった方々にお礼を申し上げるとともに、この大会がこれからも存続してくれることを願っています。

また同じチームとして参加し、共に練習に多くの時間を割いてくれたチームメイトの二人にもお礼を言いたいです。

来年もぜひ出場したいと思います。対戦よろしくお願いします。