完敗です。悔しい気持ちもありますが、最後まで抜本解決に至れなかったので完敗したという気持ちの方が強いです。
リポジトリは以下でそのまま公開しています。軽くやったことを振り返ります。時間とかはざっくりです。それとチームとしてではなく、あくまでも自分の視点でのエントリーです。
追記 (2020/09/14):
事前準備
最初は一人で出ようかなーとも思ったのですが、今回はmethaneさんと一緒に出ることにしました。
他社の人と組むこと自体が初めてで、しかもお互いリモートでの参戦だったのでどうするか悩みました。
とりあえず普段通りSlackでの情報共有をしつつ、Discordで音声をつなぎっぱなしにしてお互いコミュニケーションを取れるようにしておきました。1度だけ事前に練習しておき、最初の30分感にお互いやることと、やりとりの雰囲気をつかんでおきました。
使用ツール
- pt-query-digest (スロークエリ解析)
- tkuchiki/alp (nginxのアクセスログ解析)
- netdata/netdata (分解能が1秒で簡単に導入できるモニタリングツール)
- catatsuy/notify_slack (自作のSlack通知ツール)
~1:00
最初は自分たちのサーバーのIPアドレスが分からなかったので、そこを探す作業から始まりました。本当はポータルに登録されている想定だったようですが、そこがうまくいっていなかったので情報を調べるのに苦労をしました。
軽く構成を確認してnginx/Go/MySQLという構成で普段と大きな変更はなし。メモリは2GBでCPU 1コアのサーバーが3台なので、CPUがボトルネックになると複数台使い切らないのと戦えなさそうという予感がありました(結局最後までCPUがボトルネックでしたが)。
チームメンバーに開発環境構築やデプロイスクリプトを試してもらっている間に、MySQLのスロークエリとnginxのアクセスログから集計結果を取れるように準備をしました。
アプリケーションのGo実装は自分が嫌いなechoが使われていて、少し萎えましたがそこは一旦気にせず進めます。
最初の時点ではMySQLのテーブルに一切インデックスが貼られていないのでいくつかインデックスを貼っていきました。
~2:00
レギュレーションでbotのリクエストに503を返してもいいと書いてあったので対応しました。当初はチームメンバーがGoで実装しようとしていましたが、Goのregexpは遅いので使わずにnginxで雑にif文で対応しました。雑にやり過ぎて一部漏れがあったことは終わった後に気づきましたが😅。
MySQLのスロークエリを見ているとN+1クエリがありそうな気がしたので、とりあえず shogo82148/go-sql-proxy を使って手元でSQLを見れるようにしました。
~3:00
MySQLのインデックスを追加しつつスロークエリを確認していくと、MySQL8から使える降順インデックスが使えるクエリが流れていたのでMySQL8化を決断します。今年のISUCONではnode.jsの実装を用意するアナウンスがされていたので、node.jsが未だに対応していないMySQL8は使ってこないだろうと予想していましたが、予想通りMySQL5.7だったので8にアップデートしました。設定ファイルをそのままでアップデートをしたところクエリキャッシュ周りの設定でエラーになりましたが、そこはサクッと直して無事起動しました。
MySQL8にしてインデックスを追加しましたが、スコアはあまり変わりませんでした。もう少し深入りした方が良かったかもしれませんが、この時はとりあえず先に進もうと思い、そのまま先を進みます。
~4:00
この辺りから本格的にアプリケーションの変更に着手していきますが、苦戦していきます。当初入れた最適化が、インデックスを追加したことでパフォーマンスが向上したところでfailするようになってrevertしたり、なかなか進められません。
~5:00
SQLが座標計算周りの複雑なもので、時間内に抜本的解決ができる自信がなく、MySQLのCPU使用率を時間内に下げきれないと判断しました。そこで3台の内2台をMySQLに使用することにします。レプリケーションを組むと変にハマる可能性があったのとテーブルは2つしかないので、goroutineを使って2つのDBに対して更新を同時に行うことで解決しました。結局MySQLのCPU使用率について抜本的解決ができなかったので、この変更が一番効きました。
~7:00
estateのキャッシュをチームメンバーが入れようとしていましたが、うまくいかず、可能性としてestateの更新をfor文で一つ一つ行っているからパフォーマンスが上がったときにエラーになるのではないかという仮説からestateの更新をbulk insertに変更しました。この変更自体はサクッとできましたが、スコアの向上効果は小さかったです。
最後
その後、さらにインデックスを追加したところエラーメッセージなしでベンチマークが終了するようになってしまいました。運営に質問したところエラーが多すぎるとこの状況になるとのことでした。パフォーマンスが上がることにより、nazotteのestateのN+1が詰まってしまいベンチマークが通らなくなってしまったようです。どうしてもこのN+1を解決したかったので一気にSELECTするようにしようとしましたが、なぜかベンチマークが通らず断念しました。ベンチマークのエラーメッセージが不親切で何を間違えているのか全く分かりませんでした…
そうしてコードを読んでいくと、NazotteLimitを超えた場合は捨てられるみたいだったのでNazotteLimitを見て途中で処理を打ち切るようにしました。少しだけスコアは上がりましたが、やはり抜本的解決が必要です。
さらにMySQLにインデックスを貼ろうとしていたのですが、インデックスを貼るとベンチマーカーが終了しなくなるバグを踏んでしまい、最後の1時間で予想外のタイムロスが発生して断念しました。
最後の最後でMySQL8のbinlogによってディスクがフルになってしまうトラブルがありました。なんとかbinlogを削除しましたが、ギリギリだったのでかなり焦りました。
最終的にチームメンバーがestateのキャッシュを一部だけ有効にしましたが、やはりnazotteが遅すぎるからか効果が薄く、最後までスコアを大きく伸ばせませんでした。最終スコアは1503でフィニッシュでした。
感想
最初見たときは行数がここ数年では少なく、時間内にボトルネックが全部なくなるのではないかと心配したのですが、全くそんなことはなく、今までの問題とは違うボトルネックでかなり苦しみました。
nazotteの最適化についてはN+1を解決するよりもアプリケーション側で座標計算するようにしてクエリ自体を不要にする方が確実だった気がしますが、やったことがない処理なのでプログラムを書ききる自信は全くありませんでした。そこの処理がやりきれればMySQLの負荷を下げられて次のフェーズに進めそうでしたが、そこまで進めずでした。空間インデックスみたいな機能もMySQLにある気がしましたが、使ったことがないのでそこまで手が出ずでした。
またMySQL8にしたりと色々作業をしたのに効果が全体的に今ひとつだったので、もう少し根拠を持って作業を進められれば違ったのかもなと思います。
ベンチマーカーのエラーメッセージが不親切だったり、バグがあってよく分からない挙動をしているのが非常につらかったので、そこは改善の余地がありそうな気がしています。具体的にはベンチマーカーのエラーメッセージが多すぎる場合は切ったり、一定時間ベンチマークが終了しない場合は強制終了するなどです。エラーメッセージの打ち切りはISUCON6本選の時はやっていました。ベンチマークが終了しない場合の強制終了はISUCON6本選もISUCON9予選の時もやっていました。なので過去にもあったことのような気がしていますが、この辺りは運営側の情報公開を待ちたいと思います。
問題は自分には絶対に作れない非常に素晴らしい問題でした。運営の方々、本当にありがとうございます。また復習して次に備えたいと思います。