前言
数据库查询快慢是影响项目性能的一大因素,对于数据库,我们除了要优化 SQL,更重要的是得先找到需要优化的 SQL。MySQL 数据库有一个“慢查询日志”功能,用来记录查询时间超过某个设定值的SQL,这将极大程度帮助我们快速定位到症结所在,以便对症下药。
什么是慢查询
慢查询日志,顾名思义,就是查询慢的日志,是指mysql记录所有执行超过long_query_time参数设定的时间阈值的SQL语句的日志。该日志能为SQL语句的优化带来很好的帮助。默认情况下,慢查询日志是关闭的,要使用慢查询日志功能,首先要开启慢查询日志功能。
慢查询基本配置
slow_query_log
启动停止慢查询日志。
slow_query_log_file
指定慢查询日志得存储路径及文件(默认和数据文件放一起)。
long_query_time
指定记录慢查询日志SQL执行时间得阈值(单位:秒,默认10秒)。
log_queries_not_using_indexes
是否记录未使用索引的SQL。
log_output
日志存放的地方【TABLE】【FILE】【FILE,TABLE】。
配置了慢查询后,它会记录符合条件的SQL。包括:
- 查询语句
- 数据修改语句
- 已经回滚得SQL
show VARIABLES like '%slow_query_log%'
show VARIABLES like '%slow_query_log_file%'
show VARIABLES like '%long_query_time%'
show VARIABLES like '%log_queries_not_using_indexes%'
show VARIABLES like 'log_output'
开启慢查询
MySQL的慢查询日志功能,默认是关闭的,需要手动开启。
临时开启慢查询功能
在 MySQL 执行 SQL 语句设置,但是如果重启 MySQL 的话将失效。
查看是否开启慢查询功能
show VARIABLES like '%slow_query_log%'
开启慢查询与设置超时参数
set global slow_query_log = ON;
set global long_query_time = 1;
永久开启慢查询功能
修改/etc/my.cnf配置文件,重启 MySQL, 这种永久生效。
[mysqld]
slow_query_log = ON
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
慢查询日志解读
从慢查询日志里面摘选一条慢查询日志,数据组成如下:
# Time: 190512 18:46:25
# User@Host: root[root] @ [202.105.151.121] Id: 16869
# Query_time: 14.436060 Lock_time: 0.000102 Rows_sent: 238 Rows_examined: 238
use pmcenter;
SET timestamp=1557657985;
select * from `pmcenter`.`sys_operation_log` limit 0,1000;
格式说明:
第一行:SQL查询执行的时间。
第二行:执行SQL查询的连接信息,用户名 、用户的IP信息、线程ID号。
第三行:记录了一些我们比较有用的信息,如下。
- Query_time,这条SQL执行的时间,越长则越慢;
- Lock_time,在MySQL服务器阶段(不是在存储引擎阶段)等待表锁时间;
- Rows_sent,查询返回的行数;
- Rows_examined,查询检查的行数,越长就当然越费时间。
第四行,应用的数据库。
第五行,设置时间戳,没有实际意义,只是和第一行对应执行时间。
第六行,及后面所有行(第二个# Time:之前),执行的sql语句记录信息,因为sql可能会很长。
慢查询分析
慢查询的日志记录非常多,要从里面找寻一条查询慢的日志并不是很容易的事情,一般来说都需要一些工具辅助才能快速定位到需要优化的SQL语句,下面介绍两个慢查询辅助工具。
Mysqldumpslow
常用的慢查询日志分析工具,汇总除查询条件外其他完全相同的SQL,并将分析结果按照参数中所指定的顺序输出。
语法:
mysqldumpslow -s r -t 10 slow-mysql.log
-s order (c,t,l,r,at,al,ar)
c:总次数
t:总时间
l:锁的时间
r:总数据行
at,al,ar :t,l,r平均数 【例如:at = 总时间/总次数】
-t top 指定取前面几天作为结果输出
示例:
mysqldumpslow -s c -t 10 /var/lib/mysql/iz2zeb0r3wwhspv7w8emgtz-slow.log
Reading mysql slow query log from /var/lib/mysql/iz2zeb0r3wwhspv7w8emgtz-slow.log
Count: 1 Time=14.44s (14s) Lock=0.00s (0s) Rows=238.0 (238), root[root]@[202.105.151.121]
select * from `pmcenter`.`sys_operation_log` limit N,N
注:这是单独的工具
linux -> /usr/bin/mysqldumpslow
windows mysql\scripts\mysqldumpslow.pl
Percona-toolkit工具
percona-toolkit是一组高级命令行工具的集合,可以查看当前服务的摘要信息,磁盘检测,分析慢查询日志,查找重复索引,实现表同步等等。
下载
安装
tar -zxvf percona-toolkit-3.0.11_x86_64.tar.gz -C /app
cd /app/percona-toolkit-3.0.11
perl Makefile.PL
make
make install
报错
Can't locate ExtUtils/MakeMaker.pm in @INC (@INC contains: /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5 .) at Makefile.PL line 1.
错误解决
yum install -y perl-Time-HiRes
yum install perl-ExtUtils-CBuilder perl-ExtUtils-MakeMaker
yum -y install perl-Digest-MD5
使用pt-query-digest查看慢查询日志
pt-query-digest /var/lib/mysql/iz2zeb0r3wwhspv7w8emgtz-slow.log
# Files: /var/lib/mysql/iz2zeb0r3wwhspv7w8emgtz-slow.log
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2019-05-12 18:46:25
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 14s 14s 14s 14s 14s 0 14s
# Lock time 102us 102us 102us 102us 102us 0 102us
# Rows sent 238 238 238 238 238 0 238
# Rows examine 238 238 238 238 238 0 238
# Query size 58 58 58 58 58 0 58
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== ================================== ============== ===== ======= ===
# 1 0xACA4F145E7369BD42032C949AAF8717A 14.4361 100.0% 1 14.4361 0.00 SELECT pmcenter.sys_operation_log
# Query 1: 0 QPS, 0x concurrency, ID 0xACA4F145E7369BD42032C949AAF8717A at byte 0
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-05-12 18:46:25
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 100 1
# Exec time 100 14s 14s 14s 14s 14s 0 14s
# Lock time 100 102us 102us 102us 102us 102us 0 102us
# Rows sent 100 238 238 238 238 238 0 238
# Rows examine 100 238 238 238 238 238 0 238
# Query size 100 58 58 58 58 58 0 58