转:故障分析|不是慢 SQL 的锅！一次数据库 CPU 被打满的诡异排查

原文： mp.weixin.qq.com

一、前言

近期随着数据量的增长，数据库 CPU 使用率 100% 报警频繁起来。第一个想到的就是慢 Sql，我们对未合理运用索引的表加入索引后，问题依然没有得到解决，深入排查时，发现在 order by id asc limit n 时，即使 where 条件已经包含了覆盖索引，优化器还是选择了错误的索引导致。通过查询大量资料，问题得到了解决。这里将解决问题的思路以及排查过程分享出来，如果有错误欢迎指正。

二、正文

1、环境介绍

2、发现问题

22 日开始，收到以下图 1 报警变得频繁起来，由于数据库中会有大数据推数动作，数据库 CPU 偶尔报警并没有引起对该问题的重视，直到通过图 2 对整日监控数据分析时，才发现问题的严重性，从 0 点开始，数据库 CPU 频繁被打满。

图 1 报警图

图 2 整日 CPU 监控图

3、排查问题

发现问题后，开始排查慢 Sql，发现很多查询未添加合适的索引，经过一轮修复后，问题依然没有得到解决，在深入排查时发现了一个奇怪现象，SQL 代码如下（表名已经替换），比较简单的一个单表查询语句。

1
2
3
4
5
6
7
8
9
10
11
12
13
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 2100
ORDER BY
id
LIMIT 500;

看似比较简单的查询，但执行时长平均在 90s 以上，并且调用频次较高。如图 3 所示。

图 3 慢 Sql 平均执行时长

开始检查表信息，可以看到表数据量在 2100w 左右。

图 4 数据表情况

排查索引情况，主键为 id，并且有 business_day 与 full_ps_code 的联合索引。

1
2
3
4
5
6
7
8
PRIMARY KEY (`id`) USING BTREE,
KEY `idx_business_day_full_ps_code` (`business_day`,`full_ps_code`)
==========以下索引可以忽略========
KEY `idx_erp_month_businessday` (`erp`,`month`,`business_day`),
KEY `idx_business_day_erp` (`business_day`,`erp`),
KEY `idx_erp_month_ps_plan_id` (`erp`,`month`,`ps_performance_plan_id`),
......

通过 Explain 查看执行计划时发现，possible_keys 中包含上面的联合索引，而 Key 却选择了 Primary 主键索引，扫描行数 Rows 为 1700w，几乎等于全表扫描。

图 5 执行计划情况

4、解决问题

第一次，我们分析是，由于 Where 条件中包含了 ID，查询分析器认为主键索引扫描行数会少，同时根据主键排序，使用主键索引会更加合理，我们试着添加以下索引，想要让查询分析器命中我们新加的索引。

1
2
ADD INDEX `idx_test`(`business_day`, `full_ps_code`, `id`) USING BTREE;

再次通过 Explain 语句进行分析，发现执行计划完全没变，还是走的主键索引。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
explain
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 2100
ORDER BY
id
LIMIT 500;

图 6 执行计划情况

第二次，我们通过强制指定索引方式 force index (idx_test) 方式，再次分析执行情况，得到图 7 的结果，同样的查询条件同样的结果，查询时长由 90s->0.49s 左右。问题得到解决

图 7 强制指定索引后执行计划情况

第三次，我们怀疑是 where 条件中有 ID 导致直接走的主键索引，where 条件中去掉 id，Sql 调整如下，然后进行分析。依然没有命中索引，扫描 rows 变成 111342，查询时间 96s

1
2
3
4
5
6
7
8
9
10
11
12
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
ORDER BY
id
LIMIT 500

第四次，我们把 order by 去掉，SQL 调整如下，然后进行分析。命中了 idx_business_day_full_ps_code 之前建立的联合索引。扫描行数变成 154900，查询时长变为 0.062s，但是发现结果与预想的不一致，发生了乱序

1
2
3
4
5
6
7
8
9
10
11
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 2100
LIMIT 500;

第五次，经过前几次的分析可以确定，order by 导致查询分析器选择了主键索引，我们在 Order by 中增加排序字段，将 Sql 调整如下，同样可以命中我们之前的联合索引，查询时长为 0.034s，由于先按照主键排序，结果是一致的。相比第四种方法多了一份 filesort，问题得解决。

1
2
3
4
5
6
7
8
9
10
11
12
13
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 2100
ORDER BY
id，full_ps_code
LIMIT 500;

第六次，我们考虑是不是 Limit 导致的问题，我们将 Limit 500 调整到 1000，Sql 调整如下，奇迹发生了，命中了联合索引，查询时长为 0.316s，结果一致，只不过多返回来 500 条数据。问题得到了解决。经过多次实验 Limit 大于 695 时就会命中联合索引，查询条件下的数据量是 79963，696/79963 大概占比是 0.0087，猜测当获取数据比超过 0.0087 时，会选择联合索引，未找到源代码验证此结论。

1
2
3
4
5
6
7
8
9
10
11
12
13
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 2100
ORDER BY
id
LIMIT 1000;

经过我们的验证，其中第 2、5、6 三种方法都可以解决性能问题。为了不影响线上，我们立即修改代码，并选择了 force index 的方式，上线观察一段时间后，数据库 CPU 恢复正常，问题得到了解决。

三、事后分析

上线后问题得到了解决，同时也留给我了很多疑问。

  • 为什么明明 where 条件中包含了联合索引，却未能命中，反而选择了性能较慢的主键索引？

  • 为什么在 order by 中增加了一个索引其他字段，就可以命中联合索引了呢？

  • 为什么我仅仅是将 limit 限制条件由原来的 500 调大后，也能命中联合索引呢？

这一切的答案都来自 MySQL 的查询优化器。

1、查询优化器

查询优化器是专门负责优化查询语句的优化器模块，通过计算分析收集的各种系统统计信息，为查询给出最优的执行计划 —— 最优的数据检索方式。

优化器决定如何执行查询的方式是基于一种称为基于代价的优化的方法。5.7 在代价类型上分为 IO、CPU、Memory。内存的代价收集了，但是并没有参与最终的代价计算。Mysql 中引入了两个系统表，mysql.server_cost 和 mysql.engine_cost，server_cost 对应 CPU 的代价，engine_cost 代表 IO 的代价。

server_cost（CPU 代价）

  • row_evaluate_cost (default 0.2) 计算符合条件的行的代价，行数越多，此项代价越大

  • memory_temptable_create_cost (default 2.0) 内存临时表的创建代价

  • memory_temptable_row_cost (default 0.2) 内存临时表的行代价

  • key_compare_cost (default 0.1) 键比较的代价，例如排序

  • disk_temptable_create_cost (default 40.0) 内部 myisam 或 innodb 临时表的创建代价

  • disk_temptable_row_cost (default 1.0) 内部 myisam 或 innodb 临时表的行代价

由上可以看出创建临时表的代价是很高的，尤其是内部的 myisam 或 innodb 临时表。

engine_cost（IO 代价）

  • io_block_read_cost (default 1.0) 从磁盘读数据的代价，对 innodb 来说，表示从磁盘读一个 page 的代价

  • memory_block_read_cost (default 1.0) 从内存读数据的代价，对 innodb 来说，表示从 buffer pool 读一个 page 的代价

这些信息都可以在数据库中配置，当数据库中未配置时，从 MySql 源代码（5.7）中可以看到以上默认值情况

2、代价配置

1
2
3
4
5
6
7
--修改io_block_read_cost值为2
UPDATE mysql.engine_cost
SET cost_value = 2.0
WHERE cost_name = 'io_block_read_cost';
--FLUSH OPTIMIZER_COSTS 生效，只对新连接有效，老连接无效。
FLUSH OPTIMIZER_COSTS;

3、代价计算

代价是如何算出来的呢，通过读 MySql 的源代码，可以找到最终的答案

1）全表扫描（table_scan_cost）

以下代码摘自 MySql Server（5.7 分支），全表扫描时，IO 与 CPU 的代价计算方式。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
double scan_time=
cost_model->row_evaluate_cost(static_cast<double>(records)) + 1;
// row_evaluate_cost 核心代码
// rows * m_server_cost_constants->row_evaluate_cost()
// 数据行数 * 0.2 (row_evaluate_cost默认值) + 1 = CPU代价
Cost_estimate cost_est= head->file->table_scan_cost();
//table_scan_cost 核心代码
//const double io_cost
// = scan_time() * table->cost_model()->page_read_cost(1.0)
// 这部分代价为IO部分
//page_read_cost 核心代码
//
//const double in_mem= m_table->file->table_in_memory_estimate();
//
// table_in_memory_estimate 核心逻辑
//如果表的统计信息中提供了信息,使用统计信息，如果没有则使用启发式估值计算
//pages=1.0
//
//const double pages_in_mem= pages * in_mem;
//const double pages_on_disk= pages - pages_in_mem;
//
//
//计算出两部分IO的代价之和
//const double cost= buffer_block_read_cost(pages_in_mem) +
// io_block_read_cost(pages_on_disk);
//
//
//buffer_block_read_cost 核心代码
// pages_in_mem比例 * 1.0 （memory_block_read_cost的默认值）
// blocks * m_se_cost_constants->memory_block_read_cost()
//
//
//io_block_read_cost 核心代码
//pages_on_disk * 1.0 （io_block_read_cost的默认值）
//blocks * m_se_cost_constants->io_block_read_cost();
//返回IO与CPU代价
//这里增加了个系数调整，原因未知
cost_est.add_io(1.1);
cost_est.add_cpu(scan_time);

根据源代码分析，当表中包含 100 行数据时，全表扫描的成本为 23.1，计算逻辑如下

1
2
3
4
5
//CPU代价 = 总数据行数 * 0.2 (row_evaluate_cost默认值) + 1
cpu_cost = 100 * 0.2 + 1 等于 21
io_cost = 1.1 + 1.0 等于 2.1
//总成本 = cpu_cost + io_cost = 21 + 2.1 = 23.1

验证结果如下图

2）索引扫描（index_scan_cost）

以下代码摘自 MySql Server（5.7 分支），当出现索引扫描时，是如何进行计算的，核心代码如下

1
2
3
4
5
6
//核心代码解析
*cost= index_scan_cost(keyno, static_cast<double>(n_ranges),
static_cast<double>(total_rows));
cost->add_cpu(cost_model->row_evaluate_cost(
static_cast<double>(total_rows)) + 0.01)

io 代价计算核心代码

1
2
3
4
5
6
7
8
//核心代码
const double io_cost= index_only_read_time(index, rows) *
table->cost_model()->page_read_cost_index(index, 1.0);
// index_only_read_time(index, rows)
// 估算index占page个数
//page_read_cost_index(index, 1.0)
//根据buffer pool大小和索引大小来估算page in memory和in disk的比例，计算读一个page的代价

cpu 代价计算核心代码

1
2
3
4
5
6
add_cpu(cost_model->row_evaluate_cost(
static_cast<double>(total_rows)) + 0.01);
//total_rows 等于索引过滤后的总行数
//row_evaluate_cost 与全表扫描的逻辑类似，
//区别在与一个是table_in_memory_estimate一个是index_in_memory_estimate

3）其他方式

计算代价的方式有很多，其他方式请参考 MySql 原代码。https://github.com/mysql/mysql-server.git

4、深度解析

通过查看 optimizer_trace，可以了解查询优化器是如何选择的索引。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
set optimizer_trace="enabled=on";
--如果不设置大小，可能导致json输出不全
set OPTIMIZER_TRACE_MAX_MEM_SIZE=1000000;
SELECT
*
FROM
test
WHERE
is_delete = 0
AND business_day = '2021-12-20'
AND full_ps_code LIKE 'xxx%'
AND id > 0
ORDER BY
id
LIMIT 500;
select * FROM information_schema.optimizer_trace;
set optimizer_trace="enabled=off";

通过分析 rows_estimation 节点，可以看到通过全表扫描（table_scan）的话的代价是 8.29e6，同时也可以看到该查询可以选择到主键索引与联合索引，如下图。

上图中全表扫描的代价是 8.29e6，我们转换成普通计数法为 8290000，如果使用主键索引成本是 3530000，联合索引 185881，最小的应该是 185881 联合索引，也可以看到第一步通过成本分析确实选择了我们的联合索引。

但是为什么还是选择了主键索引呢？

通过往下看，在 reconsidering_access_paths_for_index_ordering 节点下， 发现由于 Order by 导致重新选择了索引，在下图中可以看到主键索引可用（usable=true），我们的联合索引为 not_applicable （不适用），意味着排序只能使用主键索引。

接下来通过 index_order_summary 可以看出，执行计划最终被调整，由原来的联合索引改成了主键索引，就是说这个选择无视了之前的基于索引成本的选择。

为什么会有这样的一个选项呢，主要原因如下：

The short explanation is that the optimizer thinks — or should I say hopes — that scanning the whole table (which is already sorted by the id field) will find the limited rows quick enough, and that this will avoid a sort operation. So by trying to avoid a sort, the optimizer ends-up losing time scanning the table.

从这段解释可以看出主要原因是由于我们使用了 order by id asc 这种基于 id 的排序写法，优化器认为排序是个昂贵的操作，所以为了避免排序，并且它认为 limit n 的 n 如果很小的话即使使用全表扫描也能很快执行完，所以它选择了全表扫描，也就避免了 id 的排序。

四、总结

查询优化器会基于代价来选择最优的执行计划，但由于 order by id limit n 的存在，MySql 可能会重新选择一个错误的索引，忽略原有的基于代价选择出来的索引，转而选择全表扫描的主键索引。这个问题在国内外有大量的用户反馈，BUG 地址 https://bugs.mysql.com/bug.php?id=97001 。官方称在 5.7.33 以后版本可以关闭 prefer_ordering_index 来解决。如下图所示。

另外在我们日常慢 Sql 调优时，可以通过以下两种方式，了解更多查询优化器选择过程。

1
2
3
4
5
6
7
8
9
10
11
--第一种
explain format=json
sql语句
-------------------------------------------------------------------------
--第二种 optimizer_trace方式
set optimizer_trace="enabled=on";
--如果不设置大小，可能导致json输出不全
set OPTIMIZER_TRACE_MAX_MEM_SIZE=1000000;
SQL语句
select * FROM information_schema.optimizer_trace;
set optimizer_trace="enabled=off";

当你也出现了本篇文章碰到的问题时，可以采用以下的方法来解决：
1）使用 force index，强制指定索引。
2）order by 中增加一个联合索引的 key。
3）扩大 limit 返回的范围（不推荐，随着数据量的增大，可能还会走回主键索引）。
4）order by (id+0) asc 欺骗查询优化器，让其选择联合索引。
5）MySQL 5.7.33 版本以上，可以关闭 prefer_ordering_index 解决。

作者丨陈强

来源丨网址：https://my.oschina.net/u/4090830/blog/5571483