🏄

Railsにおける .explain でパフォーマンスを考える

に公開

はじめに

explainメソッド を使うことで、SQLの実行計画だけでなく、実際の実行時間までをもとに調査できます。ここでは、それの使い方について実際の例も踏まえながら解説していきます

※ 本記事は MySQL(8.0) を対象としています。他のRDBMS(PostgreSQLなど)とは出力項目や挙動が異なる場合があります。

そもそも EXPLAIN って何

EXPLAIN は、SQLクエリがデータベース内部でどのように実行されるのかを教えてくれる「実行計画表示コマンド」です。

EXPLAIN SELECT name FROM users WHERE id = 10005

項目名 説明
id クエリ内の操作の識別子(サブクエリなどがあると増える)
select_type クエリの種類(例: SIMPLE、PRIMARY、SUBQUERYなど)
table 対象となるテーブル名
partitions 一致するパーティション
type アクセス方法の種類( ALL,index,range,const )
possible_keys 使用可能なインデックス
key 実際に使用されたインデックス
key_len 使用されたインデックスの長さ(バイト単位)
ref どのカラムや定数がインデックス検索に使われたか
rows 推定される読み込み行数
filtered 条件を満たすと見積もられた行の割合(%)
Extra その他の補足情報(Using index, Using filesort など)

例として、typeALLExtraUsing Filesortなどの場合、クエリに改善の余地がある可能性が高いです。このように EXPLAIN ではそのクエリのボトルネックを探すことに優れています。

EXPLAIN ANALYZE では、実際にクエリが実行された上で実行時間、行数などを確認できます

EXPLAIN ANALYZE SELECT name FROM users WHERE id = 10005
-> Rows fetched before execution  (cost=0..0 rows=1) (actual time=125e-6..208e-6 rows=1 loops=1)

Railsでは .explain.explain(:analyze) を使って、ActiveRecordのクエリに対してこれを確認できます。

プロジェクト構成

# db/schema.rb
create_table "users" do |t|
  t.string "name"
  t.integer "age"
  t.string "email"
  t.timestamps
end

create_table "posts" do |t|
  t.references :user, null: false, foreign_key: true
  t.string "title"
  t.text "content"
  t.integer "likes_count",
  t.timestamps
end
  • ユーザーは 10,000人
  • 各ユーザーは 0〜100 件の投稿
  • likes_count は 0〜10,000 の値

実験1: 人気な投稿50件を取得(user情報付き)

Post.preload(:user).order(likes_count: :desc).limit(50).explain

実行結果

Post.preload(:user).order(likes_count: :desc).limit(50).explain
  Post Load (165.2ms)  SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
  User Load (0.5ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` IN (19922, 19815, 19421, 19369, 19262, 19316, 16992, 16875, 16002, 15883, 16834, 16720, 16584, 16446, 11689, 11535, 10930, 10233, 11451, 11413, 11349, 11205, 11118, 11042, 15203, 15206, 14357, 13688, 13707, 13896, 13843, 14970, 14733, 18462, 18433, 17771, 17775, 17668, 18329, 18255, 17311, 17236, 13156, 13169, 12728, 11822, 12461, 12426, 12335)
=> 
EXPLAIN SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------+
| id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows   | filtered | Extra          |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------+
|  1 | SIMPLE      | posts | NULL       | ALL  | NULL          | NULL | NULL    | NULL | 490947 |    100.0 | Using filesort |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+----------------+
1 row in set (0.00 sec)

EXPLAIN SELECT `users`.* FROM `users` WHERE `users`.`id` IN (19922, 19815, 19421, 19369, 19262, 19316, 16992, 16875, 16002, 15883, 16834, 16720, 16584, 16446, 11689, 11535, 10930, 10233, 11451, 11413, 11349, 11205, 11118, 11042, 15203, 15206, 14357, 13688, 13707, 13896, 13843, 14970, 14733, 18462, 18433, 17771, 17775, 17668, 18329, 18255, 17311, 17236, 13156, 13169, 12728, 11822, 12461, 12426, 12335)
+----+-------------+-------+------------+-------+---------------+---------+---------+------+------+----------+-------------+
| id | select_type | table | partitions | type  | possible_keys | key     | key_len | ref  | rows | filtered | Extra       |
+----+-------------+-------+------------+-------+---------------+---------+---------+------+------+----------+-------------+
|  1 | SIMPLE      | users | NULL       | range | PRIMARY       | PRIMARY | 8       | NULL |   49 |    100.0 | Using where |
+----+-------------+-------+------------+-------+---------------+---------+---------+------+------+----------+-------------+
1 row in set (0.00 sec)

実行計画を確認(postsテーブル)

  • type: ALL(= 全件読み込み)
  • rows=490947、全行を見ているのが分かる
  • Extra:Using filesort とあり、以下のように推測できる
    • ORDER BY likes_count DESC に対して
      • 全件(type: ALL)を読み取り
      • 結果を一時的に格納
      • 手動でソートして上位50件を取り出している

.explain(:analyze) を実行

EXPLAIN ANALYZE SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN                                                                                                                                                                                                                                                                                                                          |
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Limit: 50 row(s)  (cost=50224 rows=50) (actual time=139..139 rows=50 loops=1)
    -> Sort: posts.likes_count DESC, limit input to 50 row(s) per chunk  (cost=50224 rows=490947) (actual time=139..139 rows=50 loops=1)
        -> Table scan on posts  (cost=50224 rows=490947) (actual time=0.0308..99 rows=496238 loops=1)
 |
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.14 sec)
...
指標 内容
処理時間 139ms
読み込み件数 49万件

考察:ボトルネックを見出す

ORDER BY に使っているカラム(likes_count)にインデックスが貼られていないため、MySQLは全件をスキャンしてから手動でソート(filesort)しています。これは典型的な「インデックス貼付けで改善できる」パターンであり、type: ALL や Extra: Using filesort はその明確なサインであると考えられます。

では、likes_countにインデックスを貼り、再度検証してみましょう

実験2: インデックスありで再度 .explain

Post.preload(:user).order(likes_count: :desc).limit(50).explain

実行結果

Post.preload(:user).order(likes_count: :desc).limit(50).explain
  Post Load (5.0ms)  SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
  User Load (0.4ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` IN (19922, 19815, 19421, 19369, 19316, 19262, 18462, 18433, 18329, 18255, 17775, 17771, 17668, 17311, 17236, 16992, 16875, 16834, 16720, 16584, 16446, 16002, 15883, 15206, 15203, 14970, 14733, 14357, 13896, 13843, 13707, 13688, 13169, 13156, 12972, 12824, 12728, 12461, 12426, 12335, 12202, 12176, 11822, 11689, 11535, 11451, 11413, 11349, 11205)
=> 
EXPLAIN SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
+----+-------------+-------+------------+-------+---------------+----------------------------+---------+------+------+----------+---------------------+
| id | select_type | table | partitions | type  | possible_keys | key                        | key_len | ref  | rows | filtered | Extra               |
+----+-------------+-------+------------+-------+---------------+----------------------------+---------+------+------+----------+---------------------+
|  1 | SIMPLE      | posts | NULL       | index | NULL          | index_posts_on_likes_count | 5       | NULL |   50 |    100.0 | Backward index scan |
+----+-------------+-------+------------+-------+---------------+----------------------------+---------+------+------+----------+---------------------+
1 row in set (0.00 sec)
...

実行計画を確認

項目 出力 意味
type index インデックスを使ったアクセス
key index_posts_on_likes_count likes_count に貼ったインデックスが使用されている
rows 50 インデックスで並んだ先頭50件だけ読んでいる
Extra Backward index scan 降順 (DESC) でインデックスを逆順スキャン

.explain(:analyze)を実行

Post.preload(:user).order(likes_count: :desc).limit(50).explain(:analyze)
  Post Load (0.9ms)  SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
  User Load (1.0ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` IN (19922, 19815, 19421, 19369, 19316, 19262, 18462, 18433, 18329, 18255, 17775, 17771, 17668, 17311, 17236, 16992, 16875, 16834, 16720, 16584, 16446, 16002, 15883, 15206, 15203, 14970, 14733, 14357, 13896, 13843, 13707, 13688, 13169, 13156, 12972, 12824, 12728, 12461, 12426, 12335, 12202, 12176, 11822, 11689, 11535, 11451, 11413, 11349, 11205)
=> 
EXPLAIN ANALYZE SELECT `posts`.* FROM `posts` ORDER BY `posts`.`likes_count` DESC LIMIT 50
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| EXPLAIN                                                                                                                                                                                                                        |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| -> Limit: 50 row(s)  (cost=0.116 rows=50) (actual time=0.0237..0.183 rows=50 loops=1)
    -> Index scan on posts using index_posts_on_likes_count (reverse)  (cost=0.116 rows=50) (actual time=0.0221..0.177 rows=50 loops=1)
 |
+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
...
指標 内容
処理時間 0.18ms(※約 770 倍高速)
読み込み件数 50件

インデックス適用の効果

likes_count にインデックスが無い場合、MySQLは posts テーブルを全件読み込み(約50万件)してから、filesortで並び替えて上位50件を抽出していました

一方、インデックスを貼ると ORDER BY likes_count DESC LIMIT 50 は「インデックスを逆順にスキャンして上から50件だけ取る」だけになります。

  • 実行時間:139ms → 0.18ms
  • 処理件数:49万件 → 50件
  • Extra: filesort → index scan

まとめ

このように .explain を使うことで、クエリがどのように実行されるかを可視化でき、ボトルネックを探す大きな手助けとなります。実際の実行計画をRailsから確認して、パフォーマンスチューニングのステップを覚えていきましょう

参考

https://railsguides.jp/active_record_querying.html#explainを実行する
https://dev.mysql.com/doc/refman/8.0/ja/explain-output.html

ラブグラフのエンジニアブログ

Discussion