死闘の果てに ISUCON 8 予選を全体7位で突破した記録
ISUCON 8 の予選に、チーム「死闘の果てに」(najeira, bluerabbit, songmu)で参加し、全体7位で通過しました。
運営のみなさま、ありがとうございました。本戦もよろしくお願いいたします。
やったこと
- najeira
- Fabricのファイル用意
- dep化
- nginxに切り替え、もろもろ設定
- getEventのループ内SQLクエリを外に出す
- getEventsのreservationsもワンクエリで取得
- 2台構成化(1をDB, 2をアプリ)
- fail対策のロック
- bluerabbit (bluerabbitさんによる予選記)
- SSH設定、Ansibleで各ツール準備
- コードをgit登録
- 計測用コード埋め込み
- SQLインデックス追加
- 有効予約のみのreserved_sheetsテーブル
- songmu
- sheetsオンメモリ化
- SQLインデックス追加
- reservations.last_updated_at
- (間に合わず) 空席情報をRedisのSetにする
getEvent
※自分がやったところだけ解説します
reservationsをループ内で取得しているので、外に出してevent_id = ?
で一気に取得して、ループ内では取得済みのなかから対応するシートのものだけを使うようにしました。
その後、getEventsでもワンクエリになるようにevent_id IN (?)
で取得して、対応するイベントID && シートIDのものを使うようにしました。
これでクエリ発行数が減ったのでスコアが伸び、他のいくつか入っていた修正とあわせて、2万点ほどになりました。
<img width="899" alt="SS 2018-09-16 13.27.28.png" src="/posts/qiita-527e1f54fa417fd20b65/2.png">
その他
他、自分がやったことは、初期のFabric準備、nginx設定、2台化、再起動まわり(systemd)を設定&確認といったところです。
nginx化はスコアには影響ありませんでしたが、ルーティングまわりで何か必要がでたときに、慣れているほうがよいので変更しました。
2台化をした直後はスコアには影響ありませんでしたが、その後にいくつかの修正が入ってMySQLのボトルネックが軽減されたので、最終的には効いたと思います。
songmuさんとbluerabbitさんがMySQLまわりをきっちり見てくれたので助かりました。
FOR UPDATEがテーブルロックになっているよね……というのは話していたんですが、解決しきるところまではいきませんでした。
fail
ベンチマークを実行すると、成功しても「xxxに失敗したので負荷があがりませんでした」というメッセージが出ていることに気が付きました。また、ベンチマークが成功したあとで、何も変更せずに再実行してもfailしてゼロ点になるということがありました。
今回のISUCON予選で自分は、この謎のfailとの戦いに一番時間を使いました。
最初は自分の実装のバグを疑いましたが、データはすべてMySQLに保存しており、キャッシュや別DB(Redis)は使っていません。よって、書き込んだものが読めていないということはありえない……。また、この現象が出始めた時点では、ループ内のクエリを外に出しただけで、予約関連のロジックに影響がでそうな変更もありませんでした。
そこで、APIの処理中にUPDATE(予約やキャンセル)が入ってしまうことで、ベンチマーカーが整合性エラーと判断してしまうのでは? というベンチマーカーの問題を疑いました(もしくは初期実装のバグ)。最初のボトルネックが改善されてベンチマーカーのアクセスが増えた=並列度が上がったことによるトラブルでは? ということです。
それを確認するために reservations まわりの処理をしている箇所に、Goのロック(sync.RWMutex)を入れてみたところ、fail しなくなりました。これによってreservations まわりの処理がイベントごとに直列になってしまいスコアは下がりますが、failよりはマシです。
自分のバグなのか外部要因なのか、結局のところ確証はありませんが、ロックを入れることで回避していくという作戦でいくことにしました。スコアが出るのが正義です。その後、スコアが上がるたびに別の箇所でfailが出たりしたので、ロックの箇所を増やしたり範囲を広げたりしながらfailが出ないようにしていました。
※これに関しては運営からの講評およびベンチマーカーのソースコード公開待ちです。しかし仮に初期実装にバグがあったり、ベンチマーカーの挙動に怪しい点があったとしても、そういったものの調査・対応するのも含めてISUCONかなと、自分は勝手に思っています。うちはロックで対応しましたが、飲み会で聞いた話ではsleepを入れて対応したところもあるそうです。
終盤戦
ループ内のクエリを外に出したことと、各種SQLインデックスで、ロックなしの状態では4万点近く出ていました。しかし、終了後の追試でfailするのは困るので、最大限にロックを入れて、2万-2.5万点ほどになりました。終盤、有効予約のみのreserved_sheetsテーブルを入れて4万点を超え、ベストスコア 45,238 となりました。
残り時間は40分ほどありましたが、ここでベンチマーク終了を宣言しました。このあとは再起動しても動くかどうかをブラウザベースで確認し、片付けしたりしながら、まったりと終了を迎えました。
最後、songmuさんによるRedisによる空席管理の実装ができたり、bluerabbitさんがFOR UPDATEの解決を準備していましたが、スコア4.5万はおそらく突破している(スコアのクローズされたときの情報から3.5万が当落線と予想していた)ので、ベンチマークなしということを決めて終了しました。
ツール
Fabric
デプロイや、サーバ側での何らかのタスク実行にはFabricというツールを使いました。
これは、Pythonで定義したタスクを、SSH接続してリモート(複数台対応)で実行してくれる便利ツールです。
def upload():
local_file = "webapp/go/src/torb/torb"
remote_file = "/home/isucon/torb/webapp/go/torb"
put(local_file, remote_file, use_sudo=True)
sudo("chmod 0755 %s" % remote_file)
def restart():
sudo("systemctl restart torb.go")
※一部抜粋
上記のようなタスクを定義しておいて、ローカルでコマンドを実行します。
fab upload restart
複数台に対して実行できること、一連の操作をタスク化しておくのでミスしにくいのが良かったです。
measure
以前にISUCON用として https://github.com/najeira/measure というライブラリを作って、今回も使いました。
alpなどのHTTPのアクセスログを集計するツールだと、集計範囲が広いのでボトルネックが見えないことがあります。例えば今回だと、あちこちのハンドラから呼ばれるgetEventという関数が遅いので、どのハンドラも遅いという情報が得られるだけです。Goのコードに集計処理を埋め込むことで、関数ごとや、関数内の一部の範囲を集計することができます。
今回の初期の状態は以下のとおりでした。
<img width="1038" alt="スクリーンショット 2018-09-18 15.26.32.png" src="/posts/qiita-527e1f54fa417fd20b65/3.png">
getEventを解決しない限りどうしようもないことが一目瞭然です。
終盤は以下のようになりました。
<img width="1133" alt="スクリーンショット 2018-09-18 15.30.25.png" src="/posts/qiita-527e1f54fa417fd20b65/4.png">
getEventは、もはや 1ms もかかっていません。かわりに予約とキャンセルのAPIが支配的になっていることが分かります。
延長戦
ベンチマーカーとインスタンスがアクセス可能になったので、Redisによる空席管理を入れてみました。これを入れると、Goによるロックを削除してもfailしなくなったので、初期実装の予約・キャンセルまわりに整合性に関するバグがあったのかもしれませんね。
なおスコアは2台で 110,069 を記録することができました。この段階では次は /admin/api/reports/sales
がボトルネックになっているようです。reservations の全件取得なので、やるとしたら、ここはオンメモリにキャッシュでしょうか。
さて、当日に考えていた・途中までやっていたことは確認できたので、ここで終了とします。では本戦で!
この記事はQiitaの記事をエクスポートしたものです
Discussion