前言
我们在日常开发中，一定遇见过某些SQL执行较慢的情况，我们俗称“慢SQL”，如果你对系统的接口性能要求较高的话，一定不会放过这种SQL，肯定会想办法进行解决，那么，导致慢 SQL 出现的原因，究竟可能都有哪些呢？
这是一道经典的面试题，就此我们来研究一番，下面我们就来好好看一下，原因可能出在哪里。
本篇我们将从如下几个方面进行讨论：
1.慢SQL捕获
2.执行计划分析
3.引擎参数配置分析
让我们就此开启本次慢SQL分析之旅，Let's go！
ps: 本篇文章的讨论，主要基于MySQL8.0数据库，Oracle等其他数据库不在本篇讨论范围之列。
一、慢SQL捕获
追查应用服务的慢SQL，首先需要追踪哪些SQL可能是慢SQL，对于JAVA服务，很多数据库中间件提供了慢SQL的追踪能力，例如Alibaba Druid，会将服务运行过程中的慢SQL打印到日志文件，方便开发运维人员追查。
MySQL当然也提供了捕获慢查询的监控能力，记录在MySQL中执行时间超过指定时间的SQL语句。
默认情况下，MySQL并没有开启慢日志，可以通过修改slow_query_log参数来打开慢日志。与慢日志相关的参数介绍如下：
一般情况下，我们只需开启慢日志记录，配置下阈值时间，其余参数可按默认配置。对于阈值时间，可灵活调整，比如说可以设置为 1s 或 3s 。
1.慢查询追踪配置方式
MySQL提供了两种配置慢查询参数的方式，提供给开发者使用，下面我们依次来看一下。
第一种，将慢查询参数配置写入MySQL配置文件，永久生效：
# 慢查询日志相关配置，可根据实际情况修改
vim /etc/my.cnf
[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/sql-slow.log
long_query_time = 1
log_timestamps = SYSTEM
log_output = FILE
第二种，MySQL Server中临时开启慢查询功能，当MySQL Server重启时，配置修改则全部失效并恢复原状：
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL slow_query_log_file = '/var/log/mysql/sql-slow.log';
SET GLOBAL log_queries_not_using_indexes = 'ON';
SET SESSION long_query_time = 1;
SET SESSION min_examined_row_limit = 100;
如何查看下慢查询日志是否开启，以及慢查询日志文件的位置：
mysql> show variables like '%slow_query_log%';
+---------------------+-----------------------------------------+
Variable_name | Value |
+---------------------+-----------------------------------------+
slow_query_log | ON |
slow_query_log_file | /var/lib/mysql/VM-16-14-centos-slow.log |
+---------------------+-----------------------------------------+
2 rows in set (0.00 sec)
下面我们具体看下，慢日志会记录哪些内容？我们执行一条较慢的查询SQL，来看下在慢日志中的体现。
# Time: 2022-11-02T09:23:37.004885Z
# User@Host: wtopps[wtopps] @ localhost [] Id: 10831
# Query_time: 1.609214 Lock_time: 0.003828 Rows_sent: 2050008 Rows_examined: 2150010
SET timestamp=1667381015;
SELECT A.* FROM `user` A LEFT JOIN grade B ON A.`id` = B.`user_id`;
对于每一组慢SQL，日志内容格式如下：
第一行记录的是该条SQL执行的时刻（如果log_timestamps参数为UTC，则改时间会显示UTC时区时间）。
第二行记录的是执行该语句的用户和IP以及链接id。
第三行的几个字段含义如下：
在8.0.14及以上版本可以打开log_slow_extra系统参数，收集更多信息。
mysql>set global log_slow_extra=on
# Time: 2023-02-10T13:07:50.617272Z
# User@Host: wtopps[wtopps] @ [111.197.236.164] Id: 19187
# Query_time: 91.511261 Lock_time: 0.000124 Rows_sent: 2050008 Rows_examined: 2150010 Thread_id: 19187 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 58061725 Read_first: 2 Read_last: 0 Read_key: 2 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 2150012 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2023-02-10T13:06:19.106011Z End: 2023-02-10T13:07:50.617272Z
SET timestamp=1676034379;
SELECT A.* FROM `user` A LEFT JOIN grade B ON A.`id` = B.`user_id`;
可以看到，当开启log_slow_extra参数后，慢查询日志中出现了大量的额外信息，其含义如下：
Thread_id：连接的标识；
Errno：SQL错误号，0表示没有错误；
Killed：语句终止的错误号，0表示正常终止；
Bytes_received/sent：收到和发送的字节数；
Read_first:Handler_read_first的值，代表读取索引中第一个条目的次数。反映查询全索引扫描的次数。
Read_last：读取索引最后一个key的次数；
Read_key：基于key读取行的请求数，较大说明使用正确的索引
Read_next：按顺序取下一行数据的次数，索引范围查找和索引扫描时该值会增大；
Read_prev：按顺序读取上一行的请求数，order by desc查询较优时该值较大；
Read_rnd：按固定位置读取行的请求数，大量的回表、没有索引的连接和对结果集排序时会增加；
Read_rnd_next：读取数据文件下一行的次数，大量表扫描、未创建或合理使用索引时会增加；
Sort_range_count：使用范围完成的排序次数；
Sort_rows：排序的行数；
Sort_scan_count：通过扫描表完成的排序次数；
Sort_merge_passes：排序算法合并的次数，如该值较大考虑增加sort_buffer_size的值
Created_tmp_disk_tables：创建内部磁盘临时表的数量；
Created_tmp_tables：创建内部临时表的数量；
Start/End：语句开始和结束时间
Tips：
在MariaDB中，可以开启log_slow_verbosity参数，可以更加详尽的打印出慢SQL的执行细节，该参数在MySQL8.0版本中并未支持，读者感兴趣可以自行查阅相关信息。
通过慢查询日志，我们可以捕获到具体的慢SQL，接下来，则要具体分析慢SQL产生的可能原因。
二、情况分析
1.为什么查询会慢？
在尝试编写快速的查询之前，需要清楚一点，真正重要是响应时间。如果把查询看作是一个任务，那么它由一系列子任务组成，每个子任务都会消耗一定的时间。如果要优化查询，实际上要优化其子任务，要么消除其中一些子任务，要么减少子任务的执行次数，要么让子任务运行得更快。
MySQL在执行查询的时候有哪些子任务，哪些子任务运行的速度很慢？这里很难给出完整的列表，通常来说，查询的生命周期大致可以按照顺序来看：
从客户端，到服务器，然后在服务器上进行解析，生成执行计划，执行，并返回结果给客户端。其中“执行”可以认为是整个生命周期中最重要的阶段，这其中包括了大量为了检索数据到存储引擎的调用以及调用后的数据处理，包括排序、分组等。
mysql执行过程
在完成这些任务的时候，查询需要在不同的地方花费时间，包括网络，CPU计算，生成统计信息和执行计划、锁等待（互斥等待）等操作，尤其是向底层存储引擎检索数据的调用操作，这些调用需要在内存操作、CPU操作和内存不足时导致的I/O操作上消耗时间。
根据存储引擎不同，可能还会产生大量的上下文切换以及系统调用。
在每一个消耗大量时间的查询案例中，大概率会出现一些不必要的额外操作、某些操作被额外地重复了很多次、某些操作执行得太慢等。优化查询的目的就是减少和消除这些操作所花费的时间。
再次申明一点，对于一个查询的全部生命周期，上面列的并不完整。这里我们只是想说明：了解查询的生命周期、清楚查询的时间消耗情况对于优化查询有很大的意义。有了这些概念，我们再一起来看看如何优化查询。
捕获具体的慢查询SQL后，我们需要对可能导致慢查询的原因进行分析，我们可以从如下几个角度，对问题进行拆解：
2.SQL执行计划分析
查询性能低下最基本的原因是访问的数据太多。某些查询可能不可避免地需要筛选大量数据，但在实际业务场景中，这并不常见。
大部分性能低下的查询都可以通过减少访问的数据量的方式进行优化。对于低效的查询，我们发现通过下面两个步骤来分析总是很有效：
有些查询会请求超过实际需要的数据，然后这些多余的数据会被应用程序丢弃。这会给MySQL服务器带来额外的负担，并增加网络开销，另外也会消耗应用服务器的CPU和内存资源。
因此，合理的使用索引的重要性就凸显出来，如果查询中的查询条件未命中索引字段，MySQL引擎则只能对全量的数据进行检索，再根据查询条件进行过滤，筛选出目标的数据集，这个过程是非常耗时且低效的。
接下来，我们将逐步对SQL执行的过程进行分析拆解，通过工具手段剖析慢查询的具体原因。
SQL分析三步走
3.explain执行计划分析
对于SQL执行过程分析，最先登场的毫无疑问就是explain语句了，explain是我们在日常开发最常使用的分析命令。其使用方式，这里不再赘述，一般来说，95% 的慢查询问题只需要explain就可以解决了。
对于explain执行计划的分析，我们需要关注最简单的衡量查询开销的两个点：
通过explain执行计划可以获得SQL在执行时预估的扫描行数以及返回行数的大概比例，这在一定程度上能够说明该查询找到需要的数据的效率高不高。
但这个指标也并不是绝对的，因为并不是所有的行的访问代价都是相同的。较短的行的访问速度更快，内存中的行也比磁盘中的行的访问速度要快得多。
理想情况下扫描的行数和返回的行数应该是相同的。但实际情况中这种情况并不多见。
例如在做一个多表的join关联查询时，服务器必须要扫描多行才能生成结果集中的一行。扫描的行数对返回的行数的比率通常很小，一般在1：1和10：1之间，不过有时候这个值也可能非常非常大。
比值越大则意味着查询效率越低，因为引擎执行扫描出的大部分数据行都会被丢弃，这也意味着需要执行更多的I/O操作，因此尽可能降低扫描的行数对返回的行数的比率，是我们对慢查询优化的关键所在。
一般MySQL能够使用如下三种方式应用where条件，从好到坏依次为：
Extra中Using Index与Using Where，MySQL官方文档的解释如下：
Using Index
The column information is retrieved from the table using only information in the index tree without having to do an additional seek to read the actual row. This strategy can be used when the query uses only columns that are part of a single index.
Using Where
A WHERE clause is used to restrict which rows to match against the next table or send to the client. Unless you specifically intend to fetch or examine all rows from the table, you may have something wrong in your query if the Extra value is not Using where and the table join type is ALL or index.
使用explain判断导致查询慢的原因，判断依据可以根据如下几点：
综上我们总结，SQL执行时其扫描的行数决定了执行的效率，而决定扫描行数的关键，则是索引的命中情况与索引的质量。
Tips：关于索引的一些小建议
4.PROFILE分析
通过使用explain分析SQL的执行计划，我们可以看到SQL执行过程中是否使用索引，使用了哪些索引，索引扫描的行数等，但MySQL的慢查询，并不一定慢在有没有索引，SQL的执行环节中任意一环出了问题都会表现为查询变慢，所以即使执行过程命中了索引，explain的结果也很完美，但是还是慢，怎么办？
这时候，就需要profile工具来帮忙了，这个命令可以详细列出SQL语句在每一个步骤消耗的时间，前提（缺点）是先执行一遍语句。
PROFILE默认是关闭的，所以需要在client端先打开，操作如下：
set session profiling = 1;
在实际的生产环境中，可能会需要加大profile的队列，保证想要查看的profile结果还保存着，因此可以用如下操作来增加profile的队列大小：
set session profiling_history_size = 50;
让我们一起来看一下profile分析如何使用，我们先执行下面的SQL：
mysql> explain select * from user where name = '小六' and code = 300000003;
+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+
id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+
1 | SIMPLE | user | NULL | ALL | NULL | NULL | NULL | NULL | 2043040 | 1.00 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+------+---------+----------+-------------+
1 row in set, 1 warning (0.00 sec)
这个一个典型的效果较差的查询，type=ALL，没有命中索引，执行了全表扫描，我们使用profile分析一下各阶段的执行时间：
mysql> show profiles;
+----------+------------+---------------------------------------------------------------+
Query_ID | Duration | Query |
+----------+------------+---------------------------------------------------------------+
1 | 0.55695825 | select * from user where name = '小六' and code = 300000003 |
+----------+------------+---------------------------------------------------------------+
1 row in set, 1 warning (0.00 sec)
找到我们需要分析的语句，查询执行耗时详情：
mysql> show profile block io,cpu,memory,source for query 1;
profile执行耗时详情
从profile执行结果中，我们可以清晰的看到一条SQL在每个执行阶段的耗时、CPU使用率、IO等指标，帮助我们定位到慢查询具体执行耗时的阶段，对于该条SQL，执行过程中最耗时的部分是executing部分，executing阶段包括了执行线程正在为SELECT读取和处理数据行，并将数据发送到客户端。
因为在这个状态下发生的操作往往执行大量的磁盘读取，所以它往往是在整个查询的生命周期中运行时间最长的一个阶段。
经过了对SQL语句进行explain与profile分析之后，一个SQL为什么慢，慢在哪里基本上可以定位出来了，那么最后的手段主要是解决什么问题呢？
我们将使用最终的分析工具，OPTIMIZER_TRACE。
5.OPTIMIZER_TRACE分析
OPTIMIZER_TRACE是MySQL 5.6添加的新功能，这个功能可以看到内部查询计划的TRACE信息，也就是MySQL在执行过程中的具体决策细节，从而可以知道MySQL是如何在众多索引中的挑选最合适的索引。
如果我们通过执行计划，发现MySQL选择的索引并不符合我们的预期，就需要根据OPTIMIZER_TRACE的信息来判断为什么会选择它，是MySQL的配置原因，还是SQL某些地方写的不好导致MySQL误判。
开启这个功能的方式如下：
set session optimizer_trace='enabled=on';
在客户端执行一个EXPLAIN语句，生成一个执行计划，然后在information_chema.optimizer_trace的表里面查找这一条语句对应的信息：
mysql> select * from information_schema.optimizer_trace;
explain select * from user where age = 21 | {
"steps": [
{
"join_preparation": {
"select#": 1,
"steps": [
{
"expanded_query": "/* select#1 */ select `user`.`id` AS `id`,`user`.`name` AS `name`,`user`.`age` AS `age`,`user`.`code` AS `code` from `user` where (`user`.`age` = 21)"
}
]
}
},
{
"join_optimization": {
"select#": 1,
"steps": [
{
"condition_processing": {
"condition": "WHERE",
"original_condition": "(`user`.`age` = 21)",
"steps": [
{
"transformation": "equality_propagation",
"resulting_condition": "multiple equal(21, `user`.`age`)"
},
{
"transformation": "constant_propagation",
"resulting_condition": "multiple equal(21, `user`.`age`)"
},
{
"transformation": "trivial_condition_removal",
"resulting_condition": "multiple equal(21, `user`.`age`)"
}
]
}
},
{
"substitute_generated_columns": {
}
},
{
"table_dependencies": [
{
"table": "`user`",
"row_may_be_null": false,
"map_bit": 0,
"depends_on_map_bits": [
]
}
]
},
{
"ref_optimizer_key_uses": [
{
"table": "`user`",
"field": "age",
"equals": "21",
"null_rejecting": true
}
]
},
{
"rows_estimation": [
{
"table": "`user`",
"range_analysis": {
"table_scan": {
"rows": 2043040,
"cost": 205676
},
"potential_range_indexes": [
{
"index": "PRIMARY",
"usable": false,
"cause": "not_Applicable"
},
{
"index": "idx_age",
"usable": true,
"key_parts": [
"age",
"id"
]
}
],
"setup_range_conditions": [
],
"group_index_range": {
"chosen": false,
"cause": "not_group_by_or_distinct"
},
"skip_scan_range": {
"potential_skip_scan_indexes": [
{
"index": "idx_age",
"usable": false,
"cause": "query_references_nonkey_column"
}
]
},
"analyzing_range_alternatives": {
"range_scan_alternatives": [
{
"index": "idx_age",
"ranges": [
"21 <= age <= 21"
],
"index_dives_for_eq_ranges": true,
"rowid_ordered": true,
"using_mrr": false,
"index_only": false,
"in_memory": 0.788627,
"rows": 1,
"cost": 0.61,
"chosen": true
}
],
"analyzing_roworder_intersect": {
"usable": false,
"cause": "too_few_roworder_scans"
}
},
"chosen_range_access_summary": {
"range_access_plan": {
"type": "range_scan",
"index": "idx_age",
"rows": 1,
"ranges": [
"21 <= age <= 21"
]
},
"rows_for_plan": 1,
"cost_for_plan": 0.61,
"chosen": true
}
}
}
]
},
{
"considered_execution_plans": [
{
"plan_prefix": [
],
"table": "`user`",
"best_access_path": {
"considered_access_paths": [
{
"access_type": "ref",
"index": "idx_age",
"rows": 1,
"cost": 0.35,
"chosen": true
},
{
"access_type": "range",
"range_details": {
"used_index": "idx_age"
},
"chosen": false,
"cause": "heuristic_index_cheaper"
}
]
},
"condition_filtering_pct": 100,
"rows_for_plan": 1,
"cost_for_plan": 0.35,
"chosen": true
}
]
},
{
"attaching_conditions_to_tables": {
"original_condition": "(`user`.`age` = 21)",
"attached_conditions_computation": [
],
"attached_conditions_summary": [
{
"table": "`user`",
"attached": "(`user`.`age` = 21)"
}
]
}
},
{
"finalizing_table_conditions": [
{
"table": "`user`",
"original_table_condition": "(`user`.`age` = 21)",
"final_table_condition ": null
}
]
},
{
"refine_plan": [
{
"table": "`user`"
}
]
}
]
}
},
{
"join_explain": {
"select#": 1,
"steps": [
]
}
}
]
}
1 row in set (0.02 sec)
内容是非常长的 JSON格式，所以推荐把结果转存到其他地方，然后用JSON的转换工具来辅助查看，如果要看索引的选择情况，就重点关注这个JSON的ref_optimizer_key_uses，rows_estimation及之后的部分，这里会展示索引选择相关的信息，截取一部分结果作为示例：
{
"ref_optimizer_key_uses": [
{
"table": "`user`",
"field": "age",
"equals": "21",
"null_rejecting": true
}
]
}
"chosen_range_access_summary": {
"range_access_plan": {
"type": "range_scan",
"index": "idx_age",
"rows": 1,
"ranges": [
"21 <= age <= 21"
]
},
"rows_for_plan": 1,
"cost_for_plan": 0.61,
"chosen": true
}
chosen_range_access_summary部分的含义是在前一个步骤中分析了各类索引使用的方法及代价，得出了一定的中间结果之后，在summary阶段汇总前一阶段的中间结果确认最后的方案。
OPTIMIZER_TRACE的核心是在跟踪记录TRACE的JSON树，通过这棵树中的内容可以具体去分析优化器究竟做了什么事情，进行了哪些选择，是基于什么原因做的选择，选择的结果及依据。这一系列都可以辅助验证我们的一些观点及优化，更好的帮助我们对我们的数据库的实例进行调整。
由于OPTIMIZER_TRACE的内容非常复杂，本文由于篇幅的关系，无法在此对于每一个字段进行详细的解读，感兴趣的读者，可以参考MySQL官方文档对于OPTIMIZER_TRACE的解读。
三、引擎参数配置分析
上面的篇幅中，我们针对SQL层面进行了可能导致慢查询的原因分析，MySQL的数据最终都会存储在磁盘上，因此操作系统的I/O情况也会影响MySQL的运行性能，这一章节我们将从底层入手，从操作系统I/O层面分析MySQL执行性能问题。
1.I/O性能分析
linux系统查看 系统I/O情况，可以使用IOStat命令：
[root@VM-16-14-centos ~]# iostat -x 1 -m
Linux 3.10.0-1160.11.1.el7.x86_64 (VM-16-14-centos) 12/21/2022 _x86_64_ (1 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
0.82 0.00 0.67 0.07 0.00 98.44
Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
vda 0.00 1.67 0.04 2.49 0.00 0.02 17.55 0.01 2.34 3.74 2.31 0.29 0.07
scd0 0.00 0.00 0.00 0.00 0.00 0.00 7.10 0.00 0.89 0.89 0.00 0.88 0.00
avg-cpu自然就是CPU相关的指标，判断IO问题时可以关注%iowait，其他指标的意义如下：
一般来说，评价一块IO设备（忽略机械盘的情况，没有评价的意义）是否达到了高负载情况，可以看这几个指标：r/s，w/s，rMB/s，wMB/s，r_await，w_await，avgqu-sz。
2.MySQL I/O参数
MySQL涉及到IO相关的参数会比较多，因此这里仅一部分经常用到的参数：
innodb_io_capacity和innodb_io_capacity_max是最直接限制IOPS的指标，大多数时候，SSD 可以设置成16000或者更高的数值，如果是云主机或者其他的共享存储设备，则需要了解一下详细的IOPS上限再具体调整。
trx_commit和 sync_binlog这两个参数也放进来的原因是不同的参数组合对 IO的压力也会有区别。
通常的用法是双 1或者20（二零），参考官方文档的描述，双 1 在每次提交事务的时候都会刷盘，对IO的压力要高不少；
20 则是滞后刷盘，对IO的压力会较小，因此写入QPS会高一些。
另外，可以关注到一个细节，innodb_io_capacity的描述对象是：后台任务。这代表着 MySQL后台的 flush，purge操作会受到这个参数设置的限制。
吞吐量和IOPS，一般情况下衡量IO系统性能最直观的指标，并没有特别的提及，主要原因还是判断起来很简单：如果iostat的指标已经达到或者接近了实际硬件的指标（比如达到了 75%），那么根据业务量增长的情况及早规划硬件升级或者其他手段来分散读写压力。
常规的手段，可以简单的遵循以下场景来酌情使用：读多写少读写分离，写多读少拆库拆表加缓存。
四、其他原因分析
1.网络抖动
目前的互联网应用服务，数据库的部署与应用服务的部署，不会在一台服务器上，那么应用服务器与数据库服务器之间就需要通过网络通信，一般情况来讲，都会在同机房或同一个可用区进行部署，以保证网络通信的质量。
但是难免可能会出现网络抖动的情况，这种情况下，对应用服务来讲，可能会出现一条SQL执行较慢的情况，但不是由于数据库原因导致的，而是由于网络原因导致的。
发现偶现的SQL执行慢，且SQL本身执行计划没有问题，可以从网络的角度分析问题，在服务所在的机器ping数据库服务器，查看响应时间，特别针对数据库服务器与业务服务器跨城市的情况，如果没有拉通专线访问，会很容易出现网络慢导致的问题。
2.单表数据量过大
上面我们提到了InnoDB的数据存储方式是面向主键索引进行数据存储的。InnoDB的数据表数量级超过几千万后，性能会出现下降，核心是由于B+Tree的数据结构导致的。
因此，当你的数据表超过几千万量级的时候，SQL执行即使全部命中的索引，也有可能出现执行慢的情况。
这个时候，建议考虑采用拆表。目前开源的优秀的分库分表中间件有很多，例如sharing-JDBC、MyCat等，可以根据业务的实际情况进行选择，这里就不过多的进行赘述。
总结
本篇，我们围绕着一个问题：一条SQL执行较慢可能有哪些原因导致的？进行了研究，总结一下，大部分的慢查询其实均由SQL书写不当导致的，通过explain命令结合实际业务场景分析，可以解决绝大多数的慢查询问题，对于一些疑难杂症SQL，使用MySQL强大的SQL分析工具，也可以找出真正的问题原因。
另外，系统层面的分析也是必不可少的，作为开发人员，我们也需要掌握一些DBA的分析手段，检查MySQL运行性能情况，保证数据库服务的稳定运行。
>>>>参考资料
作者丨狐友宣光耀
来源丨公众号：搜狐技术产品（ID：sohu-tech）
京公网安备 11010802035086号