Aurora の MySQL 8.0 互換で、EXPLAIN ANALYZE を触ってみた

EXPLAIN ANALYZE とは

MySQL 8.0.18 から、EXPLAIN ANALYZE が追加されています。SQL クエリーの頭に EXPLAIN ANALYZE を付けることで、その SQL クエリーの詳細なパフォーマンスの分析をしてくれる機能です。SQL クエリーで複雑な JOIN をしている時に、どこにどれくらい時間が掛かっていそうなのかを分析してくれます。SQL クエリーのボトルネックの特定などで便利に使える機能です。

現時点では、SELECT 句で使えます。INSERT, UPDATE, DELETE では使えません。詳細な情報を知りたい方は、こちらのリソースも確認してみてください。

• https://dev.mysql.com/doc/refman/8.0/ja/explain.html#explain-analyze
• https://www.slideshare.net/NorvaldRyeng/mysql-80-explain-analyze
• https://hackmysql.com/post/book-2/

従来あった EXPLAIN を使った実行結果の表示との違いは、実際に SELECT 句を実行することで、より現実に近いパフォーマンスデータを取得できます。また、SQL クエリーの内部で実行される JOIN などの各ステップで、実際にどれくらいの時間が掛かったかを表示してくれるのも大きな違いです。

実際に触ってみないとわからないので、検証をしていきます。今回の記事では、MySQL 8.0 互換の Aurora 3 系を利用しています。

SELECT 句

手元の Aurora に既にデータが入っており、以下のクエリーを EXPLAIN ANALYZE でかけていきます。このクエリーは、30秒くらいかかるクエリーとなっていて、分析のサンプルとして利用します。

SELECT 
    c_count, COUNT(*) AS custdist
FROM
    (SELECT 
        c_custkey, COUNT(o_orderkey) AS c_count
    FROM
        CUSTOMER
    LEFT OUTER JOIN ORDERS ON (c_custkey = o_custkey
        AND o_comment NOT LIKE '%special%requests%')
    GROUP BY c_custkey) AS c_orders
GROUP BY c_count
ORDER BY custdist DESC , c_count DESC;

まず、実行計画を確認するための EXPLAIN を見てみましょう。これは従来から使えるコマンドです。

EXPLAIN SELECT 
    c_count, COUNT(*) AS custdist
FROM
    (SELECT 
        c_custkey, COUNT(o_orderkey) AS c_count
    FROM
        CUSTOMER
    LEFT OUTER JOIN ORDERS ON (c_custkey = o_custkey
        AND o_comment NOT LIKE '%special%requests%')
    GROUP BY c_custkey) AS c_orders
GROUP BY c_count
ORDER BY custdist DESC , c_count DESC;

実行例です。実行計画を表示するだけなので、一瞬で表示されました。利用するテーブル CUSTOMER , ORDERS や、Index の利用有無がわかります。

+----+-------------+------------+------------+-------+---------------+---------+---------+------+---------------+----------+--------------------------------------------+
| id | select_type | table      | partitions | type  | possible_keys | key     | key_len | ref  | rows          | filtered | Extra                                      |
+----+-------------+------------+------------+-------+---------------+---------+---------+------+---------------+----------+--------------------------------------------+
|  1 | PRIMARY     | <derived2> | NULL       | ALL   | NULL          | NULL    | NULL    | NULL | 5417391452616 |   100.00 | Using temporary; Using filesort            |
|  2 | DERIVED     | CUSTOMER   | NULL       | index | PRIMARY       | PRIMARY | 4       | NULL |        743886 |   100.00 | Using index; Using temporary               |
|  2 | DERIVED     | ORDERS     | NULL       | ALL   | NULL          | NULL    | NULL    | NULL |       7282556 |   100.00 | Using where; Using join buffer (hash join) |
+----+-------------+------------+------------+-------+---------------+---------+---------+------+---------------+----------+--------------------------------------------+
3 rows in set, 1 warning (0.00 sec)

では本題の ``EXPLAIN ANALYZE です。

EXPLAIN ANALYZE SELECT 
    c_count, COUNT(*) AS custdist
FROM
    (SELECT 
        c_custkey, COUNT(o_orderkey) AS c_count
    FROM
        CUSTOMER
    LEFT OUTER JOIN ORDERS ON (c_custkey = o_custkey
        AND o_comment NOT LIKE '%special%requests%')
    GROUP BY c_custkey) AS c_orders
GROUP BY c_count
ORDER BY custdist DESC, c_count DESC\G

実行例です。実際に SELECT クエリーを実行しているので、表示されるまで 30 秒ほど掛かりました。

EXPLAIN: -> Sort: custdist DESC, c_orders.c_count DESC  (actual time=30387.278..30387.280 rows=42 loops=1)
    -> Table scan on <temporary>  (actual time=0.002..0.005 rows=42 loops=1)
        -> Aggregate using temporary table  (actual time=30387.246..30387.251 rows=42 loops=1)
            -> Table scan on c_orders  (cost=609456538421.80 rows=5417391452616) (actual time=0.002..53.410 rows=749999 loops=1)
                -> Materialize  (actual time=30022.196..30121.927 rows=749999 loops=1)
                    -> Table scan on <temporary>  (actual time=0.003..39.367 rows=749999 loops=1)
                        -> Aggregate using temporary table  (actual time=29852.270..29934.855 rows=749999 loops=1)
                            -> Left hash join (ORDERS.O_CUSTKEY = CUSTOMER.C_CUSTKEY)  (cost=541739665581.34 rows=5417391452616) (actual time=19736.698..26302.066 rows=7668749 loops=1)
                                -> Index scan on CUSTOMER using PRIMARY  (cost=76623.35 rows=743886) (actual time=3.108..2629.816 rows=749999 loops=1)
                                -> Hash
                                    -> Filter: (not((ORDERS.O_COMMENT like '%special%requests%')))  (cost=1.68 rows=7282556) (actual time=3.379..17834.993 rows=7418747 loops=1)
                                        -> Table scan on ORDERS  (cost=1.68 rows=7282556) (actual time=3.373..15533.983 rows=7499999 loops=1)

1 row in set (30.53 sec)

いろいろ Tree 形式で表示されています。一番上に書かれている actual time=30387.278..30387.280 rows=42 loops=1 の部分が、SQL クエリー全体で掛かった時間を表示してくれています。

• time=30387.278..30387.280 : 詳細は置いておきますが、30387.280 ミリ秒掛かったことがわかります。
• rows=42 : 42行
• loops=1 : ループ一回

2行目以降は、インデントがずれて、Tree の段が表示されています。これは、Scan, Join, Filter などの各種処理にどれくらいの時間が掛かっているのか、という表示内容です。一番わかりやすいところでいうと、一番下の行 Table scan on ORDERS (cost=1.68 rows=7282556) (actual time=3.373..15533.983 rows=7499999 loops=1) です。

rows=7282556 となっており、そもそもデータの取得量が多いことがわかります。また、テーブルにたいして SCAN をしているので、もしかしたら、Index の活用なども検討してもいいのかもしれません。

このように、EXPLAIN ANALYZE を利用すると、より詳細なデータを取得できるため、パフォーマンスの問題などで便利に活用できます。詳細な読み解き方は、こちらを参考にしてみてください。

INSERT, UPDATE, DELETE

INSERT, UPDATE, DELETE 句で使えないのですが、改めて確認してみましょう。

INSERT

EXPLAIN ANALYZE INSERT INTO sample(value)
VALUES (1), (2), (3), (4), (5), (6), (7), (8), (9), (10);

エラー

mysql> EXPLAIN ANALYZE INSERT INTO sample(value)
    -> VALUES (1), (2), (3), (4), (5), (6), (7), (8), (9), (10);
+----------------------------------------+
| EXPLAIN                                |
+----------------------------------------+
| <not executable by iterator executor>
 |
+----------------------------------------+
1 row in set (0.00 sec)

UPDATE

EXPLAIN ANALYZE UPDATE sample
SET value=11 WHERE id=1;

エラー

mysql> EXPLAIN ANALYZE UPDATE sample
    -> SET value=11 WHERE id=1;
+----------------------------------------+
| EXPLAIN                                |
+----------------------------------------+
| <not executable by iterator executor>
 |
+----------------------------------------+
1 row in set (0.00 sec)

DELETE

EXPLAIN ANALYZE DELETE FROM sample
WHERE id=1;

エラー

mysql> EXPLAIN ANALYZE DELETE FROM sample
    -> WHERE id=1;
+----------------------------------------+
| EXPLAIN                                |
+----------------------------------------+
| <not executable by iterator executor>
 |
+----------------------------------------+
1 row in set (0.00 sec)

検証をつうじてわかったこと

• EXPLAIN は実行計画を表示するため、すぐに表示される
• EXPLAIN ANALYZE は、実際にクエリーを実行するので、より詳細な分析が可能。表現を変えると、MySQL データベース側に実際に負荷を掛けるので、あまりにも大きいデータを対象にするのは望ましくない場面がありえる。
• Aurora 3系は、MySQL 8.0 互換なので、EXPLAIN ANALYZE が利用できる
• SELECT 句は利用できるが、INSERT, UPDATE, DELETE は利用できない

参考 URL