暂无图片
暂无图片
3
暂无图片
暂无图片
暂无图片

[译]MySQL EXPLAIN ANALYZE

原创 代野(Tank) 2022-04-19
1540

原文地址:https://hackmysql.com/post/book-2/

原文作者:Hack MySQL

发布时间:2022/2/27

从 MySQL 8.0.18 开始,EXPLAIN ANALYZE 是了解查询执行不可或缺的工具,因为它通过测量查询执行计划的每个步骤来分解响应时间的查询执行阶段。 这些信息很有启发性,但输出并不直观:它需要练习并了解 MySQL 如何执行超出传统 EXPLAIN 输出显示的表连接顺序的查询。 这篇博文仔细研究了 EXPLAIN ANALYZE 输出的三个不同示例。

这篇博文是十一篇文章中的第三篇:一篇作为我的书 [Efficient MySQL Performance](https://oreil.ly/efficient-mysql-performance 的序言,每章十篇。完整列表是 tags/efficient-mysql-performance

背景和术语

Norvald Ryeng 的“MySQL 8.0 EXPLAIN ANALYZE”的幻灯片列举并说明了 MySQL 查询执行器在 8.0 中的变化:

image

在 MySQL 8.0 之前,在查询执行计划中检测步骤是不可行的,因为代码是分散的和异构的。从 MySQL 8.0 开始,在查询执行计划中检测步骤是微不足道的,因为每个步骤本质上都是一样的:一个迭代器。由于迭代器是一个接口,因此可以透明地将每个真正的迭代器包装在一个定时迭代器(sql/timing_iterator.h)中:

template <class RealIterator>
bool TimingIterator<RealIterator>::Init() {
  ++m_num_init_calls;
  steady_clock::time_point start = now();     /* start time    */
  bool err = m_iterator.Init();               /* real iterator */
  steady_clock::time_point end = now();       /* end time      */
  m_time_spent_in_first_row += end - start;
  m_first_row = true;
  return err;
}

TimingIterator这是包装和测量真实迭代器的挂钟时间的类的一部分(我添加的评论)。在执行查询时,MySQL 直接执行真正的迭代器。对于EXPLAIN ANALYZE,MySQL 将每个真正的迭代器包装在 a 中TimingIterator(并丢弃结果集)。

迭代器接口有两个方法:Init()和Read()。“循环”是迭代器的一次调用:调用Init(), 然后Read()直到没有更多行。 EXPLAIN ANALYZE打印每个迭代器的测量值,例如:

(actual time=0.106..9.991 rows=2844 loops=2)

0.106

Init time: average time (in milliseconds) for Init() and first row (first Read())

9.991

Read time: average time (in milliseconds) for Init() and all rows (all Read())

rows=2844

Total number of rows read (all loops)

loops=2

Number of calls to Init() (number of times iterator invoked)

第一个时间值,我称之为“初始化时间”,被认为是启动成本,它通常非常低,但它取决于迭代器——下一节,示例 1:文件排序,就是一个例子。

第二个时间值,我称之为“读取时间”,乘以loops计算时最有用迭代器时间:迭代器读取行所花费的总时间(以毫秒为单位)。在本例中,9.991 ms × 2 = 19.982 ms 迭代器时间。

When loops=1, read time 和 iterator time 是一样的。

init time、read time和iterator time 是我定义的术语,不是 MySQL 官方术语,因为 MySQL 没有为这些值指定简洁的名称。

一般来说,迭代器时间是从叶子到根的累积时间。

-> A (200ms loops=1)
   -> B (185ms loops=1)
      -> C (90ms loops=2)

给定上面的伪迭代器树,叶子迭代器 C 需要 180 毫秒(90 × 2 循环)。由于迭代器 B 调用迭代器 C,迭代器的时间 B(不包括迭代器 C)为 5 毫秒(185 毫秒 - 180 毫秒)。同样,迭代器A调用迭代器 B,因此前者的时间为 15 毫秒(200 毫秒 - 185 毫秒)。这很重要,因为查询花费了 200 毫秒,而不是报告时间的总和(565 毫秒)。这通常是正确的,但并非总是如此——MySQL 总是有这样有趣的小惊喜。

有关更多技术细节,请阅读:

输出格式和注释

EXPLAIN ANALYZE输出并非易读(琐碎的查询除外)。这是真正的输出格式:

mysql> EXPLAIN ANALYZE SELECT c FROM sbtest1 WHERE k < 450000 ORDER BY id\G
*************************** 1. row ***************************
EXPLAIN: -> Sort: sbtest1.id  (cost=84245.94 rows=133184) (actual time=1347.876..1357.375 rows=68440 loops=1)
    -> Index range scan on sbtest1 using k_1, with index condition: (sbtest1.k < 450000)  (cost=84245.94 rows=133184) (actual time=41.021..1298.076 rows=68440 loops=1)

1 row in set (1.37 sec)

当有许多迭代器时,输出是密集且繁琐的。这不是对 MySQL 的批评,它只是EXPLAIN输出在 MySQL CLI/shell 中的工作方式。(MySQL Workbench有一个“视觉解释”功能,但我不知道它是否适用EXPLAIN ANALYZE。)

以下是我在以下三个示例中重新格式化和注释输出的方式:

1 -> Sort: sbtest1.id
     (actual time=2043.416 .. 2051.792 rows=68440 loops=1)
0     -> Index range scan on sbtest1 using k_1, with index condition: (sbtest1.k < 450000)
         (actual time=109.302 .. 1996.350 rows=68440 loops=1)

左边距中的数字,从 0 开始,按读取顺序对迭代器进行编号:如何读取输出以遵循行访问的流程。这很有帮助,因为输出通常首先从上到下读取深度,但并非总是如此。我用这些数字来指代迭代器,比如“索引范围扫描 (0) 在……期间执行”。

此外,为了使输出更易于阅读和遵循:

  • (cost=…)已移除
  • (actual time=…)放在自己的线上
  • 41.021…1298.076初始化时间和读取时间有额外的空白:41.021 … 1298.076
  • 语法突出显示使数字从文本中脱颖而出

现在我们可以检查和讨论一些例子,而不会太费神。

示例 1:文件排序

1 -> Sort: sbtest1.id
     (actual time=2043.416 .. 2051.792 rows=68440 loops=1)
0     -> Index range scan on sbtest1 using k_1, with index condition: (sbtest1.k < 450000)
         (actual time= 109.302 .. 1996.350 rows=68440 loops=1)

在索引和索引的 Efficient MySQL Performance 的第 2 章中,我使用一页(字面意思是一页:打印中的第 70 页)EXPLAIN SELECT c FROM sbtest1 WHERE k < 450000 ORDER BY id 来证明数据访问而不是文件排序是该查询中最慢的部分。

我在书中解释了输出,所以我不会在这里重复自己。相反,EXPLAIN ANALYZE在阅读更复杂的例子之前,让我们重用这个简单的例子来更深入地理解。

的输出与EXPLAIN ANALYZE我们对查询执行的看法有些相反。对于这个查询和其他类似的查询,我们有理由认为 MySQL 获取然后对行进行排序(无法对尚未获取的行进行排序),但输出显示不同:index range scan (0) nested (indented) one排序 (1) 中的级别,看起来像获取行 — 索引范围扫描 (0) — 发生在排序 (1) 之后。但事实并非如此。左边距中带注释的数字是行访问的顺序。输出反映了这些迭代器是如何实现和调用的,如 sql/iterators/sorting_iterator.h 中所述:

/**
  An adapter that takes in another RowIterator and produces the same rows,
  just in sorted order. (The actual sort happens in Init().)

正如该评论所指出的,排序迭代器 (1) 是一个适配器,它在后台调用另一个迭代器来获取行——在本例中为索引范围扫描 (0)。然后 sort (1) 对索引范围扫描 (0) 获取的行进行排序。而 sort (1) 在Init(). sort (1)Read()只是按顺序返回已经获取和排序的行,这就是为什么读取时间非常接近初始化时间:它主要是初始化时间,只有几毫秒才能返回已排序的 68,440 行。

结果,排序(1)的初始化时间和读取时间都不是纯粹的排序时间测量,这是(恕我直言)我们期望从排序迭代器的计时中看到的,因为它的目的是排序,但它根本没有编程方式。相反,sort (1) init time 包括索引范围扫描 (0) 读取时间和对行进行排序所花费的时间。

由于索引范围扫描 (0) 读取时间只是获取行所花费的时间,我们可以从排序 (1) 初始化时间中减去它来粗略计算排序行所花费的时间:2043.416 - 1996.350 = 47 ms。

唉,前面提到的意思是我在 Efficient MySQL Performance 的 第 70 页上的原始解释是不准确的。我写道:“文件排序(第 1 行)在 [2043.416] 毫秒后开始,在 [2051.792] 毫秒后结束,这意味着文件排序花了 8 毫秒。” 结论仍然正确:“答案是否定的:filesort 不会使这个查询变慢。问题是数据访问:68,439 行不是一个小的结果集。” 但是我得出结论的方式是不正确的。

这个故事的寓意是:有时您需要了解迭代器如何在底层工作(在 MySQL 源代码中)才能正确解释报告的计时值。

示例 2:简单连接

3 -> Nested loop inner join
     (actual time=0.022..0.036 rows=4 loops=1)
1     -> Filter: (elem.a in ('Ag','Au','At'))
         (actual time=0.015..0.024 rows=4 loops=1)
0         -> Covering index range scan on elem using idx_a_b
             (actual time=0.013..0.022 rows=4 loops=1)
2     -> Single-row index lookup on elem_names using PRIMARY (symbol=elem.a)
         (actual time=0.002..0.002 rows=1 loops=4)

这是EXPLAIN ANALYZE您在本书第 74 页找到并下载示例的 2-19 的输出。查询是:

SELECT name FROM elem JOIN elem_names ON (elem.a=elem_names.symbol) WHERE a IN ('Ag', 'Au', 'At');

这个例子强调了你通常如何阅读 EXPLAIN ANALYZE输出:深度优先。尽管查询执行是基于连接 (3),但行访问从 table 上的覆盖索引扫描 (0) 开始elem。然后为IN()子句过滤行 (1)。匹配行用于查找和连接表中的相应行elem_names:主键查找(2)。

请注意,loops=1对于覆盖索引扫描(0)和过滤器(1):连接中的第一个表被访问一次。但是loops=4对于主键查找 (2),因为连接表(连接中的第二个和后续表)通常会为前面表中的每一行访问多次。同样,过滤器 (1) 匹配rows=4,它对应于主键查找 (2) loops=4:第一个表中的四行导致 MySQL 访问连接表四次。要了解更多信息,请阅读 Efficient MySQL Performance 中第 2 章末尾的“表连接算法”部分。

示例 3:Sakila

5 -> Table scan on <temporary>
     (actual time=0.001 .. 0.002 rows=2 loops=1)
4     -> Aggregate using temporary table
         (actual time=26.210 .. 26.210 rows=2 loops=1)
3         -> Nested loop inner join
             (actual time=0.140 .. 20.580 rows=5687 loops=1)
0             -> Table scan on staff
                 (actual time=0.023 .. 0.028 rows=2 loops=1)
2             -> Filter: (payment.payment_date like '2005-08%')
                 (actual time=0.106 .. 9.991 rows=2844 loops=2)
1                 -> Index lookup on payment using idx_fk_staff_id (staff_id=staff.staff_id)
                     (actual time=0.098 .. 7.099 rows=8024 loops=2)

这是 Norvald Ryeng 在 MySQL EXPLAIN ANALYZE (MySQL Blog Archive) 中使用的示例。该查询是一个简单的带有 GROUP BY 子句的两表连接,这就是为什么存在聚合 (4) 和临时表扫描 (5) 的原因:

SELECT first_name, last_name, SUM(amount) AS total
FROM staff INNER JOIN payment ON staff.staff_id=payment.staff_id AND payment_date LIKE '2005-08%'
GROUP BY first_name, last_name;

从表扫描 (0) 到索引查找 (1) 到过滤 (2) 以完成连接 (3) 的行访问流程与前面的示例类似。

聚合 (4) 是新的:它从连接 (3) 接收和分组行。注意 join (3) rows=5687but aggregate (4) rows=2:查询只返回 2 个组(每组一行)。有趣的是,聚合 (4) 的初始化时间和读取时间是相同的,这表明所有工作Init()都已完成——我们必须检查 MySQL 源代码来验证。

正如 Norvald 在他的博客文章中指出的那样,这个查询花费的大部分时间不是表扫描 (0),这有点令人惊讶,因为假定表扫描非常慢。但是对于这个查询,有一个非常简单的解释:rows=2在表扫描 (0) 上——表只有两行。因此,97% 的连接 (3) 用于查找和过滤行(分别为索引查找 (1) 和过滤器 (2))。过滤器 (2) 的时间包括索引查找 (1) 所花费的时间,过滤器 (2) 的迭代器时间为 9.991 毫秒 × 2 = 19.982 毫秒,是连接 (3) 迭代器时间 20.580 毫秒的 97%。表扫描通常很慢,但此示例表明,如果一张表很小,则对连接表的索引查找可能会更耗时。或者换一种说法:如果您type: ALL在 EXPLAIN 计划中看到(传统EXPLAIN输出),全表扫描有可能不是查询响应时间中最耗时的部分。

这个例子的奇怪部分是临时表扫描(5):它的时间不包括其他迭代器的时间,即使它是根迭代器。我无法从 MySQL 源代码中看出为什么会这样,但我认为这是因为临时表扫描 (5) 发生在聚合 (4) 完全完成之后,几乎就像临时表扫描 (5) 是完全独立的不包含和调用聚合 (4) 的迭代器。

无论如何,重点是:您必须 EXPLAIN ANAZLYE 非常仔细地阅读输出,从相关(嵌套)迭代器中提取相对数字,并根据对 MySQL 实际如何执行查询的理解为不符合典型解释的输出留出一些余量. 无论这些挑战如何,都EXPLAIN ANALYZE可以提供对查询响应时间的有价值的低级洞察。

其他资源

令人惊讶的是,MySQL 社区几乎没有写过关于 EXPLAIN ANALYZE 方面的信息,以下是一些讨论的其他资源(其中一些已经在前面链接过)EXPALIN ANALYZE:

除了这些资源和这篇博文之外,我建议您使用自己的查询场景进行练习。从传统 EXPLAIN的 查看表连接顺序开始,然后 EXPLAIN ANALYZE以 一般自上而下、深度优先的方式阅读输出,同时考虑表连接顺序以帮助指导您。如果你看到一些不太有意义的东西,很可能是输出的奇怪而不是误读。

最后,请记住 EXPLAIN ANALYZE 实际执行查询(锁定和其他所有操作),因此不要在活动的生产服务器上运行它:使用具有相同数据的只读副本或登台服务器,因为数据通常是影响查询执行和性能的一个因素,这是进入我将在下个月(2022 年 3月)写的本系列的下一篇博客文章的完美过渡。

「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
1人已赞赏
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论