慢查询日志
一篇好文章,学习保存。。。。
打开慢查询日志
慢查询日志,顾名思义就是记录执行比较慢查询的日志。
查看是否开启慢查询日志:
show variables like '%slow%';
打开慢查询日志。修改MySQL的配置文件my.cn一般是在/etc目录下面,加上下面三行配置后重启MySQL。
slow_query_log = ON slow_launch_time = 2 slow_query_log_file = /usr/local/mysql/data/slow_query.log
slow_launch_time只能精确到秒,如果需要更精确可以使用一些第三方的工具比如后面介绍的pt-query-digest。
注意:我这里用的MySQL版本是5.6,不同版本的MySQL开启慢查询的配置是不同的,比如5.6之前的某些版本是ong_query_time, long_query_time和log-slow-queries。可以先在终端执行show variables like '%slow%';查看下当前版本具体配置是什么。
也可以在终端通过设置全局变量来打开慢查询日志:
set @@global.slow_query_log = ON;
保存慢查询日志到表中
MySQL支持将慢查询日志保存到mysql.slow_log这张表中。通过@@global.log_output可以设置默认为TABLE,FILE和TABLE只能同时使用一个。
set @@global.log_output='TABLE';
我们可以使用下面的语句来模拟慢查询:
select sleep(10);
慢查询日志分析
1、可以使用MySQL自带的mysqldumpslow工具。使用很简单,可以跟-help来查看具体的用法。
# -s:排序方式。c , t , l , r 表示记录次数、时间、查询时间的多少、返回的记录数排序; # ac , at , al , ar 表示相应的倒叙; # -t:返回前面多少条的数据; # -g:包含什么,大小写不敏感的; mysqldumpslow -s r -t 10 /slowquery.log #slow记录最多的10个语句 mysqldumpslow -s t -t 10 -g "left join" /slowquery.log #按照时间排序前10中含有"left join"的
2、可以导到mysql.slow_query表中,然后通过sql语句进行分析。
3、使用第三方工具,下面会有介绍。
Percona Toolkit介绍
percona-toolkit是一组高级命令行工具的集合,用来执行各种通过手工执行非常复杂和麻烦的mysql和系统任务。这些任务包括:
- 检查master和slave数据的一致性
- 有效地对记录进行归档
- 查找重复的索引
- 对服务器信息进行汇总
- 分析来自日志和tcpdump的查询
- 当系统出问题的时候收集重要的系统信息
安装
安装percona-toolkit非常简单,到官网下载.tar.gz包:
wget percona.com/get/percona-toolkit.tar.gz tar -zxvf percona-toolkit-2.2.5.tar.gz
然后依次执行下面的命令:
perl Makefile.PL make make test make install
默认的会被安装在/usr/local/bin目录下。执行man percona-toolkit可以查看安装了哪些工具。
运行工具可能会遇到下面的错误:
这是因为缺少相应包,.pm包实际上perl的包,运行下面的命令安装即可:
yum install -y perl-Time-HiRes
如果安装过程中出现” Error Downloading Packages”错误,尝试yum clean all后再安装。使用其Percona Toolkit中其他工具也可能会遇到类似的问题,按照提示安装相应的perl包就可以了。
Percona Toolkit整个工具箱提供了非常多实用的工具,具体的使用方法可以参看官方文档。
下面有选择的给大家介绍几个有用的工具。
pt-query-digest
pt-query-digest可以从普通MySQL日志,慢查询日志以及二进制日志中分析查询,甚至可以从SHOW PROCESSLIST和MySQL协议的tcpdump中进行分析,如果没有指定文件,它从标准输入流(STDIN)中读取数据。
最简单的用法如下:
pt-query-digest slow.logs
输出信息大致如下:
整个输出分为三大部分:
1、整体概要(Overall)
这个部分是一个大致的概要信息(类似loadrunner给出的概要信息),通过它可以对当前MySQL的查询性能做一个初步的评估,比如各个指标的最大值(max),平均值(min),95%分布值,中位数(median),标准偏差(stddev)。这些指标有查询的执行时间(Exec time),锁占用的时间(Lock time),MySQL执行器需要检查的行数(Rows examine),最后返回给客户端的行数(Rows sent),查询的大小。
2、查询的汇总信息(Profile)
这个部分对所有”重要”的查询(通常是比较慢的查询)做了个一览表:
每个查询都有一个Query ID,这个ID通过Hash计算出来的。pt-query-digest是根据这个所谓的Fingerprint来group by的。举例下面两个查询的Fingerprint是一样的都是select * from table1 where column1 = ?,工具箱中也有一个与之相关的工具pt-fingerprint。
select * from table1 where column1 = 2 select * from table1 where column1 = 3
- Rank整个分析中该“语句”的排名,一般也就是性能最常的。
- Response time “语句”的响应时间以及整体占比情况。
- Calls 该“语句”的执行次数。
- R/Call 每次执行的平均响应时间。
- V/M 响应时间的差异平均对比率。
在尾部有一行输出,显示了其他2个占比较低而不值得单独显示的查询的统计数据。
3、详细信息
这个部分会列出Profile表中每个查询的详细信息:
包括Overall中有的信息、查询响应时间的分布情况以及该查询”入榜”的理由。
pt-query-digest还有很多复杂的操作,这里就不一一介绍了。比如:从PROCESSLIST中查询某个MySQL中最慢的查询:
pt-query-digest –processlist h=host1
从tcpdump中分析:
tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt pt-query-digest --type tcpdump mysql.tcp.txt
从一台机器上讲slow log保存到另外一台机器上待稍后详细分析:
pt-query-digest --review h=host2 --no-report slow.log
还可以跟一些过滤条件。详见官方文档:http://www.percona.com/doc/percona-toolkit/2.2/pt-query-digest.html
另外结合一些第三方工具还能生成相应的报表,可以参考这里:http://biancheng.dnbcw.info/mysql/433514.html
建议:当slow log很大的时候最好还是将日志文件移到其他机器上进行分析。
pt-index-usage
这个工具主要是用来分析查询的索引使用情况。
pt-index-usage slow_query.log --h localhost --password 123456
详细的用法 –help查看再对照官网就差不再赘述。
注意使用这个工具需要MySQL必须要有密码,另外运行时可能报找不到/var/lib/mysql/mysql.sock的错,简单的从/tmp/mysql.sock链接一个就行了。
重点要说明的是pt-index-usage只能分析慢查询日志,所以如果想全面分析所有查询的索引使用情况就得将slow_launch_time设置为0,因此请谨慎使用该工具,线上使用的话最好在凌晨进行分析,尤其分析大量日志的时候是很耗CPU的。
整体来说这个工具是不推荐使用的,要想实现类似的分析可以考虑一些其他第三方的工具,比如:mysqlidxchx, userstat和check-unused-keys。网上比较推荐的是userstat,一个Google贡献的patch。
Oracle是可以将执行计划保存到性能视图中的,这样分析起来可能更灵活,但是目前我还没找到MySQL中类似的做法。
pt-upgrade
这个工具用来检查在新版本中运行的SQL是否与老版本一样,返回相同的结果,最好的应用场景就是数据迁移的时候。
pt-upgrade h=host1 h=host2 slow.log
pt-query-advisor
静态查询分析工具。能够解析查询日志、分析查询模式,然后给出所有可能存在潜在问题的查询,并给出足够详细的建议。这个工具好像2.2的版本给去掉了,有可能是因为对性能影响比较大新版本直接去掉了。
总结:上面这些工具最好不要直接在线上使用,应该作为上线辅助或故障后离线分析的工具,也可以做性能测试的时候配合着使用。
SHOW PROFILE
SHOW PROFILE是Google高级架构师Jeremy Cole贡献给MySQL社区的,它可以用来MySQL执行语句时候所使用的资源。默认是关闭的,需要打开执行下面的语句:
set profiling = 1;#这个命令只在本会话内起作用。
执行简单的SHOW PROFILES可以看到打开profiling之后所有查询的执行时间。
执行SHOW PROFILE [TYPE] FOR QUERY Query_ID可以看到MySQL执行某个查询各个步骤的各项性能指标的详细信息:
如果没有指定FOR QUERY则显示最近一条查询的详细信息。TYPE是可选的,有以下几个选项:
- ALL 显示所有性能信息
- BLOCK IO 显示块IO操作的次数
- CONTEXT SWITCHES 显示上下文切换次数,不管是主动还是被动
- CPU 显示用户CPU时间、系统CPU时间
- IPC 显示发送和接收的消息数量
- MEMORY [暂未实现]
- PAGE FAULTS 显示页错误数量
- SOURCE 显示源码中的函数名称与位置
- SWAPS 显示SWAP的次数
MySQL在执行查询语句的时候会有很多步骤,这里就不一一赘述了,用到的时候网上搜下就行。需要特别说明的是Sending data这个步骤,给人感觉是MySQL把数据发送给客户端的耗时,其实不然,这个步骤包括了MySQL内部各个存储之间复制数据的过程,比如硬盘的寻道。
总结:前面的慢查询日志分析更像是对整个MySQL查询情况做一个全面的检查,而SHOW PROFILE则是对单个查询语句的剖析,通常当现网出现问题时应该结合二者。使用慢查询分析定位到具体的查询,使用SHOW PROFILE定位到具体的问题,是Sending data比较耗时还是System lock比较耗时...
performance_schema
这两个库保存了MySQL的一些性能和元数据相关的信息,其中performance_schema是MySQL5.5才新增的,上面提到的很多工具其实利用了这个库的信息。比如SHOW PROFILE ALL FOR QUERY 2:的信息还可以通过下面的查询获取:
SELECT * FROM information_schema.profiling WHERE query_id = 2 ORDER BY seq;
利用performance_schema还可以做一些更灵活的统计:
SET @query_id = 1; SELECT STATE,SUM(DURATION) AS Total_R, ROUND(100*SUM(DURATION)/(SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = @query_id),2) AS Pct_R, COUNT(*) AS Calls, SUM(DURATION)/COUNT(*) AS "R/Call" FROM INFORMATION_SCHEMA.PROFILING WHERE QUERY_ID = @query_id GROUP BY STATE ORDER BY Total_R DESC;
这个简单的查询可以在《高性能MySQL第三版》中找到,可它能统计SHOW PROFILE各个步骤的耗时、耗时占比、调用API次数以及每次的平均耗时。在《高性能MySQL第三版》中还提到了很多有用的工具(SHOW STATUS,SHOW PROCESSLIST...)包括使用方法,强烈推荐这本书。
转自: