【MySQL】EXPLAIN ANALYZEで実測値を確認する

MySQLでクエリの実行計画とあわせて実際の実行時間を確認するにはEXPLAIN ANALYZEを使う。MySQL 8.0.18以降で利用できる。

type・key・rows・ExtraなどEXPLAIN単体の出力については以下の記事を参照。

以降の例では、主キーidとbalanceカラムを持つaccountsテーブル（3万行）と、account_idにインデックスを持つordersテーブル（1,000行）を使う。

CREATE TABLE accounts (id INT PRIMARY KEY AUTO_INCREMENT, balance INT NOT NULL);

CREATE TABLE orders (
  id INT PRIMARY KEY AUTO_INCREMENT,
  account_id INT NOT NULL,
  amount INT NOT NULL,
  KEY idx_account_id (account_id)
);

EXPLAIN ANALYZEとは

EXPLAINは実行計画の見積もりだけを表示するのに対し、EXPLAIN ANALYZEは実際にクエリを実行し、見積もりと実測値をあわせて表示する。

mysql> EXPLAIN ANALYZE SELECT * FROM accounts WHERE balance = 84946;

-> Filter: (accounts.balance = 84946)  (cost=3061 rows=3037) (actual time=1.83..4.06 rows=1 loops=1)
    -> Table scan on accounts  (cost=3061 rows=30369) (actual time=0.175..3.03 rows=30000 loops=1)

出力形式はEXPLAIN単体とは全く異なり、id・select_type・typeといった列を持つ表ではなく、->から始まる行がインデントで入れ子になったツリー形式である。

ツリー構造の読み方

各行は1つの処理ステップ（イテレータ）を表す。インデントが深い行ほど内側の処理であり、内側から外側へデータが流れる。

上記の例では、内側のTable scan on accountsが先に実行され、accountsテーブル全体（3万行）を読み込む。その結果を外側のFilterが受け取り、balance = 84946に一致する行だけに絞り込んでいる。テーブル全体を読んでからフィルタしているため、balance列にインデックスがないと分かる。

costと実測値

各行の末尾には見積もりと実測値が並ぶ。

(cost=3061 rows=3037) (actual time=1.83..4.06 rows=1 loops=1)

cost: そのステップまでのオプティマイザによる見積もりコスト。単位は時間ではなく、オプティマイザ内部の相対値
rows（見積もり側）: そのステップが返すと見積もられた行数
actual timeの1つ目の数値: 最初の1行を返すまでにかかった実際の時間（ミリ秒）
actual timeの2つ目の数値: そのステップの処理が完了するまでにかかった実際の時間（ミリ秒）
rows（実測側）: 実際に処理した行数（loopsが2以上の場合は1回あたりの平均）
loops: そのステップが実行された回数

見積もりのrows=3037に対し、実測のrows=1は大きく乖離している。統計情報から見積もった行数と実際の行数は、balance列の値の分布に偏りがあるなどの理由でずれることがある。乖離が大きい場合はANALYZE TABLEで統計情報を更新する。

ANALYZE TABLE accounts;

インデックスを使うと変わる例

主キーidの範囲検索は、Table scanではなくIndex range scanになる。

mysql> EXPLAIN ANALYZE SELECT * FROM accounts WHERE id BETWEEN 12340 AND 12350;

-> Filter: (accounts.id between 12340 and 12350)  (cost=2.46 rows=11) (actual time=0.0225..0.0247 rows=11 loops=1)
    -> Index range scan on accounts using PRIMARY over (12340 <= id <= 12350)  (cost=2.46 rows=11) (actual time=0.0208..0.0224 rows=11 loops=1)

Table scanのcost=3061に対し、こちらはcost=2.46と大幅に小さい。実測のactual timeも、全件を読むTable scanが最大4ミリ秒程度だったのに対し、こちらは0.02ミリ秒程度で完了している。over (12340 <= id <= 12350)には、範囲検索に使われた条件がそのまま表示される。

カバリングインデックスの例

balance列にインデックスを追加すると、FilterとTable scanの2段階だったツリーが1段階にまとまる。

mysql> ALTER TABLE accounts ADD INDEX idx_balance (balance);
mysql> EXPLAIN ANALYZE SELECT * FROM accounts WHERE balance = 84946;

-> Covering index lookup on accounts using idx_balance (balance=84946)  (cost=1.07 rows=1) (actual time=0.00454..0.00554 rows=1 loops=1)

Covering index lookupは、テーブル本体を読まずインデックスだけでクエリが完結していることを示す。accountsテーブルはidとbalanceしか持たないため、idx_balanceが暗黙に含む主キーidとあわせればSELECT *に必要な列がすべて揃う。InnoDBのセカンダリインデックスは常に主キーの値を含むため、テーブルの列数が少ないほどカバリングインデックスになりやすい。

loopsが複数になる例

JOINでは、内側のテーブルへのアクセスが外側の行数分だけ繰り返されるため、loopsが2以上になる。

mysql> EXPLAIN ANALYZE
    -> SELECT a.id, a.balance, o.amount
    -> FROM accounts a
    -> JOIN orders o ON o.account_id = a.id
    -> WHERE a.id BETWEEN 1 AND 5;

-> Nested loop inner join  (cost=3.01 rows=5) (actual time=0.026..0.0345 rows=5 loops=1)
    -> Filter: (a.id between 1 and 5)  (cost=1.26 rows=5) (actual time=0.013..0.0141 rows=5 loops=1)
        -> Index range scan on a using PRIMARY over (1 <= id <= 5)  (cost=1.26 rows=5) (actual time=0.0118..0.0127 rows=5 loops=1)
    -> Index lookup on o using idx_account_id (account_id=a.id)  (cost=0.27 rows=1) (actual time=0.00327..0.00357 rows=1 loops=5)

最も内側のIndex range scan on aがaccountsからidが1〜5の5行を1回で取得し（loops=1）、Nested loop inner joinがその5行のそれぞれについてorders側のIndex lookupを実行するため、loops=5になっている。loops=5の行のrows=1は1回あたりの平均であり、ordersから実際に読んだ行数の合計はrows × loopsで5行である。

実行に伴う注意点

EXPLAINと異なり、EXPLAIN ANALYZEは実際にクエリを実行する。SELECT文はもちろん、複数テーブルのUPDATE・DELETEやINSERT ... SELECTなど、内部にクエリを持つ文にも使える。

複数テーブルのUPDATEで実際に試すと、実行計画と実測値は表示されるものの、データそのものは変更されない。「loopsが複数になる例」と同じaccountsとordersの結合を使って確認する。

mysql> EXPLAIN ANALYZE
    -> UPDATE accounts a
    -> JOIN orders o ON o.account_id = a.id
    -> SET a.balance = a.balance + o.amount
    -> WHERE a.id BETWEEN 1 AND 5;

-> Update a (immediate)  (actual time=0.042..0.042 rows=0 loops=1)
    -> Nested loop inner join  (cost=3.01 rows=5) (actual time=0.0267..0.0397 rows=5 loops=1)
        -> Filter: (a.id between 1 and 5)  (cost=1.26 rows=5) (actual time=0.0174..0.0203 rows=5 loops=1)
            -> Index range scan on a using PRIMARY over (1 <= id <= 5)  (cost=1.26 rows=5) (actual time=0.0163..0.0189 rows=5 loops=1)
        -> Index lookup on o using idx_account_id (account_id=a.id)  (cost=0.27 rows=1) (actual time=0.00259..0.00342 rows=1 loops=5)

実行後にaccountsを確認してもbalanceは更新されていない。EXPLAIN ANALYZEは実行計画の測定のために文を最後まで実行するが、変更はコミットされない。

ただし、コミットされないだけで内部的な走査や書き込み処理そのものは実際に行われるため、負荷の高い文を本番環境でむやみに実行すると相応のリソースを消費する。テスト環境で試すのが無難である。