之前写了一篇“MySQL慢查询日志总结“,总结了一些MySQL慢查询日志常用的相关知识,这里总结一下在工作当中遇到关于MySQL慢查询日志的相关细节问题,有些是释疑或自己有疑惑,自己测试验证、解惑方面的知识。此篇只是总结个人的一些经验,不足之处,敬请指正!
1: 为什么在慢查询日志里面出现Query_time小于long_query_time阀值的SQL语句呢?
例如,如下截图,long_query_time=5, 但是Query_time小于1秒的SQL都记录到慢查询日志当中了。
相信有些人遇到这个问题的时候觉得很奇怪,其实这个不是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.log
1: 出现这种情况是因为慢查询日志变得很大(个人遇到的案例,慢查询日志就有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.20181115
2: 开启了系统变量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累计的锁定时间为48s
Rows 表示返回的记录数,括号里面表示所有SQL语句累计返回记录数
然后我们看看慢查询日志的相关信息:
# 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)