MySQL慢SQL优化思路
具体思路:
1、慢查询日志记录慢 SQL
2、explain 分析 SQL 的执行计划
3、profile 分析执行耗时
4、Optimizer Trace 分析详情
5、确定问题并采用相应的措施
1、查看慢日志
1.1 使用命令查询慢日志配置
mysql> show variables like 'slow_query_log%';
+---------------------+---------------------------------------------------------------------+
| Variable_name | Value |
+---------------------+---------------------------------------------------------------------+
| slow_query_log | OFF |
| slow_query_log_file | C:\ProgramData\MySQL\MySQL Server 5.5\Data\DESKTOP-CR3IL33-slow.log |
+---------------------+---------------------------------------------------------------------+
2 rows in set (0.00 sec)
slow_query_log
:表示慢查询开启的状态。slow_query_log_file
:表示慢查询日志存放的位置。
1.2 使用命令查看超过多少时间才记录到慢查询日志
mysql> show variables like 'long_query_time';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)
long_query_time
:表示查询超过多少秒才记录到慢查询日志。
1.3 查看是否开启记录未使用索引sql慢查询日志
-- 默认是关闭的
mysql> show variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF |
+-------------------------------+-------+
1 row in set (0.00 sec)
1.4 启用慢日志
-- 启用慢查询,加上global,不然会报错的
mysql> set global slow_query_log='ON';
Query OK, 0 rows affected (0.01 sec)
-- 是否开启慢查询
mysql> show variables like 'slow_query_log%';
+---------------------+---------------------------------------------------------------------+
| Variable_name | Value |
+---------------------+---------------------------------------------------------------------+
| slow_query_log | ON |
| slow_query_log_file | C:\ProgramData\MySQL\MySQL Server 5.5\Data\DESKTOP-CR3IL33-slow.log |
+---------------------+---------------------------------------------------------------------+
2 rows in set (0.00 sec)
1.5 修改慢查询时间
-- 修改慢查询时间
mysql> set global long_query_time=2;
Query OK, 0 rows affected (0.00 sec)
-- 查看慢查询时间阈值
mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 2.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
-- 修改了慢查询日志马上用上述命令查看发现不生效,其实已经修改成功,可以用下面的命令
mysql> show global variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 2.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
1.6 开启记录未使用索引sql慢查询日志
-- 开启
mysql> set global log_queries_not_using_indexes=1;
Query OK, 0 rows affected (0.00 sec)
-- 查询
mysql> show variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON |
+-------------------------------+-------+
1 row in set (0.00 sec)
1.7 永久生效
上面的操作并不是永久开启慢查询日志,如果要永久生效,就必须修改配置文件 my.cnf
或 my.ini
,在该文件
中,找到或在 [mysqld]
部分下添加以下内容,然后保存文件并重启 MySQL 服务。
# 开启慢查询日志
slow_query_log=1
# 指定慢查询日志生成文件所在路径
slow_query_log_file=D:\OwnerSoftwareInstall\MySQL\zsx-slow.log
# 设置慢查询时间阈值
long_query_time=2
# 开启记录未使用索引sql慢查询日志
log_queries_not_using_indexes=1
# 日志输出方式为文件
log_output=FILE
-- 查看
mysql> show variables like 'slow_query_log%';
+---------------------+--------------------------------------------+
| Variable_name | Value |
+---------------------+--------------------------------------------+
| slow_query_log | ON |
| slow_query_log_file | D:\OwnerSoftwareInstall\MySQL\zsx-slow.log |
+---------------------+--------------------------------------------+
2 rows in set (0.00 sec)
1.8 定位慢查询
看看mysql从启动到现在,mysql数据库的一些运行状态:
mysql> flush status;
Query OK, 0 rows affected (0.00 sec)
-- 从启动到现在执行select次数
mysql> show global status like 'com_select';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_select | 3 |
+---------------+-------+
1 row in set (0.00 sec)
-- 当前session里执行select次数,session可以不加
mysql> show session status like 'com_select';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_select | 1 |
+---------------+-------+
1 row in set (0.00 sec)
-- 从启动到现在执行update次数
mysql> show global status like 'com_update';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_update | 0 |
+---------------+-------+
1 row in set (0.00 sec)
-- 当前session里执行update次数,session可以不加
mysql> show session status like 'com_update';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_update | 0 |
+---------------+-------+
1 row in set (0.00 sec)
-- 从启动到现在执行delete次数
mysql> show global status like 'com_delete';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_delete | 0 |
+---------------+-------+
1 row in set (0.00 sec)
-- 当前session里执行delete次数,session可以不加
mysql> show session status like 'com_delete';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Com_delete | 0 |
+---------------+-------+
1 row in set (0.00 sec)
-- 从开启慢查询日志开始到现在有多少条慢查询记录
mysql> show global status like '%slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries | 1 |
+---------------+-------+
1 row in set (0.00 sec)
1.9 使用mysqldumpslow工具分析慢查询
日志分析工具mysqldumpslow,mysql官方自带的,只要安装了mysql就可以使用它,可以用来帮助我们分析慢
日志文件。
# 指定慢查询日志进行分析
# 查询执行时间最长的前10
$ perl mysqldumpslow.pl -s t -a -t 10 D:\OwnerSoftwareInstall\MySQL\zsx-slow.log
$ perl mysqldumpslow.pl --help
Locale 'Chinese (Simplified)_China.936' is unsupported, and may crash the interpreter.
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
Parse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default
al: average lock time
ar: average rows sent
at: average query time
c: count
l: lock time
r: rows sent
t: query time
-r reverse the sort order (largest last instead of first)
-t NUM just show the top n queries
-a don't abstract all numbers to N and strings to 'S'
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '*', i.e. match all
-i NAME name of server instance (if using mysql.server startup script)
-l don't subtract lock time from total time
参数选项 | 使用说明 |
---|---|
-a | 显示具体的数字和字符信息,而不是用N或者S代替 |
-n | 将数字抽象显示为指定的数字个数 |
–debug | -d | 指定debug模式运行 |
-g | 指定大小写不敏感的正则表达 |
–help | 显示帮助信息 |
-h | 指定MySQL主机名称用于选择慢查询日志 |
-i | 指定服务器示例名称用于选择慢查询日志 |
-l | 显示总时间(包括lock锁定时间) |
-r | 逆序排序 |
-s | 指定排序方式 |
-t | 只显示指定数量的结果内容 |
–verbose | -v | Verbose模式 |
使用-s指定排序方式,主要有如下四种方式:
- l: 按锁定时间排序
- r: 按结果行数排序
- t: 按查询时间排序
- c:按执行次数排序
a为平均,与上述参数结合可形成新的排序方式:
- at:按平均查询时间排序(默认排序方式)
- al:按平均锁定时间排序
- ar:按平均结果行数排序
# 返回执行次数最高的前10条sql
$ perl mysqldumpslow.pl -s c -a -t 10 D:\OwnerSoftwareInstall\MySQL\zsx-slow.log
# 返回结果行数最多的前10条sql
$ perl mysqldumpslow.pl -s r -a -t 10 D:\OwnerSoftwareInstall\MySQL\zsx-slow.log
# 返回执行时间最长的前10条sql
$ perl mysqldumpslow.pl -s t -a -t 10 D:\OwnerSoftwareInstall\MySQL\zsx-slow.log
分析后结果参数解读
- Count:代表这个 SQL 语句执行了多少次
- Time:代表执行的时间,括号是累计时间
- Lock:表示锁定的时间,括号是累计时间
- Rows:表示返回的记录数,括号是累计记录数
2、explain 分析 SQL 的执行计划
mysql> explain select * from student;
+----+-------------+---------+------+---------------+------+---------+------+------+-------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+----+-------------+---------+------+---------------+------+---------+------+------+-------+
| 1 | SIMPLE | student | ALL | NULL | NULL | NULL | NULL | 7 | |
+----+-------------+---------+------+---------------+------+---------+------+------+-------+
1 row in set (0.00 sec)
type=all 代表进行了全表扫描。
3、show profile分析
了解SQL执行的线程的状态及消耗的时间。
profiling 默认是关闭,我们可以使用命令查看是否开启:
-- 未开启
mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES |
| profiling | OFF |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.00 sec)
-- 开启
mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES |
| profiling | ON |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.00 sec)
-- 默认是关闭的,开启语句set profiling = 1;也可以使用set profiling=ON;开启
mysql> set profiling =1;
Query OK, 0 rows affected (0.00 sec)
-- 执行SQL
mysql> select * from student;
+----+-------+
| id | name |
+----+-------+
| 1 | John |
| 2 | tom |
| 3 | marry |
| 6 | marry |
| 7 | tom |
| 10 | marry |
| 11 | tom |
+----+-------+
7 rows in set (0.00 sec)
-- 可以看到实际的执行语句
mysql> show profiles;
+----------+------------+-----------------------+
| Query_ID | Duration | Query |
+----------+------------+-----------------------+
| 1 | 0.00017550 | select * from student |
+----------+------------+-----------------------+
1 row in set (0.00 sec)
show profiles
会显示最近发给服务器的多条语句,条数由变量 profiling_history_size
定义,默认是15。
如果我们需要看单独某条SQL的分析,可以show profile
查看最近一条SQL的分析,也可以使用show profile
for query id
(其中id就是show profiles中的QUERY_ID)查看具体一条的SQL语句分析。
mysql> show profiles;
+----------+------------+-----------------------+
| Query_ID | Duration | Query |
+----------+------------+-----------------------+
| 1 | 0.00017550 | select * from student |
+----------+------------+-----------------------+
1 row in set (0.00 sec)
mysql> show profile for query 1;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000024 |
| checking permissions | 0.000003 |
| Opening tables | 0.000015 |
| System lock | 0.000004 |
| init | 0.000008 |
| optimizing | 0.000002 |
| statistics | 0.000005 |
| preparing | 0.000004 |
| executing | 0.000001 |
| Sending data | 0.000033 |
| end | 0.000002 |
| query end | 0.000002 |
| closing tables | 0.000003 |
| freeing items | 0.000025 |
| logging slow query | 0.000001 |
| logging slow query | 0.000044 |
| cleaning up | 0.000002 |
+----------------------+----------+
17 rows in set (0.00 sec)
除了查看 profile ,还可以查看 cpu 和 io:
mysql> show profile cpu,block io for query 1;
+----------------------+----------+----------+------------+--------------+---------------+
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting | 0.000024 | 0.000000 | 0.000000 | NULL | NULL |
| checking permissions | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| Opening tables | 0.000015 | 0.000000 | 0.000000 | NULL | NULL |
| System lock | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| init | 0.000008 | 0.000000 | 0.000000 | NULL | NULL |
| optimizing | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| statistics | 0.000005 | 0.000000 | 0.000000 | NULL | NULL |
| preparing | 0.000004 | 0.000000 | 0.000000 | NULL | NULL |
| executing | 0.000001 | 0.000000 | 0.000000 | NULL | NULL |
| Sending data | 0.000033 | 0.000000 | 0.000000 | NULL | NULL |
| end | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| query end | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
| closing tables | 0.000003 | 0.000000 | 0.000000 | NULL | NULL |
| freeing items | 0.000025 | 0.000000 | 0.000000 | NULL | NULL |
| logging slow query | 0.000001 | 0.000000 | 0.000000 | NULL | NULL |
| logging slow query | 0.000044 | 0.000000 | 0.000000 | NULL | NULL |
| cleaning up | 0.000002 | 0.000000 | 0.000000 | NULL | NULL |
+----------------------+----------+----------+------------+--------------+---------------+
17 rows in set (0.00 sec)
4、Optimizer Trace分析详情(mysql 5.6 及以上版本)
profile 只能查看到 SQL 的执行耗时,但是无法看到 SQL 真正执行的过程信息,即不知道 MySQL 优化器是如何选
择执行计划。这时候,我们可以使用Optimizer Trace
,它可以跟踪执行语句的解析优化执行的全过程。
-- 第一步打开trace,设置格式为JSON格式
mysql> set session optimizer_trace="enabled=on",end_markers_in_json=ON;
Query OK, 0 rows affected (0.00 sec)
-- 设置优化器跟踪使用的最大内存量
mysql> set session optimizer_trace_max_mem_size=1000000;
Query OK, 0 rows affected (0.00 sec)
-- 查看
mysql> show session variables like 'optimizer_trace';
+-----------------+-------------------------+
| Variable_name | Value |
+-----------------+-------------------------+
| optimizer_trace | enabled=on,one_line=off |
+-----------------+-------------------------+
1 row in set (0.00 sec)
-- 第二步,执行要分析的sql语句
mysql> select * from student;
+----+-------+
| id | name |
+----+-------+
| 1 | John |
| 2 | tom |
| 3 | marry |
| 6 | marry |
| 7 | tom |
| 10 | marry |
| 11 | tom |
+----+-------+
7 rows in set (0.00 sec)
-- 第三步,查看information_schema.OPTIMIZER_TRACE,查看sql语句执行跟踪记录
mysql> select * from information_schema.optimizer_trace;
+-----------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------+-------------------------+
| QUERY | TRACE | MISSING_BYTES_BEYOND_MAX_MEM_SIZE | INSUFFICIENT_PRIVILEGES |
+-----------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------+-------------------------+
| select * from student | {
"steps": [
{
"join_preparation": {
"select#": 1,
"steps": [
{
"expanded_query": "/* select#1 */ select `student`.`id` AS `id`,`student`.`name` AS `name` from `student`"
}
] /* steps */
} /* join_preparation */
},
{
"join_optimization": {
"select#": 1,
"steps": [
{
"table_dependencies": [
{
"table": "`student`",
"row_may_be_null": false,
"map_bit": 0,
"depends_on_map_bits": [
] /* depends_on_map_bits */
}
] /* table_dependencies */
},
{
"rows_estimation": [
{
"table": "`student`",
"table_scan": {
"rows": 7,
"cost": 0.25
} /* table_scan */
}
] /* rows_estimation */
},
{
"considered_execution_plans": [
{
"plan_prefix": [
] /* plan_prefix */,
"table": "`student`",
"best_access_path": {
"considered_access_paths": [
{
"rows_to_scan": 7,
"access_type": "scan",
"resulting_rows": 7,
"cost": 0.95,
"chosen": true
}
] /* considered_access_paths */
} /* best_access_path */,
"condition_filtering_pct": 100,
"rows_for_plan": 7,
"cost_for_plan": 0.95,
"chosen": true
}
] /* considered_execution_plans */
},
{
"attaching_conditions_to_tables": {
"original_condition": null,
"attached_conditions_computation": [
] /* attached_conditions_computation */,
"attached_conditions_summary": [
{
"table": "`student`",
"attached": null
}
] /* attached_conditions_summary */
} /* attaching_conditions_to_tables */
},
{
"finalizing_table_conditions": [
] /* finalizing_table_conditions */
},
{
"refine_plan": [
{
"table": "`student`"
}
] /* refine_plan */
}
] /* steps */
} /* join_optimization */
},
{
"join_execution": {
"select#": 1,
"steps": [
] /* steps */
} /* join_execution */
}
] /* steps */
} | 0 | 0 |
+-----------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------+-------------------------+
1 row in set (0.00 sec)
-- 第四步,关闭trace。
mysql> set session optimizer_trace="enabled=off";
Query OK, 0 rows affected (0.00 sec)
-- 查看
mysql> show session variables like 'optimizer_trace';
+-----------------+--------------------------+
| Variable_name | Value |
+-----------------+--------------------------+
| optimizer_trace | enabled=off,one_line=off |
+-----------------+--------------------------+
1 row in set (0.00 sec)
可以查看分析其执行树,会包括三个阶段:
- join_preparation:准备阶段
- join_optimization:分析阶段
- join_execution:执行阶段
5、确定问题并采用相应的措施
根据上面4个步骤的分析结果进行相应的优化。