MySQL慢查询日志释疑总结
author:一佰互联 2019-04-01   click:169

简介:作者:潇湘隐者出处:http://www.cnblogs.com/kerrycode/之前写了一篇“MySQL慢查询日志总结“,总结了一些MySQL慢查询日志常用的相关知识,这里总结一下在工作当中遇到关于MySQL慢查询日志的相关细节问题,有些是 ...

作者:潇湘隐者出处:http://www.cnblogs.com/kerrycode/
之前写了一篇“MySQL慢查询日志总结“,总结了一些MySQL慢查询日志常用的相关知识,这里总结一下在工作当中遇到关于MySQL慢查询日志的相关细节问题,有些是释疑或自己有疑惑,自己测试验证、解惑方面的知识。此篇只是总结个人的一些经验,不足之处,敬请指正!1: 为什么在慢查询日志里面出现Query_time小于long_query_time阀值的SQL语句呢?例如,如下截图,long_query_time=5, 但是Query_time小于1秒的SQL都记录到慢查询日志当中了。

MySQL慢查询日志释疑总结

相信有些人遇到这个问题的时候觉得很奇怪,其实这个不是bug,而是你设置了系统变量log_queries_not_using_indexes ,这个系统变量开启后,会将那些未使用索引的SQL也被记录到慢查询日志中,另外,full index scan的SQL也会被记录到慢查询日志。所以,当满足这些条件的SQL,即使Query_time时间小于long_query_time的值,也会被记录到慢查询日志。2: 使用日志分析工具mysqldumpslow分析有些日志非常慢,如何加快?mysqldumpslow -s t -t 10 /var/lib/mysql/MyDB-slow.log1: 出现这种情况是因为慢查询日志变得很大(个人遇到的案例,慢查询日志就有2G多了),所以,需要每天或每周切分慢查询日志。设置一个Crontab作业即可。/var/lib/mysql/DB-Server-slow.log.20181112/var/lib/mysql/DB-Server-slow.log.20181113/var/lib/mysql/DB-Server-slow.log.20181114/var/lib/mysql/DB-Server-slow.log.201811152: 开启了系统变量log_queries_not_using_indexes后,如果系统设计糟糕,未使用索引的SQL很多,那么这一类的日志可能会有很多,所以还有个特别的开关log_throttle_queries_not_using_indexes用于限制每分钟输出未使用索引的日志数量。3:mysqldumpslow的生成报告中的Count、 Time、 Lock、Rows代表具体意思。mysqldumpslow -s c -t 10 /var/lib/mysql/MyDB-slow.log 使用mysqldumpslow分析慢查询日志分析获取访问次数最多的10个SQL。Count : 表示这个SQL总共执行了195674次(慢查询日志中出现的次数)Time 表示执行时间,后面括号里面的38s 表示这个SQL语句累计的执行耗费时间为38秒。其实就是单次执行的时间和总共执行消耗的时间的区别。Lock 表示锁定时间,后面括号里面表示这些SQL累计的锁定时间为48sRows 表示返回的记录数,括号里面表示所有SQL语句累计返回记录数

MySQL慢查询日志释疑总结

然后我们看看慢查询日志的相关信息:

MySQL慢查询日志释疑总结

# Time: 2018-11-15T01:43:51.338167Z这个表示日志记录的时间,确切的说是SQL执行完的时间点。注意这个时间有可能跟系统当前时间不一致,它可能是UTC时间。这个要看系统变量log_timestamps是UTC还是system。
mysql> show variables like "log_timestamps";+----------------+-------+| Variable_name | Value |+----------------+-------+| log_timestamps | UTC |+----------------+-------+1 row in set (0.01 sec) mysql> set global log_timestamps=system;Query OK, 0 rows affected (0.00 sec)
# User@Host: xxx[xxx] @ [xxx.xxx.xxx.xxx] Id: 23781客户端的账户信息,两个用户名(第一个是授权账户,第二个为登录账户),客户端IP地址,还有mysqld的线程ID。# Query_time: 16.480118 Lock_time: 0.000239 Rows_sent: 1 Rows_examined: 348011查询执行的信息,包括查询时长,锁持有时长,返回客户端的行数,优化器扫描行数。通常需要优化的就是最后一个内容,尽量减少SQL语句扫描的数据行数#use xxx;#SET timestamp=1542246231;这个是时间戳,你可以将其转换为时间格式(注意时区),如下所示:[root@mylnx02 ~]# date -d @1542246231Thu Nov 15 09:43:51 CST 2018[root@DB-Server ~]# date -d @1542246231Wed Nov 14 20:43:51 EST 20184: 如何分析慢查询日志一段时间内的数据呢?mysqldumpslow这款工具没有提供相关参数分析某个日期范围内的慢查询日志,也就是说没法提供精细的搜索、分析。如果要分析某段时间内的慢查询日志可以使用工具pt-query-digest如果实在需要使用mysqldumpslow分析某段时间内的慢查询SQL,可以借助awk命令的帮助。如下样例所示#取出一天时间的慢查询日志# awk "/# Time: 2018-11-14/,/# Time: 2018-11-15/" DB-Server-slow.log > DB-Server-slow.log.20181114#取出2018-11-14号4点到6点之间两个小时的数据#awk "/# Time: 2018-11-14T04/,/# Time: 2018-11-14T06/" DB-Server-slow.log > slow_04_06.log5: 关于慢查询日志中query_time和lock_time的关系。只有当一个SQL的执行时间(不包括锁等待的时间 lock_time)>long_query_time的时候,才会判定为慢查询SQL;但是判定为慢查询SQL之后,输出的Query_time包括了(执行时间+锁等待时间),并且也会输出Lock_time时间。当一个SQL的执行时间(排除lock_time)小于long_query_time的时候(即使他锁等待超过了很久),也不会记录到慢查询日志当中的。6: mysqldumpslow相关参数的详细信息
# mysqldumpslow --helpUsage: 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 排序方式,at是默认方式 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  #只显示前n个查询 -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) #根据服务器MySQL实例名称选择慢查询日志。 -l don"t subtract lock time from total time  #不要从总时间减去锁定时间
7: 系统变量Slow_queries会统计慢查询出现的次数。
mysql> show global status like "%slow%"; +---------------------+--------+| Variable_name | Value |+---------------------+--------+| Slow_launch_threads | 0 || Slow_queries | 120 |+---------------------+--------+
8:系统变量slow_launch_time 是什么? 跟慢查询日志有关系吗?如果创建线程需要的时间比slow_launch_time多,服务器会增加Slow_launch_threads的状态变量的数量。其实这个状态变量跟慢查询没有什么关系。之所以放到这里,是有人问过这个问题!本文仅代表作者个人观点,不代表巅云官方发声,对观点有疑义请先联系作者本人进行修改,若内容非法请联系平台管理员,邮箱2522407257@qq.com。更多相关资讯,请到巅云www.yinxi.net学习互联网营销技术请到巅云建站www.yx10011.com。