ISUCON10の予選にmeguryohikaとして @megumish_unsafe, @systemctl_ryoto と共に出たのでその記録です。
結果としては、初期スコア500点台から、900点台の、1000点に届きそうかな？というところまでは行けたものの、最後のベンチマーク前に複数台構成にしようとして失敗した結果スコアがつかずおしまいでした。来年もまたやりたいですね！
ISUCONは参加者だけじゃなくて運営にも降りかかる…
午前10:00から試合開始ということで、前日は人々とイカをやるのも午前1時までにとどめておき、無事健康的な午前起床を達成しました。
いい感じに睡眠からwake-Upするコンテスト、勝利した（起床成功）。
— hikalium (@hikalium) 2020年9月12日
ところが、その少しまえに、こんなツイートが運営から…
ISUCON10 オンライン予選について重要なお知らせです。参加者用サポートチャットで共有いたしましたが、環境構築に想定以上の時間がかかっており予定していた10時の開始は難しく現在のところ12時開始となる見込みです。状況についてはまたあらためてアナウンスいたします。 #isucon
— ISUCON公式 (@isucon_official) 2020年9月11日
ということで、私の目覚める前からISUCONは始まっていたようです。私たちの開始は昼ごろまで遅れたけれど。（運営のみなさんお疲れ様でした！）
正午までの暇を持て余して環境が整う
2時間の余裕を得た我々は、「二度寝するなよ！」というネタをやったり、眠気覚ましにご飯を買いにいく人々が出たりと自由な雰囲気が漂っていました。
私も、あまりにも暇だったので、ちょうど横にあるLinuxマシンを、負荷をかけている際のCPU統計などを表示するのに適したようにセットアップしたいなあという気持ちになって、apt updateしたり、NVIDIAのGPUドライバを入れたりしていました。（なんとドライバを入れていなかったので、1024*768の解像度になっていた…これでは流石にきついと思ったので急いでセットアップした。）
ちょっと頑張っているようで、実際にはただベンチマーク時のログを流しているだけの映像（でも見やすかった）。#ISUCON pic.twitter.com/KDsTJlQEcE
— hikalium (@hikalium) 2020年9月12日
そんなわけで、少し環境がリッチになったあたりで、試合開始が12:20からになるとの連絡が。やっていきましょう！
試合開始…からのポータルが503 Service Unavailable
我々はGoで実装を進めるつもりだった&初期実装がGoと書いてあったので、早速ベンチマーカーを回そうとしたところ…なんとポータルが503に。ISUCONむずかしいね…。
というわけで、しばらくベンチマーカーの結果は拝めそうになかったので、megumish氏はソースコードやリソースの退避とデプロイスクリプトの作成を、ryotoさんはbotを弾くnginx configをさっと書いてくれたり、ソースを読んでSQL的にヤバそうなところがないかをしらべてくれたりしていました。私はアプリを実際に触ってみて、遅い部分とか面白い部分がないかをしらべてみていました。「なぞって検索」なる、地図上に領域を描いて物件を検索できるページがあったのにはびっくりしました。また、今回は前回までと異なり、サイトへのログインという概念がなかったため、その点でも度肝を抜かれました。（ついつい/adminが存在しないか調べてしまったが、なかった…。）
14:00の定時報告
前回までの反省と、チームでこれまで練習してきたことを生かして、今回は1時間ごとにさくっと進捗共有会をすることにしました。そして、進捗共有がおわったら、強制的に5分間休憩タイムをとることにしていました。これは体力を消耗しないという点では非常によい戦略だったと思います。（今までは終盤になると、精神的にもかなり疲れがきていたのですが、今回は最後までゆったりできたので割とおすすめです。）
このあたりで、megumish氏がデプロイスクリプトを完成させていて、次はredisを入れてキャッシュできるものはやっていこうか、という流れになっていました。 ryotoさんはAPIの各エンドポイントをみ終わって、いくつか修正できそうな点がみつかったので直していく、という話になっていました。
私は、やっと初のベンチを走らせてみて、nginxのログをkataribeでフォーマットしてどのエンドポイントを直すのがよさそうか議論する材料を用意しました。
Top 20 Sort By Total Count Total Mean Stddev Min P50.0 P90.0 P95.0 P99.0 Max 2xx 3xx 4xx 5xx TotalBytes MinBytes MeanBytes MaxBytes Request 105 40.860 0.3891 0.4355 0.046 0.178 1.085 1.397 1.698 2.000 103 0 2 0 1700275 0 16193 33967 POST /api/estate/nazotte HTTP/1.1 411 33.686 0.0820 0.0246 0.031 0.078 0.115 0.123 0.151 0.206 411 0 0 0 4989248 12139 12139 12153 GET /api/chair/low_priced HTTP/1.1 411 31.674 0.0771 0.0266 0.032 0.072 0.115 0.127 0.155 0.182 411 0 0 0 5500577 13383 13383 13398 GET /api/estate/low_priced HTTP/1.1 86 14.241 0.1656 0.0457 0.087 0.157 0.234 0.247 0.271 0.271 86 0 0 0 1429937 16627 16627 16642 GET /api/estate/search?page=0&perPage=25&rentRangeId=1 HTTP/1.1 67 10.303 0.1538 0.0388 0.093 0.138 0.213 0.223 0.259 0.259 67 0 0 0 1124707 16786 16786 16801 GET /api/estate/search?page=0&perPage=25&rentRangeId=2 HTTP/1.1 72 10.238 0.1422 0.0348 0.094 0.132 0.194 0.205 0.230 0.230 72 0 0 0 1199601 16660 16661 16682 GET /api/estate/search?page=0&perPage=25&rentRangeId=0 HTTP/1.1
トータルでかかった時間としては、やはり「なぞって検索」が重く、次いで物件と椅子の安い順に上位20件をリストアップするlow_pricedが、一回一回は重くないものの、回数が多いためけっこう負荷になっていることがわかりました。あとは、検索部分が重く、今回のサービスの検索では、かなり多種多様な条件を指定できることがわかっていたので、何らかの高速化が必要だろうね、という話になりました。
例えば、searchで指定する条件には、各物件や椅子の属性(features)というのがあって、これはDBにはカンマ区切りの文字列として格納されているのですが、検索時にはそれらのAND条件を指定できる、というもので、当初の実装では全件リードが走っている状態になっており、まあ重いのは致し方ないかな、という感じでした。
改善のアイディアとしては、featuresの各要素は固定で50件であることから、各属性に対応するboolのカラム50列をDBに追加して、ついでにindexも貼ってあげればいい感じになるんじゃないか？と考えて、以後私はそれに取り組むことにしました。
ちなみに、初期状態でのベンチ終了時点では、データが3万件それぞれのテーブル(chair, estate)に入っており、初期データには2万9500件入っている、ということがわかっていました。なので、実行時に動的に増加する分は、最初は500件ということです。（おそらく、負荷レベルが向上すると、ここが増えたのでしょうが、残念ながらそこまで行きつきませんでした…。）
また、単一サーバー(1 core, 2GB RAM)でDB, Webアプリを同時に動かしている状態でベンチマークをかけても、CPU時間は100%に張り付く一方、メモリ消費量は500MBもいかない程度で、swapも全く発生していないという点に気付きました。かなりCPUに集中した負荷がかかっていたようです。当初、私はこれがMySQLのメモリ設定が厳しすぎるせいだと考えて、緩和する設定を入れてみたのですが、残念ながら全く使用量が増えなかったので、ボトルネックは別の部分にあったようです。
15:00の定期報告
このあたりで、megumish氏はGET chair/low_pricedの結果をキャッシュできないか奮闘していました。
ryotoさんは、全く貼られていなかったindexをDBに貼ったところ、100点程度のスコア向上がみられたと報告していました。
また、なぞって検索に関して、矩形で大まかに物件をフィルタしたあと、その各物件に対して、GIS関連の関数を用いて、描かれたポリゴンの内部にその物件が存在するか否かをチェックしているということがわかり、これをDBに毎回投げるのではなく、Goの側でうまく処理できないかということを検討していました。
私は、先ほど言ったMySQL周りのチューニングが効果ゼロだったことを報告して、もしかするとDBやアプリを複数サーバーに分散させる必要があるのかもしれないと言いつつ、とりあえずfeaturesをbooleanでDBの複数カラムに格納するものに着手するという話になっていました。
16:00の定期報告
megumish氏は、キャッシュの大まかな実装はできたけれど、うまくベンチが通らず四苦八苦していました。
ryotoさんは、椅子を購入すると、物件がrecommendされる（椅子が通るような玄関の間口をもつ家がリコメンドされるシステムだった！）機能のぶぶんを、事前にテーブルを作成することで高速化できないか挑戦していました。
私は、chairのfeaturesをカラム化することを引き続き挑戦していました。
17:00
ほぼ同上。だんだんつらくなってくるね。
18:00
megumish氏は、キャッシュをするのはいいけれど、レースコンディションがおきたらどうなるんだろう？という問題に頭を悩ませていました。
ryotoさんは、椅子に合った不動産をおすすめする部分の改善目処がつきそうという報告をしており、それが終わり次第、なぞって検索に取り掛かるという目標を掲げていました。
私は、featuresをカラムにし終わったものの、なぜかベンチマークが通らない問題で時間をつぶしていました。（サーバーにデプロイしてみるとうまく動いているように見えた。）
糖分が足りなくなってきたので、ここらへんでクレープをたべました。おいしかったです。
19:00
megumish氏の実装のバグが取れたとの報告。JSONが正しく吐けていなかったみたい。とりあえずうまくいったら、次は複数台構成の検討に入るとのこと。
ryotoさんは、物件おすすめ機能をあきらめました。というのも、冷静に考えると、事前計算をする処理はかなり重く、また椅子や物件を追加するAPIの時間制限はわりと厳しかったため、時間内に事前計算を終わらせられそうにないというのが理由でした。
今思えば、全部を事前計算せずとも、一度計算したものをキャッシュしておく、などの方策がとれたかもしれないなあ、という感想が浮かんできました。（後から振り返るとそういうアイディアが思いつく。）
私は、クレープの糖分をもってしてもバグを解決できず、なんでだーと頭を抱えていました。
さいご
最後ぎりぎりになって、ryotoさんがなぞって検索のジオメトリ計算の部分をgolangに持ってくることに成功し、これで+300程度になりました。
さらに、私もベンチマークが失敗する理由に気付き（デプロイ時に走るDB初期化と、ベンチマーク時に走るinitialize/内でのDB初期化で異なるデータを流し込んでいた）、なんとかマージに成功。
最終的に、これでスコアが900点ちょい出たのですが、複数台構成を試そうとしてぎりぎりまでryotoさんが頑張ったものの、間に合わず終了時刻を迎えました。いやはや、よくがんばりました…。
反省点
- 複数台構成を練習時にもあまりできておらず、本番でも手間取って間に合わずじまいになってしまった。練習でできないことは本番でもできないよ！
- 当初リストアップしていた修正できそうな点のうち、ひとつを見過ごしてしまっていた。（終わった後に気づいた。）
- 報告会を定期的にしていたのは非常によかったが、ToDoの管理が不十分だった。見ないToDoに意味はないよ！
- 複数台構成の件にもつながるが、本番サーバー以外に実行環境を用意できていれば、もう少し開発を効率的に行えたかもしれない。
まとめ
来年はさらに準備して望みたい…またがんばりましょう！おつかれさまでした！
追記: チームメンバーのryotoさんとツイート被りしていたことが判明（終わるまで全く気づかなかった）（みんな考えることは同じである）
いい感じにWake Upコンテスト予選突破です
— Ryoto (@systemctl_ryoto) 2020年9月11日
