【聚看点】相同执行计划，为何有执行快慢的差别
2022-08-15 16:49:26来源：GreatSQL社区
前言
今天遇到一个很神奇的现象，在数据库中，相同的执行计划，执行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 || 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)mysql>
再看执行慢的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有差别
