はじめに
Zeals Advent Calendar 2020 の13日目の記事です。
Zeals でインフラエンジニア/データエンジニアをやっている鍵本です。本日は弊社の Rails アプリケーションで使用されていた SQL の EXISTS によって起きてしまった問題についてお話したいと思います。今更な話題ではありますが、我々の知識の整理と反省のためのものと位置付けて書いていきます。
背景
ある日 Slack にアラートが飛んできました。内容は Cloud SQL の CPU 使用率が100%近くまで上がってるよってものです。その時のグラフは下図のようなものでした。
show full processlist コマンドで確認すると、以下のようなクエリが居座っていました(クエリは実際のものとは異なります)。言わずと知れた相関サブクエリですね。「そんなものは INNER JOIN に書き換えて終わりでしょ」と言われそうですが、はい、そのとおりですね。
SELECT
buttons.postback_action_id
FROM
buttons
WHERE
EXISTS (
SELECT
boxes.id
FROM
boxes
INNER JOIN blocks ON blocks.id = boxes.block_id
WHERE
boxes.id = buttons.box_id
AND blocks.id = 10);
このようなクエリが一回呼ばれるくらいならば大したことがなかったのですが、一つのコンテンツを生成するために、上記のようなクエリをIDを変更して最大で数十回も呼ばれたことで、実行中のクエリが多数滞留して CPU 使用率が上がってしまったことがわかりました。
相関サブクエリのパフォーマンス
では相関サブクエリがパフォーマンス的にどうなのか、上記クエリが実行できる環境を作って実際に見てみることにします。
環境
- MacBook Pro 16GB RAM (MacOS 10.15.7)
- MySQL 5.7.32
- ruby 2.6.6
- Rails 6.0.3.4
Rails アプリのモデル作成
bin/rails g model Block name:string
bin/rails g model Box name:string block:references
bin/rails g model PostbackAction url:string
bin/rails g model Button label:string box:references postback_action:references
bin/rails db:create
bin/rails db:migrate
seed ファイルの作成
外枠 Block の中に Box が 5 つ存在し、それぞれの Box の中に Button が最大で 1 つ存在する状態を想定します。そして Button がクリックされると指定 url にジャンプさせる PostbackAction が一つ存在します。このような状態を再現するようなサンプルデータを以下の seeds.rb で作成します。
vi db/seeds.rb
N_BLOCKS = 100000
N_BLOCKS.times do |n|
Block.create!(name: "テスト#{n}")
end
n = 0
r = Random.new
Block.all.each do |b|
5.times do |_|
box = b.boxes.create!(name: "ボックス#{n}")
if r.rand(0..99) > 20
pa = PostbackAction.create!(url: 'https://foo.bar')
box.buttons.create!(label: "ラベル#{n}", postback_action: pa)
end
n += 1
end
end
N_BLOCKS の値を 10〜100,000 まで変えてデータを作成します。上記ファイルは 100,000 の場合の例になります。
データの作成
bin/rails db:reset
クエリ実行時間の測定
以下のスクリプトを使って、当該クエリを 100 回実行し、その平均値をクエリの実行に要する時間とします。
#!/bin/bash
loops=100
db=correlated_subquery_development
query="SELECT buttons.postback_action_id FROM buttons WHERE EXISTS (SELECT boxes.id FROM boxes INNER JOIN blocks ON blocks.id = boxes.block_id WHERE boxes.id = buttons.box_id AND blocks.id = 10);"
time for n in `seq 1 ${loops}`; do echo "${query}" | mysql -u root ${db} > /dev/null; done
測定結果
下図は異なる N_BLOCKS の値ごとに上記スクリプトで測定した所要時間の結果です(青線)。ボタン総数(buttons テーブルのレコード数)が増えるに従って平均実行時間が増えていくことが分かります。グラフは指数関数的な増加を表していますが、横軸が対数軸なので実数に変更すると線形に増加していることを確認することができます(表の値をご覧下さい)。
| N_BLOCKS | ボタン総数 | クエリ平均実行時間 [s] |
|---|---|---|
| 10 | 40 | 0.01374 |
| 100 | 402 | 0.01404 |
| 1,000 | 3,933 | 0.01724 |
| 10,000 | 39,396 | 0.05202 |
| 25,000 | 98,555 | 0.11227 |
| 50,000 | 197,617 | 0.22609 |
| 75,000 | 296,218 | 0.34117 |
| 100,000 | 394,764 | 0.47793 |
この結果は相関サブクエリに関して解説してくださっている多くのブログ等の記事に記載されている、「クエリのコストは外部クエリのレコード数に比例する」ことと矛盾しません。まぁ当たり前ですね。
参考までに EXISTS を INNER JOIN に書き換えたものの所要時間も表示してあります(赤線)。こちらはボタン総数に関係なく一定であることがわかります。またボタン総数が数千レコード程度であれば EXISTS を使っても INNER JOIN を使っても、実行時間にそれほど差がないことがわかります。
まとめ
外部クエリで参照されるテーブルのレコード総数によって、相関サブクエリの所要時間が比例して増大していくことを確認しました。また相関サブクエリを内部結合に書き換えることによって、当該レコード総数に関係なく一定に保つことができることも確認できました。
今回の測定では、約40万レコードでたかだか0.5秒程度要するという結果になりました。弊社で起きた問題は外部クエリのレコード数が約27万件で同程度でしたが、実行に約10秒も要していたため大きな問題となりました。
さいごに
弊社の Rails アプリケーションではユニットテストで動作保証をしていますが、上記のようにレコード数が増大するに従ってパフォーマンスが劣化していくことを検知する仕組みが残念ながらありません。強いて言えばコードレビューで発見するしかないといったところでしょうか。FactoryBot で大規模データを生成して一定時間内に結果が返ってくるかのテストをすることも可能でしょうが、上記の例において N_BLOCKS = 100,000 の場合の seed データ投入で 2 時間程度要したので、そのようなテストは現実的とは思えません。何かいい方法があれば知りたいところであります。