はじめに
ISUCON 14にチーム「ミレニアムサイエンススクール」で参加しました。メンバーは自分と 
id:nonylene 
id:wass80 です。
最終スコアは28875点で、22位でした。やった～
リポジトリはこれです。言語はGoです。なぜなら自分が最速で書けるため……。
やったこと
トレーシンググッズを入れる
初手ですね。前日に素振りしていたのでスムーズに入れることができました。といってもだいたいはコピペするぐらいだけど。
通知系エンドポイントが呼ばれる頻度を減らす
GET /api/app/notification GET /api/chair/notification が呼ばれまくっているのがCloud Traceの結果から一目瞭然でした。30ミリ秒に1回呼ばれとる！！
最初はコントローラー内で time.Sleep(time.Second) って書いてdelayを入れることで緩和しようとしたのですが、よく見るとレスポンスのJSONに retry_after_ms っていうフィールドがあるし、これで調整しようねってことじゃ～ん、ということに気づきました。いったん3000ミリ秒に1回呼ばれるようにしました。
GET /api/owner/chairs のレスポンスを3秒キャッシュする
明らかにやばいクエリが発行されているし、3秒キャッシュしていい、ってマニュアルに書いてあったのでさくっとキャッシュしました。
キャッシュ自体はできていたけど、キャッシュの参照・更新がうまく直列化できていなかったのであとでnonyleneさんに直してもらいました。mutexでガードする範囲が狭すぎたっぽい。
interpolateParams=true
いつものアレです。どうせ後でやるんだから最初から入れちゃえよ、ということで早い段階で有効にしました。
GET /api/app/notification のN+1クエリを潰す
相変わらず通知エンドポイントの負荷が高いので、まずはそこから取り組みました。ループの中で SELECT * FROM ride_statuses WHERE ride_id = ? ORDER BY created_at というクエリを発行しているのをINクエリで外に逃がすぐらいです。
足りないインデックスを足しまくる
とにかくインデックスが不足していたので、トレーシングに出てくるエンドポイントから発行されているクエリや、pt-query-digestの結果に出てくるクエリに対して効くインデックスを片っ端から足していました。
GET /api/app/rides のN+1クエリを解決する
ride_idごとの最新のride_statusesを取得するクエリをGitHub Copilotに丸投げしました。ちなみにこういうクエリになりました。
SELECT rs.* FROM ride_statuses rs INNER JOIN ( SELECT ride_id, MAX(created_at) AS max_created_at FROM ride_statuses WHERE ride_id IN (?) GROUP BY ride_id ) latest ON rs.ride_id = latest.ride_id AND rs.created_at = latest.max_created_at;
クーポンを考慮した料金計算ロジックが calculateDiscountedFare 関数に書いてあり、引数が nil かどうかで分岐していて嫌だな！！ と思ったけど、ユースケースをよく見ると、POST /api/app/rides/estimated-fare でしか引数が nil になることはないようでした。
ということで、まずは POST /api/app/rides/estimated-fare から呼ぶ用の関数を分け、そのあと元の calculateDiscountedFare 関数の実装を整理しました。最終的には以下のようなシグネチャになりました。かなり引数を減らせましたね。
// before func calculateDiscountedFare(ctx context.Context, tx *sqlx.Tx, userID string, ride *Ride, pickupLatitude, pickupLongitude, destLatitude, destLongitude int) (int, error) // after func calculateDiscountedFare(ctx context.Context, tx *sqlx.Tx, ride *Ride) (int, error)
ここまで整理できたら、あとは SELECT * FROM coupons WHERE used_by = ? というクエリでのN+1クエリを解決するだけですね。
引数が nil かどうかで分岐してもいい、してもいいが、このロジックを同じ関数に押し込めるのは見通しが悪すぎるんじゃないか？？ と嘆くといった活動もやっていました。まあこれは出題意図通りではあるんじゃないか。
ride_idごとの最新のride_statusesを非正規化する
「ride_idごとの最新のride_statuses」は頻繁に参照されているので、これを非正規化することにしました。
以下のようなテーブルを用意して、ride_statuses テーブルへINSERTされるたびにUPSERTするようにしました。
DROP TABLE IF EXISTS latest_ride_statuses; CREATE TABLE latest_ride_statuses ( ride_id VARCHAR(26) NOT NULL COMMENT 'ライドID', status ENUM ('MATCHING', 'ENROUTE', 'PICKUP', 'CARRYING', 'ARRIVED', 'COMPLETED') NOT NULL COMMENT '状態', created_at DATETIME(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6) COMMENT '状態変更日時', PRIMARY KEY (ride_id) ) COMMENT = 'ライドの最新ステータステーブル。ride_statusesをもとに構築される';
通知系エンドポイントが呼ばれる頻度を増やす
通知系エンドポイントの負荷が高いので3000msおきに呼ばれるようにして緩和していたのですが、そろそろいいんじゃないか、ということで500ms秒おきに呼ばれるようにしました。点数が6000点ぐらいから14000点ぐらいまで伸びてました。2倍になっててウケるね。
chair_idごとの最新のride_statusesを非正規化する
ride_statuses テーブルには chair_id カラムがなくて大変！！ ということで手こずりましたがなんとか手なずけました。
GET /api/app/nearby-chairs で非正規化した行を参照するようにしたり、chair_idごとの最新の位置情報を非正規化してもらっていたのを参照するようにしたりして、めでたく GET /api/app/nearby-chairs のN+1クエリを完全に解消できました。
トレーシング系グッズを外す
ENABLE_TRACING=1 環境変数を指定したときだけトレーシング系のライブラリを有効にするようにしました。
やらなかったこと
POST /api/chair/coordinate の書き込みバッファリング
POST /api/chair/coordinate の呼ばれる頻度が高く、書き込みヘビーになっているし、レギュレーションに記載されている遅延の範囲で書き込みをバッファリングしてもいいのかな～と思っていましたが、他の箇所の改善に取り組んだり様子を見たりしていたので、最後まで着手しませんでした。
通知のSSE化
アプリケーションマニュアルをまったく読んでいなかったので、通知をServer-Sent Eventsとして送るようにしてもよい、ということに気づいていなかった……。
決済のリトライ
アプリケーションマニュアルをまったく読んでいなかったし、決済マイクロサービスがボトルネックにならなかったので手を入れていません。
アプリケーションマニュアルには Idempotency-Key ヘッダを指定できると書いてあるので、ちゃんと読んでいたらオッとなったと思います。Idempotency-Key ヘッダ好きだし実戦投入したいんだよな～。ここで安全にリトライできない決済マイクロサービスが動いていたら嫌すぎるな。
DBの垂直分割
最新のライドの状態などだけ別のDBに分ける、ということを考えましたが、競技時間中にうまい分割方法を思い付けず没になりました。
マッチングのキューをアプリケーション側で実装する
マッチングのキューにMySQLを使わず、goroutineとチャネルでキューを実装しようとしましたが、エンキューはされるけどデキューされないキューが完成してしまったため没になりました。普段やらないようなことをやるとすぐバグる、ということの典型っぽいですね。チャネルあんまり使わないんだよな～。
よかったこと
効果が分かりやすい改修から順番に着手した
トレースの結果を見て、レイテンシが大きすぎる・呼ばれる頻度が高いエンドポイントから順番に対応を検討し、対処する、というのを初動でちゃんとできていたと思います。
Grafanaでpt-query-digestの結果が見れるようになってからは、なんでもないSELECTクエリなのに上位に来ているものに対して必要なインデックスを貼る、というのを順番にやっていました。
ISUCONで上位に入るには何らかの飛び道具が必要になるんじゃないか、というイメージを持たれる方も多いと思いますが、このような地道な改善を避けて通ることはできないと自分は考えています。
こういった改修を支える可視化技術については id:nonylene さんの記事を見てください。
GitHub Copilotを活用した
実はGitHub Copilotを使っていなかったのですが、このたびトライアルを開始しました。
Ride 型のスライスの変数 rides から Ride.ID のスライスを作る、のような典型的な処理なら、rideIDs := とだけ書いてTabキーを押すだけで勝手に完成します。
sqlx.In 関数を使いつつ、複数のIDを指定して chairs テーブルをクエリする、ぐらいの関数はちょっと修正したら使えるコードが出てきます。
最初は確か以下のようなコードが生成されました。このコードはそのままでは動きません。
func getChairsByIds(ctx context.Context, tx *sqlx.Tx, chairIDs []string) (map[string]*Chair, error) { var chairRows []*Chair if err := tx.SelectContext(ctx, &chairRows, "SELECT * FROM chairs WHERE id IN (?)", chairIDs); err != nil { return nil, err } chairs := make(map[string]*Chair) for _, chair := range chairRows { chairs[chair.ID] = chair } return chairs, nil }
プレースホルダにスライスを直接渡すことはできません。IN句を使ったクエリを発行するときは、プレースホルダの数とスライスの長さを合わせたクエリを組み立てる必要があります。この場合は sqlx.In 関数を使うことで簡単にクエリを組み立てられます。
また、sqlx.In 関数に対して空スライスを渡すと実行時エラーが返ります。したがって、chairIDs が空の場合はearly returnするべきです。
加えて、引数としてトランザクション *sqlx.Tx を受け取ってもいいけど、 sqlx.QueryerContext interfaceを受け取るようにしておくと *sqlx.DB も渡せるようになって使う側の制約が小さくできていいですね。
ということで、自分が考えて書き直した正解のコードはこう:
func getChairsByIds(ctx context.Context, q sqlx.QueryerContext, chairIDs []string) (map[string]*Chair, error) { if len(chairIDs) == 0 { return nil, nil } query, args, err := sqlx.In("SELECT * FROM chairs WHERE id IN (?)", chairIDs) if err != nil { return nil, err } var chairRows []*Chair if err := sqlx.SelectContext(ctx, q, &chairRows, query, args...); err != nil { return nil, err } chairs := make(map[string]*Chair) for _, chair := range chairRows { chairs[chair.ID] = chair } return chairs, nil }
ちゃんと動作するコードに書き換えるのは最初の1回ぐらいで、あとは func getOwnersByIds のように関数名を書くだけで欲しい・ちゃんと動作する実装が生成されるようになりました。これまでは自分の手を速く動かすことでカバーしていたのですが、こういう実装がポンと出てくるのはいいですね。
書いててだんだん思ったけど、ジュニアメンバーに対するコードレビューのような気持ちでCopilotと向き合うのが大事なんだろうなと思いました。
いまいちだったこと
マニュアルをちゃんと読まなかった
これ毎年書いてる気がしていて反省が活かされていないのでは？？ 初手で実装を見て直すところに集中してしまってマニュアルに意識が向いていないかも。
何が点数に寄与しているのか明確でない時間が長かった
16時ぐらいに25000点ぐらいを記録していたけど、そこから競技終了間近まで苦しい時間が続いていました。wassに配車マッチングの仕組みを改善してもらっても20000点も出ない、長時間マッチングされずに確率的にFAILする、という感じで明らかに不穏。
答えはマッチングの間隔でした。0.1秒ごとにマッチングさせる設定にしていたけどいつの間にか0.5秒ごとに戻ってしまっていたため、点数の伸びが悪かったり、長時間マッチングせずにFAILしたりしていました。0.1秒ごとにマッチングさせるように戻した上でベンチマークを走らせたのが最終スコアになります。
このあたりはもうちょっと冷静に状況を分析できたらよかったかな～。
「ミレニアムサイエンススクール」について
適当にチーム名をつけて申し込んだままにしていたら、チーム名の変更ができる期間を過ぎており、そのまま出場しました。
おわりに
今年の問題も程よいボリューム感で解きごたえがあったと思います。最後までやりたい施策が尽きることもなく、終盤以外はずっと手を動かすことができました。来年も上位入賞して「偶数回だけ本選に出る」のジンクスを破れるといいですね。
id:papix
id:stefafafan
id:asumiso
