とても重いクエリがなぜ重いかを調べてみた(explain/optimizer_trace)
はじめましてこんにちは、2018年入社のエンジニアの羽中田といいます。
現在は技術推進室という部署で、データ分析を行なっています。
GMOメディアのDBといえば何と言ってもMySQL、ということでMySQLで１記事！
障害検知やパフォーマンス向上のために、ある一定の閾値以上の時間がかかったクエリに関しては、Slackに通知しています。
集計作業などで使うクエリはどうしても時間がかかりがち(slackを鳴らしがち)にはなるんですが、
そんな中、30分以上slackを鳴らし続けた重ーいクエリがあったので、なぜそんなに重いのか調査してみました。
MySQLのバージョンは 5.6 で検証しています。
調査
問題のクエリ
SELECT
`target_date`,
`point`,
count(point) as cnt
FROM
`history_point`
WHERE
`media_id` = '60'
AND `status` = 1
AND `target_date` >= '2019-01-01'
AND `target_date` <= '2019-01-31'
GROUP BY
`target_date`,
`point`
ORDER BY
`target_date`;
クエリを見る感じ、集計作業で使っているクエリに見えますね。
では次はテーブル定義をみてみましょう。
テーブル定義
CREATE TABLE `history_point` (
`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
`media_id` int(10) unsigned NOT NULL DEFAULT '0',
`user_id` bigint(20) unsigned NOT NULL,
`status` tinyint(3) unsigned NOT NULL DEFAULT '0',
`detail_id` int(10) unsigned NOT NULL DEFAULT '0',
`point` int(10) unsigned NOT NULL DEFAULT '0',
`balance` int(10) unsigned NOT NULL DEFAULT '0',
`target_month` date DEFAULT NULL,
`target_date` date DEFAULT NULL,
`created_at` datetime NOT NULL,
`updated_at` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
PRIMARY KEY (`id`),
KEY `idx_userid_mediaid_targetdate` (`user_id`,`media_id`,`target_date`),
KEY `idx_userid_mediaid_targetmonth` (`user_id`,`media_id`,`target_month`),
KEY `idx_targetdate_status_detailid` (`target_date`,`status`,`detail_id`)
) ENGINE=InnoDB AUTO_INCREMENT=400000000 DEFAULT CHARSET=utf8
うーん、ちゃんとインデックスも貼ってありますね。
では次は実行計画(explain)をとってみましょう。
実行計画
mysql [gmomedia]> explain SELECT `target_date`, `point`, count(point) as cnt FROM `history_point` WHERE `media_id` = '60' AND `status` = 1 AND `target_date` >= '2019-01-01' AND `target_date` <= '2019-01-31' GROUP BY `target_date`, `point` ORDER BY `target_date`;
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
| 1 | SIMPLE | history_point | NULL | ALL | idx_targetdate_status_detailid | NULL | NULL | NULL | 189079914 | 0.21 | Using where; Using temporary; Using filesort |
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
1 row in set, 1 warning (0.05 sec)
Note (Code 1003): /* select#1 */ select `gmomedia`.`history_point`.`target_date` AS `target_date`,`gmomedia`.`history_point`.`point` AS `point`,count(`gmomedia`.`history_point`.`point`) AS `cnt` from `gmomedia`.`history_point` where ((`gmomedia`.`history_point`.`status` = 1) and (`gmomedia`.`history_point`.`media_id` = '60') and (`gmomedia`.`history_point`.`target_date` >= '2019-01-01') and (`gmomedia`.`history_point`.`target_date` <= '2019-01-31')) group by `gmomedia`.`history_point`.`target_date`,`gmomedia`.`history_point`.`point` order by `gmomedia`.`history_point`.`target_date`
＿人人人人人人＿
＞ +——+ ＜
＞ | type | ＜
＞ +——+ ＜
＞ | ALL | ＜
＞ +——+ ＜
￣Y^Y^Y^Y^Y^￣
結論
もうお分かりの方も多いと思いますが、
フルスキャンされている。以上。解散。
・
・
・
・
・
・
・
・
・
・
はい、なぜ重いかはわかりましたが、、、、
それではあまりにも面白くないので、indexを使わせてみましょう。
using indexつけてみる
mysql [gmomedia]> explain SELECT `target_date`, `point`, count(point) as cnt FROM `history_point` use index (idx_targetdate_status_detailid) WHERE `media_id` = '60' AND `status` = 1 AND `target_date` >= '2019-01-01' AND `target_date` <= '2019-01-31' GROUP BY `target_date`, `point` ORDER BY `target_date`;
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
| 1 | SIMPLE | history_point | NULL | ALL | idx_targetdate_status_detailid | NULL | NULL | NULL | 189112967 | 0.21 | Using where; Using temporary; Using filesort |
+----+-------------+----------------------+------------+------+--------------------------------+------+---------+------+-----------+----------+----------------------------------------------+
1 row in set, 1 warning (0.00 sec)
Note (Code 1003): /* select#1 */ select `gmomedia`.`history_point`.`target_date` AS `target_date`,`gmomedia`.`history_point`.`point` AS `point`,count(`gmomedia`.`history_point`.`point`) AS `cnt` from `gmomedia`.`history_point` USE INDEX (`idx_targetdate_status_detailid`) where ((`gmomedia`.`history_point`.`status` = 1) and (`gmomedia`.`history_point`.`media_id` = '60') and (`gmomedia`.`history_point`.`target_date` >= '2019-01-01') and (`gmomedia`.`history_point`.`target_date` <= '2019-01-31')) group by `gmomedia`.`history_point`.`target_date`,`gmomedia`.`history_point`.`point` order by `gmomedia`.`history_point`.`target_date`
クエリの変更点は、using indexを入れた点です。
しかしよく見ると、その実行計画はやっぱりフルスキャンをしている。
なぜ??
ではもう強制的にINDEXを使わせましょう。
force index してみる
mysql [gmomedia]> explain SELECT `target_date`, `point`, count(point) as cnt FROM `history_point` force index (idx_targetdate_status_detailid) WHERE `media_id` = '60' AND `status` = 1 AND `target_date` >= '2019-01-01' AND `target_date` <= '2019-01-31' GROUP BY `target_date`, `point` ORDER BY `target_date`;
+----+-------------+----------------------+------------+-------+--------------------------------+--------------------------------+---------+------+----------+----------+---------------------------------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+----------------------+------------+-------+--------------------------------+--------------------------------+---------+------+----------+----------+---------------------------------------------------------------------+
| 1 | SIMPLE | history_point | NULL | range | idx_targetdate_status_detailid | idx_targetdate_status_detailid | 5 | NULL | 39904370 | 1.00 | Using index condition; Using where; Using temporary; Using filesort |
+----+-------------+----------------------+------------+-------+--------------------------------+--------------------------------+---------+------+----------+----------+---------------------------------------------------------------------+
1 row in set, 1 warning (0.00 sec)
Note (Code 1003): /* select#1 */ select `gmomedia`.`history_point`.`target_date` AS `target_date`,`gmomedia`.`history_point`.`point` AS `point`,count(`gmomedia`.`history_point`.`point`) AS `cnt` from `gmomedia`.`history_point` FORCE INDEX (`idx_targetdate_status_detailid`) where ((`gmomedia`.`history_point`.`status` = 1) and (`gmomedia`.`history_point`.`media_id` = '60') and (`gmomedia`.`history_point`.`target_date` >= '2019-01-01') and (`gmomedia`.`history_point`.`target_date` <= '2019-01-31')) group by `gmomedia`.`history_point`.`target_date`,`gmomedia`.`history_point`.`point` order by `gmomedia`.`history_point`.`target_date`
ｷﾀｰー♪───Ｏ（≧∇≦）Ｏ────♪
keyを見てもフルスキャンじゃないし、typeを見てもindexが使われています！！！
これは早くなってる！
しかし、オプティマイザさんはなぜ、最初indexを使ってくれなかったのでしょう。
using indexを使用したにも関わらず、indexが使われず、
force indexまで指定しなければいけなかったんでしょうか。
yoku0825さん 「MySQLの気持ちになるんだ。。！」
ちょっと、まだそんなにMySQLと仲良くない自分には無理です。
私と同じく、そんなMySQLとまだ仲良くない人のために、
「MySQLの気持ちが理解できる(かもしれない)仕組み」
オプティマイザトレース
がmysql5.6から実装されました。
これは、MySQLのオプティマイザが計算しているコスト、インデックス使用の有無の判断やその理由などを、
Explainよりも詳細に出力する仕組みです。
とても重いクエリでオプティマイザトレースして、indexが使われない原因を頑張って理解しようとしてみた
方法的には、
– Force Indexを使った場合
– Use INdexを使った場合
– なにも使わなかった場合
この3パターンでoptimizer_traceを取得し、それぞれの違いを見れば(diffを取れば)わかるのではないかと思い、行って見ました。
なぜ出力を直接見比べずdiffを取るかというと、
(一度実行してみるとわかりますが)json形式で全て出力されるので、とてつもなく長いためです。
オプティマイザトレース有効化
mysql> set optimizer_trace='enabled=on';
Query OK, 0 rows affected (0.00 sec)
mysql> show variables like 'optimizer_trace';
+-----------------+-------------------------+
| Variable_name | Value |
+-----------------+-------------------------+
| optimizer_trace | enabled=on,one_line=off |
+-----------------+-------------------------+
1 row in set (0.00 sec)
セッションだけ有効化
diff 何も使わない場合 / Use_indexの場合
47c47
< "table": "`history_point`",
---
> "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)",
62c62
< "table": "`history_point`",
---
> "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)",
65c65
< "rows": 189207065,
---
> "rows": 189191254,
132c132
< "table": "`history_point`",
---
> "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)",
136c136
< "rows_to_scan": 189207065,
---
> "rows_to_scan": 189191254,
161c161
< "table": "`history_point`",
---
> "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)",
199c199
< "table": "`history_point`"
---
> "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)"
違い
テーブルの違いに関しては、見ればわかるので割愛するとして、
もう一つ、rows と rows_to_scan が異なっています。
しかしそもそも、optimizerが算出する行数やコストというものは、実際に実行して調べているわけではなく、あくまで統計によって求められているらしく、多少の差異は出るらしいです。
つまり、use indexと、何も指定しない場合では、少なくともoptimizer_trace上での実行計画には差がないことがわかります。
diff Use_indexの場合 / Force_indexの場合
114,115c114
< "chosen": false,
< "cause": "cost"
---
> "chosen": true
121a121,133
> },
> "chosen_range_access_summary": {
> "range_access_plan": {
> "type": "range_scan",
> "index": "idx_targetdate_status_detailid",
> "rows": 39904370,
> "ranges": [
> "0x21c60f <= target_date <= 0x3fc60f"
> ]
> },
> "rows_for_plan": 39904370,
> "cost_for_plan": 4.79e7,
> "chosen": true
132c144
< "table": "`history_point` USE INDEX (`idx_targetdate_status_detailid`)",
---
> "table": "`history_point` FORCE INDEX (`idx_targetdate_status_detailid`)",
136,137c148,152
< "rows_to_scan": 189191254,
< "access_type": "scan",
---
> "rows_to_scan": 39904370,
> "access_type": "range",
> "range_details": {
> "used_index": "idx_targetdate_status_detailid"
> },
139c154
< "cost": 3.88e7,
---
> "cost": 5.59e7,
147c162
< "cost_for_plan": 3.88e7,
---
> "cost_for_plan": 5.59e7,
149c164
< "new_cost_for_plan": 3.92e7,
---
> "new_cost_for_plan": 5.63e7,
違い.1
< "chosen": false,
< "cause": "cost"
---
> "chosen": true
上記の差は、indexを使った際のコスト計算を行い、使用の可否を検討している部分です。
"range_scan_alternatives": [
{
"index": "idx_targetdate_status_detailid",
"ranges": [
"0x21c60f <= target_date <= 0x3fc60f"
],
"index_dives_for_eq_ranges": true,
"rowid_ordered": false,
"using_mrr": false,
"index_only": false,
"rows": 39904370,
"cost": 4.79e7,
"chosen": false,
"cause": "cost"
}
],
use.indexのtraceを一部ですが、最後の２行に注目すると、選択されるかを意味するchosenがfalseになっており、その理由が costであると書かれています。
対して、force.indexの方は、chosenがtrueになるという違いが出ているため、indexが使われることが予想できます。
yokuさん曰く、
force indexを指定した場合、テーブルスキャンのコストが無限大と仮定されるため、必ずindexを使った方がコストが低くなる
= indexが使われる仕組みだとのこと
違い.2
< "rows_to_scan": 189191254,
< "access_type": "scan",
---
> "rows_to_scan": 39904370,
> "access_type": "range",
> "range_details": {
> "used_index": "idx_targetdate_status_detailid"
これは、最終的なアクセスタイプがどうなっているか示すもので、
use indexでは scan(全体をなめる)
force indexでは range(indexを使う)
とあり、force indexではindexが使われるということがわかる。
結論
optimizer_traceは、結局explainをより細かく書いたもので、
フルスキャンや、indexを使うことによって、optimizerがどれくらいのコストを見積もっているかというのはわかるが、コストの算出がブラックボックスなので、optimizerがなぜindexを使った際のコストを、
フルスキャンした際のコストより大きく見積もってしまったかというのは、わからないことがわかりました
どうやらoptimizer_traceというものは、 MySQL :: MySQL 5.7 Reference Manual :: 8.9.5 The Optimizer Cost Modelこの辺りを変更しつつ、オプティマイザーコストを計算するものだそうです。
結論2
mysql5.7からoptimizerがめちゃくちゃリファクタされたらしく、性能が大きく向上しています。
その結果、indexがあるのに使わない。
joinの順番がおかしい、
などなどのoptimizerに関する痒いところが結構解決されているらしいです。
つまり・・・・
Escape From MySQL5.6 or earlier ！！