ISUCON11に参加しました

ISUCON11に参加した

大学時代の友人でサーバー・インフラエンジニアである @0daryo と 2021/8/21 に行われた ISUCON11 に参加しました。

彼も 参加記録を書いている ので、その記事とはまた違った内容を書こうと思います。DRY原則ですね。何時に何をやったかというタイムラインはそちらの記事に記載されています。

大学時代の友人エンジニアが誘ってくれた

ISUCON自体は何年も前から知っていたのですが、難しそうなイメージがあったので参加していませんでした。

今年は 0daryo が声をかけてくれました。声をかけられた時は6月上旬、大会の参加申し込みが6月下旬で大会予選は8月です。

その頃ちょうど個人開発で何か作ろうかなと思っていたため、本番に向けて1ヶ月もの間、日夜準備に励むことになりそうだから断ろうかなと思っていました。

他にも断る理由はいくらでもありました。使用言語は彼の得意な Go 言語だけど自分はチュートリアルくらいしかやったことがないことや、自分は元々 PHP を書くバックエンドエンジニアだったけど、今はフロントエンドに専念していること。

それでもパフォーマンスチューニング自体に興味はあったので、とりあえず良問と言われている第9回の過去問を一緒に読み合わせしてから参加するかを決めることにしました。

6月、過去問の読み合わせ

6月のある日曜日に Google Meets を使って二人で過去問のマニュアルとレギュレーションを読みました。アプリケーションの実装内容であるmain.goをざっと眺めてみて、個々の関数の処理自体は思ったより入り組んでいないと思いました。

また、7月は個人開発をするのであまり準備する時間は取れないことを 0daryo に伝えると別に構わないとのことだったので、参加を決めました。

ちなみに、7月の個人開発の成果は note PDFy という note の記事をネット上で PDF 化するツールです。

0daryo が参加申し込みをしてくれた後、予選までの間に2回ほど休日1日をまるまる使った事前準備をしました。

惜しむらくは、同僚で ISUCON 経験者の @cureseven さんの誘ってくれた2回の ISUCON 勉強会が、自分たちの事前準備の日に2回とも被っていたことです。

彼女たちのチーム「牡蠣に当たる時の効果音→カキーン」は本戦出場もしたことがあるすごいチームなので、もしそちらに参加していたら自分たちの準備内容も最終スコアも変わってきたのかもしれません。

7月、事前準備

事前準備の内容は前出の 0daryo のブログ に記述があります。

そこに書いていないことを補足すると、matsuu さんが公開してくださっている ISUCON の AWS の AMI の第9回のものを利用させて貰い、AWS 上に EC2 インスタンスを立ててベンチを実行するなどしていました。

さらに、New Relic をインストールしたり netdata を入れてみて CPU 使用率などサーバー側の監視を行ったり、alp で nginx のログ解析をしてみたり、MySQL の Slow Query のログを吐き出したりして二人で見るようにしていました。

そして、それらの手順やメモを GitHub 上に残しておいて、予選当日はコマンドを実行するだけで各種のツールを導入できるようにしました。

ただ、そこから先の対応をしていなかったので今回は良い結果にならなかったのだと思います。

「あの API のレスポンスが遅い」「このクエリが重い」という分析はできたものの、ツールの導入方法や使い方を調べて導入することで時間を消費してしまったことで、その対策方法を考えて実装する練習をしていませんでした。

大会予選の後、0daryo が「いやー、準備したのに思ったよりやりたいことができなかったっスね」と感想を漏らしたので、「事前練習では分析だけで満足して『改善してスコアを上げる』という成功体験を積んでなかったからそうなるよ」と笑いながら答えたのですが、後から振り返るとこの答えが本質を突いてるように思いました。

ただ、これくらいの気楽さがないとおそらく自分は参加していなかったので、来年参加する時はしっかりスコアを上げるところまで準備でやりたいですね。

予選当日の午前

大会当日の 9:40 から事前説明があることをアナウンスで知っていたので、いつもより早めに起床して待機していました。

今回のテーマを説明する手の込んだムービーに大会運営側の意気込みが伝わってきました。

10時、競技開始

10時に競技開始です。午前中は動作、接続確認をしたり、まっさらな状態でベンチを回しました。初回スコアが3500くらいで、結局このスコアを超えたのは競技時間が延長になった18時以降でした。

午前中は事前に用意したタイムテーブル通りに進んでいきました。

Cloud Formation を実行して EC2 への接続を確認し、レギュレーション、マニュアルをしっかり読み、事前に用意したコマンドを実行して各種サーバー監視ツールを導入しました。

DB とコードの管理方法

当日戸惑ったのは、DB が mariaDB だったこと、コードの管理をどうするか決めていなかったことです。

前者は MySQL と互換性があるとのことだったので特に問題視せず、事前に用意した my.cnf を使って対応を進めました。後者は、サーバー内で直接コードを書き換える、Git で push してローカルで pull して書き換える、scp でファイルをローカルに落としてきてそれを Git 管理するという3つの案が出ました。0daryo は最後の方法にしたいとのことだったのでその方法を採ることにしました。

開発に必要な Go のファイル一式をダウンロードし、Git の private レポジトリに push、コードを変更した後は 0daryo が書いたビルドスクリプトを実行してビルドファイルを scp で送ることでデプロイをしていました。

ただ、サーバーに Git が導入済みだったので、来年は普通にサーバーのコードを Git に push して、サーバーでビルドすれば良いかなと思いました。

ブランチを分けて開発していましたが、常に声を掛け合って作業していたので issue を立てて管理することは特にしていませんでした。PR は差分確認のために作るという程度でした。

手元で開発できる環境を一通り整えた後、0daryo が Go のアプリケーション側に New Relic のコードを仕込みました。再度ベンチを回して、New Relic の画面で一番レスポンスが遅いエンドポイントがわかったところで昼休憩にしました。

netdata は使えなかった

想定外だったのが、選手が見れるポータルサイトの質疑応答で、「セキュリティグループを変更してはいけない」という回答が運営からされていたことです。このため、ポート19999番で接続する netdata を使うことができませんでした。

質疑応答を見るまでは二人とも使えるものと思っており、当日はブラウザで表示までしていたのでそれを読んで急いでセキュリティグループを元に戻して netdata による監視の画面を見れなくしたのですが、結果的には New Relic で十分でした。

競技で困ったというよりは、後日発表された結果を見るとセキュリティグループを変更していたことにより失格となったチームが少なくなかったため、これは頻繁に質疑応答をチェックしていた自分のファインプレーだったなと思いました（笑）。

予選当日の午後

午後は、レスポンスが遅い上位2つのエンドポイントを手分けして改善することにしました。

対策してもスコアが全然上がらない

0daryo は POST /api/condition/:jia_isu_uuid で Bulk Insert を実行したり遅延書き込みの対応、自分は DB のカラムに Index を貼ったり、Nginx の設定ファイルを書き換えたりしていました。

しかし、この辺りからではベンチを実行してもスコアが1000前後をウロウロするようになりました。 998から変わらなかったり、上がっても+20とかだったので、何かの施策でスコアが +100 に増えたくらいで喜んでいました。

いくつか施策を打ってもこれくらいの変化だったので、もしかしたら下位フィニッシュもありえるというムードが漂い始めます。

アプリの改善に着手するもアプローチを間違える

0daryo が GET /api/isu を触っている間に、自分はもう一つのレスポンス速度が遅いエンドポイントである GET /api/trends を見ていました。

コードを読んでみると明らかにループの中で SQL を発行しているではありませんか。「さすが ISUCON、これこそが音に聞くN+1よ。推測より計測。これを改善すればスコア大幅改善間違いなし」と改善に取り組みました。

しかし、結論から書くとここに時間を取られすぎてしまいました。アプローチ方法を間違えたのです。

実際は認証が不要なエンドポイントだったのでインメモリにデータを載せていればよかったのですが、「これはN+1問題だ」と思い込んで SQL と Go のコードの書き換えばかりに気を取られていました。

この間に「DBに挿入されている画像をファイル化する」ことや「椅子のステータスを計算後の値に変更する」などの施策は思いついたものの、そこまで動くことができませんでした。

結局このエンドポイントを改善できずに2~3時間くらい溶かした後、17時過ぎに負荷の過多のせいかベンチマークが実行できなくなりました。ベンチマークが復旧しないままなすすべなく競技終了の18時が近づいてきました。

「スコアはダメでも最後にベンチだけ回そう」

アプリ側で詰まっていたため、New Relic をサーバーから削除したり MySQL でスロークエリのログを出さないようする変更を加えた後、スコアも1300くらいで低いままだしベンチマークも実行できないので、重い敗戦ムードの中もう切り上げようかなと二人で話していました。

しかし、Twitter に「ISUCON延長」というつぶやきを見つけ、Discord を確認したら18時少しすぎに競技再開、競技終了は18:45に延長とのアナウンスを発見。

競技終了後のスコア測定方法は、インスタンスを再起動した後に運営側がベンチマークを実行するというものです。この再起動試験の後にベンチマークの実行に失敗すると失格となります。

スコアがいくら低くても失格だけは避けたかったので、「スコアはダメでも最後にベンチだけ回そう」と特に期待せず競技再開を待ちました。

競技再開後、早速ベンチマークを実行してみて非常に驚きました。今までの最高スコアが1300程度だったのに、画面に表示されているスコアは1000どころか3000、5000、8000とみるみる上昇するではないですか。

その後も、13000、15000と上がっていき、最終的にスコアは17000程度まで上がりました。これには二人で快哉を叫びました。

次につながる負け方

あわや20000越えかという勢いあるスコアの上昇を見ているだけで、さっきまでの敗戦ムードは吹き飛びました。

このスコアでは本戦に出場なんてとてもできないことは二人ともわかっています。上位チームなら朝の1時間以内に余裕で越えたスコアだったでしょう。

しかし、負けでも次につながる良い負け方でした。野球で例えると9回裏にツーアウトから満塁まで持っていけたような明日につながる負け方だと 0daryo が笑顔で話していました。

最後に、二人で来年もまた出場してみようと約束しました。

スコアの急激な上昇というカタルシスがなければ、来年また出場しようとすら思わなかったはずです。

結果発表

結果、最終スコアは16680で598組中249位でした。午後には真ん中上くらいにはいきたいねと二人で話していたので、一応それくらいの順位に着地しました。

自分たちと同様に今回初参加の同僚たちのいくつかチームがみんな100位以内に入っている中、客観的には誇れる結果にはならなかったです。

しかし、昔の友人と連絡を取り合って再び協力したり、普段業務で触れない箇所を触ったり、点数の急上昇を目撃するなど競技としての面白さを味わうことができたことに満足しています。

来年はもう少し健闘できるように準備していきたいと思います。運営の皆様、大会に参加された方、ISUCON コミュニティの皆様、お疲れ様でした！