MySQL运维09-慢查询日志
文章目录
1、慢查询日志的配置与开启
1.1、慢查询日志的配置与开启
- 修改配置文件/etc/my.cnf如下参数，可以开启慢查询，参数修改后需要重启后才可以生效。
- slow_query_log：设置为1表示开启慢查询日志，设置为0则表示关闭慢查询日志。
- long_query_time的单位为秒，默认的2s阈值太大，建议设置为0.2-0.5秒。MySQL5.1.21后可以设置毫秒级的慢查询记录，如设置long_query_time=0.01。
- log-queries-not-using-indexes：用于指定如果没有使用到索引或虽然使用了索引但仍然遍历了所有记录，就将其记录到慢查询日志。默认此选项是关闭的。
[mysqld]
……
slow_query_log=1
long_query_time=0.5
#slow_query_log_file=/usr/local/mysql/log/slowquery.log # 一般可以不设置
……
- MySQL可以把慢查询日志记录到数据表内，但更普遍的做法是记录到日志里，然后使用工具来分析。
1.2、如何确认慢查询日志已开启及查找日志位置
- 以下命令将查看慢查询是否启用及慢查询日志路径。如果配置文件或启动参数设置日志文件名，慢查询日志将被默认命名为“主机名-slow.log”，如果给出了文件名，但不是绝对路径名，文件则写入数据目录。
mysql> show variables like'%query_log%';
- 使用命令“SHOW VARIABLES LIKE’%query_time%'”查看全局变量long_query_time。
mysql> SHOW VARIABLES LIKE‘%query_time%’;
2、慢查询日志的解析方法
2.1、慢查询日志的格式
如下是一条慢查询日志的示例：
对日志中的字段解释如下：
- Time：执行SQL的开始时间。
- User@Host：执行查询的用户和客户端IP。
- Query_time：查询耗时。
- Lock_time：等待table lock的时间，注意InnoDB的行锁等待是不会反应在这里的。
- Rows_sent：返回了多少行记录（结果集）。
- Rows_examined：检查了多少条记录。
2.2、如何衡量查询成本
- Query_time、Rows_examined、Rows_sent这3个值可以大致衡量一条查询的成本。
- 如果检查了大量记录（Rows_examined大），而只返回很小的结果集（Rows_sent小，Rows_sent与Rows_examined的比值小），则往往意味着查询质量不佳。
2.3、慢查询不一定是不良SQL
慢查询日志里的慢查询不一定就是不良SQL，还可能是受其他的查询影响，或者受系统资源限制所导致的慢查询。比如下面的例子，会话被阻塞了，实际上是一个行锁等待50s超时，然后记录到了慢查询日志里。
3、慢查询日志的解析
一般常用有两种方式进行慢查询日志的解析：
- mysqldumpslow命令：用于获得慢查询日志摘要来处理慢查询日志
- 第三方工具pt-query-digest
3.1、mysqldumpslow
mysqldumpslow命令是官方自带的，此命令可获得日志中的查询摘要。如下是一些常用的mysqldumpslow应用场景：
- 访问时间最长的10个sql语句
mysqldumpslow -t 10 /home/mysql/localhost-slow.log
- 访问次数最多的10个sql语句
mysqldumpslow -s c -t 10 /home/mysql/localhost-slow.log
- 访问记录集最多的10个sql语句
mysqldumpslow -s r -t 10 /home/mysql/localhost-slow.log
3.2、使用pt-query-digest解析慢查询日志
3.2.1、Centos7下安装percona-tools
pt-query-digest是被包含在percona-tools，所以要想使用pt-query-digest，需要安装percona-tools。如下是在Centos7下安装percona-tools的步骤，安装完成后，pt-query-digest就在/usr/local/percona-toolkit/bin目录下。
# 1、下载percona-toolkit 工具包
cd /opt
wget percona.com/get/percona-toolkit.tar.gz# 2、解压缩
tar -zxvf percona-toolkit.tar.gz# 3、进入安装目录
cd /opt/percona-toolkit-3.1.1# 4、安装依赖包
yum -y install perl-ExtUtils-MakeMaker
yum -y install perl-DBD-MySQL
yum -y install perl-Digest-MD5# 5、安装perl模块，制定依赖路径
perl Makefile.PL PREFIX=/usr/local/percona-toolkit# 6、编译安装
make && make install# 7、将pt-query-diges所在路径加入系统路径，并使之生效
echo "PATH=/usr/local/percona-toolkit/bin/:$PATH" >> /etc/profile
source /etc/profile
3.2.2、使用pt-query-digest生成慢查询日志分析报告
使用pt-query-digest做分析可以分为两步，第一步是使用命令生成慢查询日志分析报告，第二步是人工看慢查询日志分析报告获取信息。如下是几个典型的生成慢查询日志分析报告的场景。
- 直接分析慢查询
pt-query-digest /home/mysql/localhost-slow.log > slow.rtf
- 分析半个小时内的慢查询
pt-query-digest --since 1800s /home/mysql/localhost-slow.log > slow.rtf
- 分析一段时间范围内的慢查询
pt-query-digest --since '2014-04-14 22:00:00' --until '2014-04-14 23:00:00' /home/mysql/localhost-slow.log > slow.rtf
- 显示所有分析的查询，其中，“–limit”参数默认是“95%:20”，表示显示95%的最差的查询，或者20个最差的查询。
pt-query-digest --limit 100% /home/mysql/localhost-slow.log > slow.rtf
- 还可以用pt-query-digest分析MySQL的binlog日志，以查看我们日常的修改语句是如何分布的，首先需要把二进志日志转换为文本格式。对于这个命令，同样可以加上参数筛选信息，如“–since”、“–until”。
mysqlbinlog mysql-bin.000011 > /tmp/000011.log
pt-query-digest --type binlog /tmp/000011.log
3.2.3、看懂pt-query-digest报告
-
下图显示：Current Date执行pt-query-digest工具的时间。
-
下图显示：慢查询次数一共是304.88k，唯一的查询159个。
-
下图显示：这里记录的是发现第一条慢查询的时间到最后一条慢查询的时间。
-
下图是报告中的主要统计字段
- Exec time：执行时间。
- Lock time：表锁的时间。
- Rows sent：返回的结果集记录数。
- Rows examine：实际扫描的记录数。
- Query size：应用和数据库交互的查询文本大小
-
以下将按默认的响应时间进行排序，并列出TOP n条查询。并且pt-query-digest输出了EXPLAIN的语句，以方便我们验证查询计划。从pt-query-digest工具中看到的信息里，对于响应时间，不仅需要关注平均值，还需要关注百分比响应，以及关注其的分布情况和离散程度。对于响应时间的方差均值比，如果该均值比很大，则可能意味着有一些异常值。
- Rank：所有查询日志分析完毕后，此查询的排序。
- Query ID：查询的标识字符串。
- Response time：总的响应时间，以及总占比。一般小于5%可以不用关注。
- Calls：查询被调用执行的次数。
- R/Call：每次执行的平均响应时间。
- Apdx：应用程序的性能指数得分。（Apdex响应的时间越长，得分越低。）
- V/M：响应时间的方差均值比（变异数对平均数比，变异系数）。可说明样本的分散程度，这个值越大，往往是越值得考优化的对象。
- Item：查询的简单显示，包括查询的类型和所涉及的表。
4、总结
- MySQL的慢查询日志可以通过设置my.cnf中slow_query_log为1开启，设置long_query_time(单位为秒)阀值从而确定高于阀值的SQL被记录到慢查询日志。
- 慢查询日志可以使用mysqldumpslow工具解析，主要看Rows_sent与Rows_examined的比值是否过小。
- 慢查询日志还可以通过percona-tools工具集里的pt-query-digest生成分析报告，percona-tools是第三方工具，需要安装。