GreatSQL社區原創內容未經授權不得隨意使用,轉載請聯繫小編並註明來源。 GreatSQL是MySQL的國產分支版本,使用上與MySQL一致。 前言 今天遇到一個很神奇的現象,在資料庫中,相同的執行計劃,執行SQL所需要的時間相差很大,執行快的SQL瞬間出結果,執行慢的SQL要幾十秒才出結果,一 ...
- GreatSQL社區原創內容未經授權不得隨意使用,轉載請聯繫小編並註明來源。
- GreatSQL是MySQL的國產分支版本,使用上與MySQL一致。
前言
今天遇到一個很神奇的現象,在資料庫中,相同的執行計劃,執行SQL所需要的時間相差很大,執行快的SQL瞬間出結果,執行慢的SQL要幾十秒才出結果,一度讓我懷疑是資料庫抽風了,後面才發現是見識不足,又進入了知識空白區。
場景復現
資料庫版本使用的是8.0.23 MySQL Community Server - GPL
由於生產環境數據敏感,禁止隨意折騰,我在自己的測試環境,通過如下步驟,構造了一批數據,勉強能夠復現出相同的場景來
- 使用sysbench構造一萬張表,每張表10行記錄即可。
- create table test.test_col as select * from information_schema.columns;
- create table test.test_tab as select * from information_schema.tables;
- create table test.test_tc as select * from information_schema.table_constraints;
- 執行10次 insert into test.test_tab select * from test.test_tab;
- 創建必要的索引
alter table test_col add key(table_schema, table_name);
alter table test_col add key(column_name);
alter table test_tab add key(table_schema, table_name);
alter table test_tc add key(table_name);
最終我測試表的數據如下
mysql> select count(1) from test_col;
+----------+
| count(1) |
+----------+
| 1395616|
+----------+
1 row in set (3.29 sec)
mysql> select count(1) from test_tab;
+----------+
| count(1) |
+----------+
| 10338 |
+----------+
1 row in set (0.12 sec)
mysql> select count(1) from test_tc;
+----------+
| count(1) |
+----------+
| 10143 |
+----------+
1 row in set (0.06 sec)
先看執行快的SQL和它的執行計劃
mysql> select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME limit 3 ) t;
+----------+
| count(1) |
+----------+
| 3 |
+----------+
1 row in set (0.00 sec)
mysql> explain select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME limit 3 ) t;
+----+-------------+------------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+------------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
| 1 | PRIMARY | <derived2> | NULL | ALL | NULL | NULL | NULL | NULL | 3 | 100.00 | NULL |
| 2 | DERIVED | t2 | NULL | index | TABLE_SCHEMA | TABLE_SCHEMA | 390 | NULL | 10240 | 100.00 | Using where; Using index |
| 2 | DERIVED | t3 | NULL | ref | TABLE_NAME | TABLE_NAME | 195 | test.t2.TABLE_NAME | 1 | 10.00 | Using where |
| 2 | DERIVED | t1 | NULL | ref | TABLE_SCHEMA | TABLE_SCHEMA | 390 | test.t2.TABLE_SCHEMA,test.t2.TABLE_NAME | 61 | 100.00 | NULL |
+----+-------------+------------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
4 rows in set, 1 warning (0.00 sec)
再看執行慢的SQL和它的執行計劃
mysql> select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME ) t;
+----------+
| count(1) |
+----------+
| 1333088|
+----------+
1 row in set (2.45 sec)
mysql> explain select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME ) t;
+----+-------------+-------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
| 1 | SIMPLE | t2 | NULL | index | TABLE_SCHEMA | TABLE_SCHEMA | 390 | NULL | 10240 | 100.00 | Using where; Using index |
| 1 | SIMPLE | t3 | NULL | ref | TABLE_NAME | TABLE_NAME | 195 | test.t2.TABLE_NAME | 1 | 10.00 | Using where |
| 1 | SIMPLE | t1 | NULL | ref | TABLE_SCHEMA | TABLE_SCHEMA | 390 | test.t2.TABLE_SCHEMA,test.t2.TABLE_NAME | 61 | 100.00 | Using index |
+----+-------------+-------+------------+-------+---------------+--------------+---------+-----------------------------------------+-------+----------+--------------------------+
3 rows in set, 1 warning (0.00 sec)
對比兩個SQL執行計劃,選擇索引相同,表關聯順序相同,快的執行0.00秒,慢的執行2.45秒,生產環境數據量更多,差異更大。兩條SQL差別是執行快的SQL子查詢中多了limit 3。
從上述執行計劃,我們可以看出,t2表為驅動表,先與t3做關聯,得到結果後再與t1做關聯,最後將結果集返回給客戶端。
我們都知道,MySQL從server層返回數據給client,是一行一行返回的。也就是上層結果集與t1表每關聯一行,有結果後,在沒有排序的情況下,就是直接返回,並不會等所有行關聯完後一起返回。
那麼整個關聯路徑,是怎麼樣的呢,簡化流程後應該是下麵兩種情況的一個
- 從t2取出所有數據,與t3表關聯得到所有結果集後;再從t1中取一行關聯,每得到一行結果,返回一次數據
- 從t2取一行數據,與t3表關聯得到一行結果後,再從t1中取一行關聯,每得到一行結果,返回一次數據
新的技巧
由於上面兩個SQL執行計劃、預估成本都相同,無法看出具體執行過程中差異點在什麼地方導致執行性能差這麼多.
在MySQL 8.0.18及之後,有一個新功能explain analyze,可以定量分析SQL執行過程中的耗時及實際數據訪問條數,拿到我們的場景具體使用一下
mysql> explain analyze select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME limit 3 ) t \G
*************************** 1. row ***************************
EXPLAIN: -> Aggregate: count(1) (actual time=0.348..0.349 rows=1 loops=1)
-> Table scan on t (cost=2.84 rows=3) (actual time=0.003..0.004 rows=3 loops=1)
-> Materialize (cost=75298.09 rows=3) (actual time=0.339..0.340 rows=3 loops=1)
-> Limit: 3 row(s) (cost=75298.09 rows=3) (actual time=0.179..0.205 rows=3 loops=1)
-> Nested loop inner join (cost=75298.09 rows=132366) (actual time=0.177..0.203 rows=3 loops=1)
-> Nested loop inner join (cost=4648.25 rows=1024) (actual time=0.130..0.130 rows=1 loops=1)
-> Filter: ((t2.`TABLE_NAME` is not null) and (t2.TABLE_SCHEMA is not null)) (cost=1064.25 rows=10240) (actual time=0.065..0.065 rows=1 loops=1)
-> Index scan on t2 using TABLE_SCHEMA (cost=1064.25 rows=10240) (actual time=0.053..0.053 rows=1 loops=1)
-> Filter: (t3.TABLE_SCHEMA = t2.TABLE_SCHEMA) (cost=0.25 rows=0) (actual time=0.062..0.062 rows=1 loops=1)
-> Index lookup on t3 using TABLE_NAME (TABLE_NAME=t2.`TABLE_NAME`) (cost=0.25 rows=1) (actual time=0.059..0.059 rows=1 loops=1)
-> Index lookup on t1 using TABLE_SCHEMA (TABLE_SCHEMA=t2.TABLE_SCHEMA, TABLE_NAME=t2.`TABLE_NAME`) (cost=56.08 rows=129) (actual time=0.044..0.070 rows=3 loops=1)
1 row in set (0.00 sec)
mysql> explain analyze select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME ) t \G
*************************** 1. row ***************************
EXPLAIN: -> Aggregate: count(1) (actual time=2130.310..2130.311 rows=1 loops=1)
-> Nested loop inner join (cost=19704.44 rows=132366) (actual time=0.114..2006.259 rows=1333088 loops=1)
-> Nested loop inner join (cost=4648.25 rows=1024) (actual time=0.094..108.093 rows=10143 loops=1)
-> Filter: ((t2.`TABLE_NAME` is not null) and (t2.TABLE_SCHEMA is not null)) (cost=1064.25 rows=10240) (actual time=0.051..17.021 rows=10338 loops=1)
-> Index scan on t2 using TABLE_SCHEMA (cost=1064.25 rows=10240) (actual time=0.049..12.845 rows=10338 loops=1)
-> Filter: (t3.TABLE_SCHEMA = t2.TABLE_SCHEMA) (cost=0.25 rows=0) (actual time=0.007..0.008 rows=1 loops=10338)
-> Index lookup on t3 using TABLE_NAME (TABLE_NAME=t2.`TABLE_NAME`) (cost=0.25 rows=1) (actual time=0.007..0.008 rows=1 loops=10338)
-> Index lookup on t1 using TABLE_SCHEMA (TABLE_SCHEMA=t2.TABLE_SCHEMA, TABLE_NAME=t2.`TABLE_NAME`) (cost=1.79 rows=129) (actual time=0.010..0.172 rows=131 loops=10143)
1 row in set (2.13 sec)
mysql>
從上面的分析結果來看,在驅動表t2執行Index scan on t2 using TABLE_SCHEMA
這一步的時候,就存在很大的差異了,執行快的SQL在這一步只掃描了一行記錄,耗時0.053毫秒,而執行快的SQL在這一步掃描數量基本上和執行計劃估計的一致,掃描了10338行記錄,耗時12.845毫秒;驅動表掃描記錄越多,那麼和後續表關聯的nested loop join次數也越多,導致兩條SQL執行時間差異巨大。
加大limit的返回限製為5000,驅動表t2掃描的行數增加至99行,執行時間增加至0.201毫秒
mysql> explain analyze select count(1) from (select t1.TABLE_CATALOG, t2.TABLE_SCHEMA, t2.TABLE_NAME, t1.COLUMN_NAME, t1.DATA_TYPE, t3.CONSTRAINT_TYPE from test_col t1 inner join test_tab t2 on t1.TABLE_SCHEMA = t2.TABLE_SCHEMA and t1.table_name = t2.table_name inner join test_tc t3 on t2.TABLE_SCHEMA = t3.TABLE_SCHEMA and t2.TABLE_NAME = t3.TABLE_NAME limit 5000) t \G*************************** 1. row ***************************
EXPLAIN: -> Aggregate: count(1) (actual time=33.395..33.396 rows=1 loops=1)
-> Table scan on t (cost=565.00 rows=5000) (actual time=0.005..0.765 rows=5000 loops=1)
-> Materialize (cost=75298.09 rows=5000) (actual time=31.863..33.046 rows=5000 loops=1)
-> Limit: 5000 row(s) (cost=75298.09 rows=5000) (actual time=0.126..25.326 rows=5000 loops=1)
-> Nested loop inner join (cost=75298.09 rows=132366) (actual time=0.124..24.757 rows=5000 loops=1)
-> Nested loop inner join (cost=4648.25 rows=1024) (actual time=0.095..0.834 rows=20 loops=1)
-> Filter: ((t2.`TABLE_NAME` is not null) and (t2.TABLE_SCHEMA is not null)) (cost=1064.25 rows=10240) (actual time=0.046..0.201 rows=99 loops=1)
-> Index scan on t2 using TABLE_SCHEMA (cost=1064.25 rows=10240) (actual time=0.044..0.157 rows=99 loops=1)
-> Filter: (t3.TABLE_SCHEMA = t2.TABLE_SCHEMA) (cost=0.25 rows=0) (actual time=0.005..0.006 rows=0 loops=99)
-> Index lookup on t3 using TABLE_NAME (TABLE_NAME=t2.`TABLE_NAME`) (cost=0.25 rows=1) (actual time=0.005..0.006 rows=0 loops=99)
-> Index lookup on t1 using TABLE_SCHEMA (TABLE_SCHEMA=t2.TABLE_SCHEMA, TABLE_NAME=t2.`TABLE_NAME`) (cost=56.08 rows=129) (actual time=0.011..1.171 rows=250 loops=20)
1 row in set (0.04 sec)
mysql>
從上面的analyze結果,也可以看出來,在測試使用的SQL結構中,關聯順序是方法2
,也就是從t2取一行數據,與t3表關聯得到一行結果後,再從t1中取一行關聯,每得到一行結果,返回一次數據
。
從官方文檔中介紹,explain analyze
是explain format=tree
的補充,兩者都是8.0出現的新功能,這裡簡單介紹一下我個人理解的查看這種執行計劃的順序,如果有不正確的地方,還請指正:最先查看第一個縮進最多的行,沒有相同縮進時,再向上一個縮進查看,再查看相同縮進的行(如果它有子縮進行,也是先查看縮進最多的行),以如下SQL為例,它的執行計劃查看順序為10->9->12->11->8->13->7->6->5->4->3
- 第一個縮進最多的行是第10行,執行計劃判斷以索引掃描的方式從t2表讀取10240條記錄,實際從t2表讀取了99條記錄,在讀取這99條記錄的操作過程中,讀取到第1條記錄耗時0.044毫秒,讀取到第99條耗時0.157毫秒,由於它是第一個讀取的表,也是查詢的驅動表,只會讀取一次數據
- 查看第9行,數據從存儲引擎獲取後,需要在server層過濾,計劃是過濾10240條記錄,實際上過濾了99條記錄,過濾這99條記錄的過程中,第1條記錄執行完成耗時是0.046毫秒,第99條記錄執行完成耗時是0.201毫秒,驅動表過濾操作也只進行一次
- 第11行與第9行縮進相同,但是由於它有子縮進第12行,所以先執行第12行,以普通索引等值查找的方式掃描t3表,這裡執行計劃每個關聯會返回一條記錄,但是實際數據返回0條,是由於這個值是平均值,即t2表的99行記錄在t3表中查詢記錄數除以99,取整後得到的值。
- 第12行,對從存儲引擎層返回的數據,做進一步過濾,這裡也迴圈99次
- 第8行,t2 表與t3表的關聯,關聯後返回記錄20條,完成關聯耗時為0.834毫秒
- 第13行,以普通索引等值查詢,從t1表中獲取數據,一共要完成20次迴圈查詢,每次迴圈獲取第一條記錄的平均時間是0.011毫秒,每次迴圈獲取最後一條記錄的時間是1.171毫秒,每次迴圈平均獲取250條記錄。
- 第7行,與t1關聯查詢的方法和結果,一共返回5000條記錄,返回第1條記錄耗時0.124毫秒,返回第5000條記錄耗時24.757毫秒
- 第6行,limit判斷,耗時25.326毫秒
- 第5行,物化這5000行記錄,物化完成耗時33.046毫秒
- 第4行,掃描物化表數據5000條記錄,掃描耗時0.765毫秒
- 第3行,數據做聚合,返回count數量,耗時33.396毫秒,也是整個SQL執行的總耗時
explain analyze
將執行過程中的索引、連接方式、過濾等信息嵌入了每個執行步驟,初次接觸時,可以使用explain
結果進行對比查看,以更容易接受和理解執行過程
總結
相同的SQL執行計劃,卻有不同的數據獲取過程,這個在以前的版本中,是很難分析到的,explain\optimizer_trace\profile都不行,現在通過explain analyze
能夠輕易實現,通過這個工具,也加深了對多表join的一個執行過程的理解,是一個非常實用的工具。
需要註意點:
- explain analyze過程中會實際執行具體SQL,但並不會SQL的執行結果,返回的結果集是詳細執行步驟
- 目前只支持select語句,對於insert\ update \delete未支持,這點和explain有差別
參考鏈接
https://dev.mysql.com/doc/refman/8.0/en/explain.html
Enjoy GreatSQL