なまえは まだ ない

思いついたことをアウトプットします

ISUCON14延長戦の記録⑨ N+1問題の解消とクロージング

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回は2つめの通知エンドポイントレスポンスをキャッシュし、ついに本戦当時の6位相当までスコアを伸ばすことができました。 今回はユーザーの通知エンドポイントの中で気になった実装の改善、最後のチューニングに触れていきます。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

椅子の評価情報を簡単に取得する

ユーザーの通知エンドポイントのレスポンスには椅子の評価情報が含まれています。 内容としてはこれまでに完了したライドの数と、これまでに受けた評価の平均値です。

github.com

初期実装は以下リンクのとおりで、椅子にこれまで割り当てられたライドの一覧を取得したあと、ライド毎に最新のステータスを取得するという、非常にわかりやすいN+1問題になっています。 https://github.com/furusax0621/isucon14-extend/blob/e5834de96efcf5e27cb7f4189951ee0f6fa8eb0d/webapp/go/app_handlers.go#L766-L817

これまでの実装により、ライドとその最新のステータスは単純なJOINができるようになりました。ライド数と評価の合計値も簡単な集計クエリで取得可能です。レスポンスに必要な平均値は、クエリで合計値を取得後にアプリケーション側で計算しました。

SELECT
    COUNT(r.evaluation) AS total_rides_count,
    SUM(r.evaluation) AS total_evaluation 
FROM rides AS r
JOIN ride_latest_statuses AS rl
    ON r.id = rl.ride_id
WHERE
    rl.status = 'COMPLETED'
    AND r.chair_id = ?

競技終了前の最終チューニング

スコアを伸ばすための最後の一押しとして、サーバーで記録している各種ログを無効化します。 ログ出力は多少なりとも計算コストやディスクへの書き込みコストが発生するため、これらを無効化することでパフォーマンス改善が見込めます。

アプリケーションコードからpproteinエージェントを削除する

計測用に導入したpproteinエージェントの実装を削除します。Pull Requestを作るのも面倒だったので、mainブランチに直プッシュしました。以下のコミットです。

github.com

MySQLのスロークエリログを無効化する

template-isucon-recipeで追加したスロークエリログの設定を削除します。設定は独立したファイルになっているため、そのファイルをそのまま削除すればOKです。

sudo rm -f /etc/mysql/mysql.conf.d/slow-query-log.cnf

MySQLのバイナリログを無効化する

MySQL 8.0ではデフォルトでバイナリログが有効になっており、この書き込みがパフォーマンスに影響を与えます。これも無効化しておくことでパフォーマンス改善が見込めます。

/etc/mysql/my.cnf などに以下の設定を追加しましょう。

[mysqld]
disbale-log-bin

Nginxのアクセスログを無効化する

アクセスログをalpで解析するための設定を削除しつつ、Nginx全体でアクセスログを無効化します。alp用の設定はtemplate-isucon-recipeによって反映されているので、ファイルを削除すればOKです。

sudo rm -f /etc/nginx/conf.d/alp.conf

アクセスログの無効化は /etc/nginx/nginx.conf を修正し、アクセスログの設定をしている箇所を探して以下のように記述しましょう。

access_log off;

終結

ここまでの変更をすべて反映し、何度かベンチマーカーを動かし、最終的に51,873点まで到達しました。本戦当時のスコア換算だと4位相当です。頑張ったけど1位には届かなかった……残念!

(宣言どおり、ちゃんとまとめ記事書いたぞ。えらい)

まとめ

今回、運営側の御厚意で得た延長戦のチャンスを使って、改めて問題を解いてみました。新しい発見や学びがあり、非常に充実したチャレンジでした。運営の皆さま、本当にありがとうございました。

一方で、最終的に3台目のサーバーを使えなかったこと、SSEなど実装しきれずに諦めたことなど、課題もたくさんあります。現時点でトップスコアは50万点を超えていることからも、まだまだ改善の余地はあるようです。まとまった時間があるときに、改めて考えたり、他の参加者の解法を解読したりしてみようと思います。

ISUCON14延長戦の記録⑧ インメモリキャッシュに手を出す(その2)

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回は通知エンドポイントのひとつである、椅子の通知エンドポイントを高速化しました。 今回はもうひとつの通知エンドポイントにインメモリキャッシュを導入します。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

ユーザーの通知エンドポイントレスポンスをキャッシュする

前回と同様、レスポンスで返す情報のキャッシュを試みます。 このエンドポイントではユーザーがリクエストしているライドの情報、ライドに割り当てられた椅子の情報などを返しています。 椅子の情報をキャッシュしていくのは少し骨が折れそうだったので、ライドの情報に限定してキャッシュしてみました。

完全な差分は以下のPull Requestのとおりです。

github.com

実装に関してはほぼほぼ前回の修正と同様です。効果が大きかった変更も同様で、ライドをリクエストしてないユーザーへのレスポンスを高速に返せるようになりました。

// キャッシュからライド情報を取得
rideMapByUserIDMutex.RLock()
rideFromMap, ok := rideMapByUserID[user.ID]
rideMapByUserIDMutex.RUnlock()

if !ok {
    writeJSON(w, http.StatusOK, &appGetNotificationResponse{
        RetryAfterMs: 30,
    })
    return
}

https://github.com/furusax0621/isucon14-extend/blob/eda0047d9d96b8f1968eff0546d533f8a63cfe12/webapp/go/app_handlers.go#L670-L680

まとめ・次回予告

前回に引き続き、通知エンドポイントのレスポンスをキャッシュすることで高速化を試みました。 ベンチマークの結果はおよそ43,000点!本戦終了時のスコア換算だと6位相当です!すごい、うおおお!

いよいよネタが尽きてきた……が、ユーザーの通知エンドポイントを眺めていたら気になる箇所が出てきました。次回はそこの改善に取り組みます。つづく。

ISUCON14延長戦の記録⑦ インメモリキャッシュに手を出す

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回は細かいチューニングをしつつ、MySQLサーバーを別インスタンスに切り出しました。スコアは本戦当時の上位入賞に食い込める28,000点まで伸びています。

またしてもやることが見えなくなってきたので、講評を読みながら改善点を探ることにしました。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

通知エンドポイントの高速化

解説・講評を読んでいると2種類の通知エンドポイント /api/app/notification /api/chair/notification の高速化について言及されています。当日のマニュアルにもあるとおり、これらのエンドポイントはSSE(Server Sent Events)への実装差し替えが可能です。が、正直SSEについての知識も実装できる自信もなかったため、JSON APIのまた愚直にキャッシュしていくことにしました。

椅子の通知エンドポイントレスポンスをキャッシュする

椅子の通知エンドポイントのレスポンスをよく見てみると、椅子がライドにマッチングしている場合、その情報を返すようです。 返すべきライドの情報はいくつかありますが、ステータス以外の情報は固定であることからこの情報をインメモリキャッシュできそうだと考えました。

完全な差分は以下のPull Requestで確認できます。

github.com

恥ずかしながらRedisなどインメモリデータストアに関する知見が乏しいので、sync.RWMutexとmapで愚直に実装しました。mapは椅子のIDをキーに、椅子がマッチングされているライドの情報をもつマップとして宣言しています。mapを更新するタイミングは以前導入した chairs.is_free カラムと一緒です。マッチングしたタイミングでmapに追加し、通知エンドポイントで COMPLETED を椅子に通知したタイミングで削除すればOKです。

実装してから気付いたのですが、このmapを導入することによって椅子にライドが割り当てられてないときのレスポンスを高速に返せるようになりました。ちょうど以下の実装箇所です。

rideMapByChairIDMutex.RLock()
ride, ok := rideMapByChairID[chair.ID]
rideMapByChairIDMutex.RUnlock()

if !ok {
    writeJSON(w, http.StatusOK, &chairGetNotificationResponse{
        RetryAfterMs: 30,
    })
    return
}

https://github.com/furusax0621/isucon14-extend/blob/eda0047d9d96b8f1968eff0546d533f8a63cfe12/webapp/go/chair_handlers.go#L211-L220

map導入前は椅子のIDをキーに最新のライド情報を取得し、ライドが存在しないか完了していれば割り当てられてないと判断していました。 データベースアクセスが必要な上、ロジックの都合上トランザクションを作成する必要があるのでどうしても重くなってしまうようです。 これをデータベースアクセスなしで判断できるようになったのは、とても効果が大きかったようです。

まとめ・次回予告

2つある通知エンドポイントのひとつである椅子の通知エンドポイントを修正し、椅子毎のライド情報をキャッシュできるようにしました。 これを導入したところ、スコアが37,900点程度にまで伸びました。どんどん上がりますね。楽しくなってきた。

次回はもうひとつの通知エンドポイントのキャッシュをしてみます。つづく。

ISUCON14延長戦の記録⑥ MySQLサーバーを別インスタンスにする

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回はISUCON14の目玉のひとつ(?)であるマッチングアルゴリズムの改善をしました。 これまでの改善も含め、スコアを一気に17,000点まで伸ばすことができました。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

やることがなくなってきた

マッチングアルゴリズムの改善まで済ませたところで、次にやるべきことが思いつかなくなりました。 自身の発想力のなさに嫌気が指します。

とりあえず苦し紛れに入れた改善を紹介します。スコアはわずかですが伸び、18,700点程度になりました。

インデックスの追加

改善の糸口を見つけるためにスロークエリログを眺めていたところ、クーポンを検索するクエリでインデックスが効いてないことに気付きました。 クーポンはユーザー増加によって使われる機会が増える機能です。初期実装では他の箇所がボトルネックになっていたことで、このクエリが上位に出てこなかったのでしょう。

追加したインデックスは以下のPull Requestで確認できます。

github.com

ライドの最新ステータスをテーブル管理する

ライドのステータスはride_statusesテーブルで管理されています。以前改善した椅子の位置情報と同様、履歴テーブルとして実装されています。アプリケーションの各所でこのテーブルから最新のステータスを取得する関数が呼ばれており、N+1問題になっている箇所もありました。

そこでライド毎の最新ステータスのみを管理するride_latest_statusesテーブルを追加し、ridesテーブルとJOINすることでライドの情報と最新ステータスを一度に取得できるようにしました。

なお、このテーブルについてもライドの初期データの情報を復元する必要がありますが、初期データの中身を覗いたところ登録されるライドはすべて完了済みになっていそうでした。 本来であれば椅子の位置情報と同様にride_statusesテーブルを時系列順に取得してUPSERTをかけるべきですが、ここは一定サボって固定で COMPLETED を挿入しています。

完全な差分は以下のPull Requestを参照してください。

github.com

MySQLサーバーを別インスタンスに分離する

そろそろ一台で色々やりくりする時期も終わったかなと判断し、ここでMySQLサーバーを別インスタンスに切り出すことにしました。 アプリケーションコード的には env.sh に記載されているホストを書き換えるだけで良いです。以下のPull Requestのとおりです。

github.com

※ なぜかInitializeエンドポイントがコケるようになったので、ライドの最新ステータスの挿入をUPSERTにしています

以下、MySQLサーバーを分離するためにやったコード変更以外の作業を紹介します。

インスタンスからのアクセスを許可する

MySQLサーバーがネットワーク経由で接続を受け付けるには、いくつかの設定が必要です。

まずはMySQLユーザーのホスト指定です。MySQLユーザーにはユーザー名の他にホストの概念があり、このホストが一致しないと例えユーザー名とパスワードが一致してもログインできません。 MySQLにrootユーザーでアクセスし、 mysql.user テーブルの情報を確認しましょう。ISUCON14の環境では、 sudo mysql でrootユーザーとしてログインすることが可能でした。

SELECT host, user FROM mysql.user;

ここでアプリケーションで利用しているユーザーのホストが localhost などになっている場合、他のホストからアクセスできるようユーザーを作成するなどの作業が必要です。幸いISUCON14では % (任意のホスト)が指定されていたため、この作業は不要でした。

次はMySQLサーバーが通信を受け付けるIPアドレス帯の指定です。 /etc/mysql.my.cnf/etc/mysql/mysql.conf.d/mysqld.cnf ファイルを確認し、 bind-address パラメータの値を確認します。MySQLのデフォルトは 127.0.0.1 (ローカルホストのみ許可)になっています。一番手軽なのは、これを 0.0.0.0 (任意のホスト)に書き換えることです。

[mysqld]
bind-address = 0.0.0.0

各種サービスの設定

MySQLサーバーを動かすインスタンスでは、アプリケーションやNginxサーバーが稼働している必要はありません。 不要なサービスは停止させ、CPUやメモリのリソースを有効活用できるようにしましょう。

sudo systemctl stop isuride-go.service
sudo systemctl disable isuride-go.service
sudo systemctl stop nginx.service
sudo systemctl disable nginx.service

また、スロークエリログを収集するためにpproteinエージェントを起動します。 競技序盤ではアプリケーションコードにpproteinエージェントを統合することを想定し、template-isucon-recipeはpproteinエージェントのサービスはインストールのみ行い、起動しないようになっています。 この先の改善のヒントを探すためにも、pproteinエージェントを起動しておきます。

sudo systemctl start pprotein-agent.service
sudo systemctl enable pprotein-agent.service

まとめ・次回予告

MySQLサーバーを分離したところ、さらにスコアが伸びて28,000点近くまで到達しました。本戦最終スコア換算でいうと25位に相当します。すごい、上位入賞だ!

スロークエリログの出力をオフにするなど細かいチューニングまで含めると33,500点まで届きました。本戦最終スコア換算で14位相当、特別賞を受賞できるラインです。

ここからもうひと伸びしたいなぁ〜と、再び講評を読んでヒントを探っていきます。つづく。

ISUCON14延長戦の記録⑤ マッチングアルゴリズムを改善する

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回は椅子の総移動距離を管理するカラムを追加することにより、非常に重いクエリを軽量化しました。が、スコアはまだまだ伸びません。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

マッチングアルゴリズム

アプリケーションマニュアルにあるとおり、椅子とライドのマッチングは一定間隔(初期実装では500ms)でリクエストされる内部APIによって実現しています。 この実装がよろしくなく、ベンチマークの結果を見ると次のようなログが頻出します。ライドがマッチングされるまでの時間に多くのユーザーが不満を抱えていることがわかります。

100.0%のライドは椅子がマッチされるまでの時間、50.0%のライドはマッチされた椅子が乗車地点までに掛かる時間、100.0%のライドは椅子の実移動時間に不満がありました

本戦当時も、このログからマッチングアルゴリズムが足を引っ張ってるなと気付くことができました。今回はここの改善に取り組みます。

なお、初期実装では「ここがまずいから直してくれ」と言わんばかりのコメントが書いてあります。当時これを見つけてめっちゃ笑いました。

// MEMO: 一旦最も待たせているリクエストに適当な空いている椅子マッチさせる実装とする。おそらくもっといい方法があるはず…

アルゴリズムの改善

完全な変更内容は以下のPull Requestにまとまっています。

github.com

改善方針

初期実装のアルゴリズムでは、一回のリクエストで常にひとつのライドしかマッチングしないようになっています。 あまりにも効率が悪いので、以下のように一回のリクエストでバルク的にマッチングする方針としました。

  1. マッチング待ちのライドをすべて取得する
  2. 現在空いている椅子を、その位置情報とともにすべて取得する
  3. ライド毎にループする
    1. 椅子毎にループし、ライドの始点との距離を計算する
    2. 最も近い距離にいた椅子を抽出し、ライドとのマッチング対象とする
    3. 椅子が複数のライドに割り当てられないよう、2で抽出された椅子を椅子の一覧から除外する
  4. ライドと椅子のマッチング情報を登録する
  5. 椅子を空いてない状態( is_free = FALSE )にする

3のループはライドの登録日時順で回しました。 ライドに長時間椅子がマッチングしないとクリティカルエラーになってしまうため、とにかく一番待たせているライドを最優先でマッチングするようにしています。

また、最も近い距離にいた椅子を割り出すためのしきい値として 400 という距離を設定しています。 解説記事にもあるとおり、ライドはサービス提供エリア内を移動することから、同エリア内に存在する椅子に限定してマッチングさせ、別エリアにいるような椅子とのマッチングは見送ったほうが効率が良くなります。 400 は解説記事の参考実装に出てくるしきい値で、その値をそのまま頂戴しました。

Too many connections との格闘

上記の改善アルゴリズムを実装すると、負荷走行中に Too many connections というメッセージとともに500エラーが頻発し、ベンチがコケるようになりました。トランザクションの構成など細かい調整をしましたが、根本的な解決にはならなかったため、MySQLサーバーのパラメータを調整することにしました。

MySQLサーバーのデフォルト値では、max_connectionsパラメータは151に設定されています。database/sql パッケージのコネクションプールはデフォルトで無制限にコネクションを確立するようで、おそらくアルゴリズム改善によってユーザーが増加し、同時リクエスト数が増えたことでコネクション数の上限をオーバーしてしまったのでしょう。

この問題を解決するため、 /etc/mysql/mysql.conf.d/conn.cnf ファイルを作成し、次のような設定を入れました。

[mysqld]
max_connections = 1000

併せて、アプリケーションコード側でもコネクションプールの設定を調整します。設定根拠は以下の記事を参考にしました。昔会社の先輩に教えてもらった記事で、今でもバイブル的にブックマークしている記事のひとつです。

dsas.blog.klab.org

SetMaxOpenConnsMySQLサーバーのmax_connectionsを最大値としつつ、同時接続するサーバー数で割ります。現状は1インスタンスしか使ってないのでそのまま1,000を設定しました。 SetMaxIdleConnsSetMaxOpenConns 以上であれば良いとのことなのでそのまま1,000とします。 SetConnMaxLifetime はベンチマーカーが負荷走行をかける時間以上にせっていしておけば良さそうです。負荷走行が60秒程度で完了するので、少し長めにとって80秒としました。

db.SetMaxOpenConns(1000)
db.SetMaxIdleConns(1000)
db.SetConnMaxLifetime(80 * time.Second)

これらの設定を追加することで、無事Too many connecitonsから解放され、ベンチが通るようになりました。

まとめ・次回予告

この変更を取り込んだ結果、スコアが一気に17,000点程度にまで上昇しました。これまでにないジャンプアップ、そして本戦当時の最高スコアを大幅更新です。やった!

ようやく、今まで見たことない景色を見れる位置まできました。また更にチューニングを続けていきます。つづく。

ISUCON14延長戦の記録④ 激重の集計クエリを軽量化する

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回はN+1どころじゃない問題を解消するために、椅子の空き状況と最新位置情報をデータベースで管理できるようにしました。 エンドポイント単体はとても軽量になりましたが、残念ながらスコアは思うように伸びませんでした。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

重すぎる集計クエリ

さて、前回の修正を入れると次に目立ってくるのが /api/owner/chairs エンドポイントです。 出題者の解説記事にも「いわゆる観光名所」と言われている箇所ですね。

/api/owner/chairs エンドポイントはオーナー向けのエンドポイントで、自身が管理している椅子の総走行距離を計算して出力します。初期実装では、この情報の計算にはchair_locationsテーブルが利用されていました。chair_locationsテーブルは過去の位置情報をすべて保存している履歴テーブルになっているため、目を背けたくなるような複雑なクエリが実装されています。

https://github.com/furusax0621/isucon14-extend/blob/e5834de96efcf5e27cb7f4189951ee0f6fa8eb0d/webapp/go/owner_handlers.go#L198-L219

このクエリの改善について、解説記事には次のように記述されています。

また、最新以外の chair_locations はここでの total_distance を計算することにしか使われないことと、新しく椅子の位置情報が記録されるとき次の total_distance は1つ前の位置情報とそれまでの total_distance から計算できることに気がつけると、各椅子ごとに最新の位置情報と総走行距離を持つテーブルを作りUPSERTだけで管理できるようになり、ここでのクエリをはじめ様々なクエリをシンプルにすることができます。

前回の記事で椅子の最新の位置情報を記録する chair_last_locations テーブルを追加していました。このテーブルを少し調整すれば、問題のクエリを簡素にできそうです。

総走行距離を記録するカラム追加

解説記事に従い、chair_last_locationsテーブルに総走行距離を記録するtotal_distanceカラムを追加しました。デフォルト値に0を入れ、位置情報を更新する度に加算していく運用にします。

total_distance INTEGER NOT NULL DEFAULT 0 COMMENT '総移動距離'

前回の修正では位置情報を更新する度にUPSERTするクエリを実装していましたが、ここにtotal_distanceの更新を追加します。total_distanceは更新前のレコードを参照して更新しないといけないので、ちょっと書き方が難しくなります。この辺りが少し難しくてChatGPTに色々相談しながら作りました。

INSERT INTO chair_last_locations
    (chair_id, latitude, longitude, updated_at, total_distance)
    VALUES (?, ?, ?, ?, 0) AS new
ON DUPLICATE KEY UPDATE 
    total_distance =
        chair_last_locations.total_distance
            + ABS(chair_last_locations.latitude - new.latitude)
            + ABS(chair_last_locations.longitude - new.longitude),
    latitude = new.latitude,
    longitude = new.longitude,
    updated_at = new.updated_at;

INSERTのときは0を挿入し、UPDATEするときに元のレコードとの差分を計算して加算する、という実装です。 更新するカラムを記述する順序が大事らしく、total_distanceの更新式を最後に記述すると計算結果が0になってしまいます。 おそらくですがlatitudeとlongitudeの更新式を先に書いてしまうと、 chair_last_locations.latitudechair_last_locations.longitudenew の値になってしまうんだと思います(よくわかってないので有識者の方、教えてください!)。 試行錯誤している中でしばらくこの現象に気付けず、だいぶ長いこと頭を抱えました。

改善された集計クエリ

total_distanceカラムが誕生したことによって、初期実装にあった集計クエリが一切不要になりました。該当クエリは以下のようにchair_last_locationsテーブルを参照するだけで良くなりました。

SELECT c.id,
    c.owner_id,
    c.name,
    c.access_token,
    c.model,
    c.is_active,
    c.created_at,
    c.updated_at,
    IFNULL(cl.total_distance, 0) AS total_distance,
    cl.updated_at AS total_distance_updated_at
FROM chairs AS c
LEFT JOIN chair_last_locations AS cl
    ON c.id = cl.chair_id
WHERE c.owner_id = ?

リクエスト時点でまだ椅子が位置情報を送信していない可能性があるため、chair_last_locationsテーブルとはLEFT JOINする必要があります。その点にだけ注意が必要です。 これらを取り込んだ完全な変更内容は以下のPull Requestを参照してください。

github.com

まとめ・次回予告

非常に重い集計クエリを取っ払い、またひとつエンドポイントを軽量化できました。しかしまたしてもスコアは伸びず、3,500点程度に留まってます。 次スコアが伸びるのはいつになるんでしょうか。。つづく。

ISUCON14延長戦の記録③ N+1どころじゃない問題の改善

ISUCON14の延長戦をやってます

以下の記事の続きです。

furusax0621.hatenablog.com

前回はスロークエリログから必要なインデックスを割り出して追加しました。スコアは3,500程度まで伸びています。 ここからアプリケーションコードに手を入れていきます。

なお、最終的なコードは以下のリポジトリで公開しています。

github.com

N+1どころじゃない問題

出題者による解説・講評でも言及されていますが、アクセスログなどからもまず最初に目を引くのが /api/app/nearby-chairs エンドポイントの重さです。何が悪いのかは非常にわかりやすく、いわゆるN+1問題の派生と見ることができます。

https://github.com/furusax0621/isucon14-extend/blob/e5834de96efcf5e27cb7f4189951ee0f6fa8eb0d/webapp/go/app_handlers.go#L874-L941

N+1問題って?

ISUCONに参加している方にはお馴染みのアンチパターンですが、一回目のクエリで取得したN件のレコードでループを組み、そのループの中でまたクエリを組むような実装を言います。ループで発生するN回のクエリに、最初の一回分のクエリを加えることでN+1回のクエリが回ることからN+1問題と呼ばれています。

今回のテーブル定義で例を挙げるとすると、chairsテーブルとchairs_locationテーブルのような構成があると発生しやすいです。

DROP TABLE IF EXISTS chairs;
CREATE TABLE chairs
(
  id           VARCHAR(26)  NOT NULL COMMENT '椅子ID',
  owner_id     VARCHAR(26)  NOT NULL COMMENT 'オーナーID',
  name         VARCHAR(30)  NOT NULL COMMENT '椅子の名前',
  model        TEXT         NOT NULL COMMENT '椅子のモデル',
  is_active    TINYINT(1)   NOT NULL COMMENT '配椅子受付中かどうか',
  access_token VARCHAR(255) NOT NULL COMMENT 'アクセストークン',
  created_at   DATETIME(6)  NOT NULL DEFAULT CURRENT_TIMESTAMP(6) COMMENT '登録日時',
  updated_at   DATETIME(6)  NOT NULL DEFAULT CURRENT_TIMESTAMP(6) ON UPDATE CURRENT_TIMESTAMP(6) COMMENT '更新日時',
  PRIMARY KEY (id)
)
  COMMENT = '椅子情報テーブル';

DROP TABLE IF EXISTS chair_locations;
CREATE TABLE chair_locations
(
  id         VARCHAR(26) NOT NULL,
  chair_id   VARCHAR(26) NOT NULL COMMENT '椅子ID',
  latitude   INTEGER     NOT NULL COMMENT '経度',
  longitude  INTEGER     NOT NULL COMMENT '緯度',
  created_at DATETIME(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6) COMMENT '登録日時',
  PRIMARY KEY (id)
)
  COMMENT = '椅子の現在位置情報テーブル';

まずchair_locationsテーブルのレコードを取得し

SELECT * FROM chair_locations;

このクエリで取得できるN件のレコードでループを組み、chairsテーブルに問い合わせるというものです。

SELECT * FROM chairs WHERE id = ?;

解決方法としては、各テーブルをJOINしてしまうというのが一般的かなと思います。今回の例では以下のようにJOINすれば1クエリで必要な情報をすべて入手できます。

SELECT * FROM chair_locations AS cl JOIN chairs AS c ON c.id = cl.chair_id;

N+1どころじゃない問題って?

問題のコードに戻ります。該当コードですが、初期実装では次のようなロジックになっていました。

  1. 椅子の情報を全件取得する(N件入手)
  2. 椅子毎にループ
    1. 椅子が割り当てられたライドを全件取得(M件入手)
    2. ライド毎にループ
      1. ライドの最新ステータスを取得
    3. ライドの情報から、椅子が空いてない(=ライド可能でない)ならコンティニュー
    4. 椅子の最新位置情報を取得

2のN回のループの中で2-2のM回ループが発生し、その中で一回(2-2-1)クエリが発行されています。更にN回ループの中では二回(2-1, 2-4)クエリが発行されています。 初回のクエリと合わせると、なんとN(M+2)+1回です。解説記事では2N+1問題と書かれていますが、このロジックは正確にはN(M+2)+1問題です!恐ろしい!

問題の分析

この問題が発生している原因ですが、一番の問題は椅子が空いている(=ライド可能である)ことを知るために、椅子が過去に割り当てられたすべてのライドの状態を走査する必要がある点にあります。この情報を簡単に知る術があれば、わざわざライドを取得する必要はありません。

また、椅子の位置情報を保存する chair_locations テーブルは履歴を管理するテーブルであり、椅子の最新の位置情報を簡単に入手できないという点も問題です。椅子の最新の位置情報を表すレコードを特定できれば、最初のクエリにJOINすることで椅子と位置情報を一度に取得できるはずです。

N(M+2)+1問題を解消する

最終的な差分は以下のPull Requestになります。2つの問題を同時に解決しています。

github.com

椅子が空いているという情報をテーブルで管理する

椅子毎に「空いているかどうか」という情報を管理すれば良いと思ったので、chairsテーブルに is_free というカラムを追加し、ライドのライフサイクルに合わせてこのカラムを更新するように実装しました。

まずchairsテーブルへのカラム追加になるわけですが、スキーマ管理しているSQLファイルを直接編集してカラム追加したところ、デフォルト値を入れても初期データ投入でコケるようになってしまいました。。ちょっと原因がよくわからなかったので、インデックス作成と同じタイミングでカラムを追加するクエリを実行することにしました。

ALTER TABLE chairs ADD COLUMN is_free TINYINT(1) NOT NULL DEFAULT 1;

うっかりやりがちなのが、テーブル定義をキレイに見せるために既存のカラム定義の途中(例えば、 is_active の次とか)に挿入してしまうパターンです。ISUCONではほとんどのコードが SELECT * でレコードを取得しているので、カラムの順序が変わるとスキャン時に不具合を起こす可能性があります。ORM(sqlx)を使っているとはいえ、素直にカラム定義の最後に挿入するのが無難です。

カラム作成ができたら次は更新タイミングです。TRUE→FALSEになるタイミングはわかりやすく、椅子とライドがマッチングしたときです。椅子とライドのマッチングは定期実行される内部APIによって行われており、そのエンドポイントのトランザクションの一部として追加すればOKです。

一方、FALSE→TRUEになるタイミングの見極めは少し複雑です。一見するとライドが完了した、つまりユーザーがライドの評価をするエンドポイントのトランザクションの中でやれば良い気がします。しかし正直にそのタイミングで実装すると、おそらく「椅子がライド完了の通知を受け取る前に新しいライドに割り当てられた」という旨のエラーが発生し、ベンチマークに失敗します。アプリケーションマニュアルを読むと、次のように記載されています。

椅子は自分に割り当てられたライドが COMPLETED になるまで、他のライドを受理することができません。

また、椅子が自身の状態を受け取るための通知エンドポイントというものがあり、椅子はこのエンドポイントをポーリングすることで自身に割り当てられたライドの情報を管理しているらしいです。

このことから、椅子を空いているという状態に更新して良いのは「ライドが完了したという情報を椅子が受け取った」タイミングとなります。椅子の通知エンドポイントの中で、ライドの状態が COMPLETED のとき is_free カラムを更新するように実装しました。

椅子の最新位置情報をテーブルで管理する

これは単純に椅子の最新位置を記録するテーブルを追加しました。

CREATE TABLE chair_last_locations
(
  chair_id   VARCHAR(26) NOT NULL COMMENT '椅子ID',
  latitude   INTEGER     NOT NULL COMMENT '経度',
  longitude  INTEGER     NOT NULL COMMENT '緯度',
  updated_at DATETIME(6) NOT NULL DEFAULT CURRENT_TIMESTAMP(6) ON UPDATE CURRENT_TIMESTAMP(6) COMMENT '更新日時',
  PRIMARY KEY (chair_id)
)
  COMMENT = '椅子の最終位置情報テーブル';

管理方法も非常にシンプルで、chair_locationsテーブルにレコードが挿入される箇所を探し出し、同一トランザクション内でこのテーブルにUPSERTをかけるだけです。

初期データの考慮

ISUCONで毎度厄介になるのが、新しいテーブルやカラムを追加したときに発生する、初期データとのミスマッチです。今回は初期データの中に椅子や椅子の位置情報履歴が含まれているため、これらのデータから椅子の最新位置を復元しておかないと、初期状態がおかしなことになってしまいます。SQLに造詣の深い方ならINSERT SELECTなどを使ってスマートに復元できると思いますが、私のSQL力は貧弱なので愚直にchair_locationsテーブルを時系列順に取得し、chair_last_locationsテーブルにUPSERTする方法をとりました。。

なお、 is_free カラムの状態については特に復元をしていません。初期データの中に「現在稼働中のライド」が存在していたら困るのですが、初期データを検査したところすべてのライドが完了していそうだったので大丈夫だろうと判断しました。ちょっとここはズルいハックをしています。

改善後のクエリ

2つの修正により、N(M+2)+1問題のクエリは以下のようなシンプリな1クエリで実現できるようになりました。素晴らしい!

SELECT
    c.*, l.latitude, l.longitude
    FROM
        chairs AS c
JOIN
    chair_last_locations AS l
    ON
        c.id = l.chair_id
WHERE
    c.is_free = TRUE 
    AND
        c.is_active = TRUE;

まとめ・次回予告

アプリケーションコード改善の第一弾として、ループクエリによって非常に重くなっているエンドポイントを改善しました。 この状態でベンチを回したところ、該当エンドポイントは劇的に改善しましたがスコアは特に伸びませんでした。あれー?

気を落とさず次の改善箇所を探ります。つづく。