关于MySQL慢日志，你想知道的都在这

关于MySQL慢日志，你想知道的都在这

https://mp.weixin.qq.com/s/Ifbq0Dk13SO3WVghqWVUbA

 

作者介绍
邹鹏，现任职于腾讯云数据库团队，负责腾讯云数据库MySQL中间件研发，多年的数据库、网络安全研发经验，对云计算平台的网络、计算、存储、安全有着深入的了解，在MySQL的高可用、高可靠、中间件方面有丰富的经验。

第一行：标记日志产生的时间，准确说是SQL执行完成的时间点，改行记录每一秒只打印一条。
第二行：客户端的账户信息，两个用户名（第一个是授权账户，第二个为登录账户），客户端IP地址，还有mysqld的线程ID。
第三行：查询执行的信息，包括查询时长，锁持有时长，返回客户端的行数，扫描行数。通常我需要优化的就是最后一个内容，尽量减少SQL语句扫描的数据行数。
第四行：通过代码看，就是sql语句执行时的时间戳，用来保证now()函数之类的正确
第五话：最后就是产生慢查询的SQL语句。

目录：
什么是慢日志？
什么情况下产生慢日志？
慢日志相关参数
慢日志输出内容
慢日志分析工具
慢日志的清理与备份

一、什么是慢日志？

MySQL的慢查询日志是MySQL提供的一种日志记录，它用来记录在MySQL中响应时间超过阀值的语句，具体指运行时间超过long_query_time值的SQL，则会被记录到慢查询日志中。long_query_time的默认值为10，意思是运行10s以上的语句。

默认情况下，MySQL数据库并不启动慢查询日志，需要我们手动来设置这个参数，当然，如果不是调优需要的话，一般不建议启动该参数，因为开启慢查询日志或多或少会带来一定的性能影响。慢查询日志支持将日志记录写入文件，也支持将日志记录写入数据库表。

5.6官方说明：https://dev.mysql.com/doc/refman/5.6/en/slow-query-log.html
5.7官方说明：https://dev.mysql.com/doc/refman/5.7/en/slow-query-log.html

二、什么情况下产生慢日志？



看图说话，有很多开关影响着慢日志的生成，相关的参数后面会挨个说明。从上图可以看出慢日志输出的内容有两个，第一执行时间过长（大于设置的long_query_time阈值）；第二未使用索引，或者未使用最优的索引。

这两种日志默认情况下都没有打开，特别是未使用索引的日志，因为这一类的日志可能会有很多，所以还有个特别的开关log_throttle_queries_not_using_indexes用于限制每分钟输出未使用索引的日志数量。

关键代码如下：



Slow log调用栈（MySQL 5.6.34 ）：



三、慢日志相关参数



以上应该是最完整的和慢日志相关的所有参数，大多数参数都有前置条件，所以在使用的时候可以参照上面的流程图。

5.6官方文档：
1、https://dev.mysql.com/doc/refman/5.6/en/server-system-variables.html
2、https://dev.mysql.com/doc/refman/5.6/en/server-options.html

四、慢日志输出内容

# Time: 170305 19:59:07
# User@Host: root[root] @ localhost [] Id: 45
# Query_time: 2.259747 Lock_time: 0.000191 Rows_sent: 0 Rows_examined: 0
SET timestamp=1488715147;
insert into test22(name) values(3336666);

第一行：标记日志产生的时间，准确说是SQL执行完成的时间点，改行记录每一秒只打印一条。

第二行：客户端的账户信息，两个用户名（第一个是授权账户，第二个为登录账户），客户端IP地址，还有mysqld的线程ID。

第三行：查询执行的信息，包括查询时长，锁持有时长，返回客户端的行数，扫描行数。通常我需要优化的就是最后一个内容，尽量减少SQL语句扫描的数据行数。

Query_time 是真实记录慢查询的查询时间，查询时间越长对系统的影响越大；

Lock_time 是当前查询获取数据时获取记录锁而等待的时间，等待时间越长，越可能造成慢查询；

Rows_sent 是发送多少行数据给 client ，同一个查询语句发送的数据行数越大，越可能会造成慢查询；

Rows_examined 是 server 层检索的数据，检索的数据越多，需要的IO和cpu资源也就越多，越可能造成慢查询，并影响服务稳定性；

Rows_affected 只针对修改请求，由于绝大部分慢查询都是 select ，并不会修改数据，故此值可以忽略；

Bytes_sent 是发送多少字节数据给 client ，发送的数据量越多，越可能会造成慢查询；

由于不同的表行大小不同，并且并不是所有列都需要返回，所以一个发送 10 行的数据，可能会比一个发送 100 行数据的查询更慢，Rows_sent 不如 Bytes_sent 更为直观，故我们选取 Bytes_sent ，忽略 Rows_sent 。

所以，慢查询指标中 Query_time、Lock_time 、 Bytes_sent 、 Rows_examined 作为慢查询评分模型中的指标。

第四行：通过代码看，貌似和第一行的时间没有区别。

第五话：最后就是产生慢查询的SQL语句。

--log-short-format=true：

如果mysqld启动时指定了--log-short-format参数，则不会输出第一、第二行。

log-queries-not-using-indexes=on   
log_throttle_queries_not_using_indexes > 0 :

如果启用了以上两个参数，每分钟超过log_throttle_queries_not_using_indexes配置的未使用索引的慢日志将会被抑制，被抑制的信息会被汇总，每分钟输出一次。

格式如下：



五、慢日志分析工具

官方自带工具： mysqldumpslow
开源工具：mysqlsla  
percona-toolkit：工具包中的pt-query-digest工具可以分析汇总慢查询信息，具体逻辑可以看SlowLogParser这个函数。

总的来说，MySQL的日志内容本身不复杂，上面3个工具都是用perl脚本实现，代码行数不超过200行，有兴趣的同学也可以自己尝试着解析下。

详情可以参阅下这篇文章：
《MySQL 慢查询设置和分析工具 》：
https://flyerboy.github.io/2016/12/23/mysql_slow/

以上工具可以支撑慢日志的常用统计，但是当我们需要做到SQL级别的统计时，我们还需要取解析SQL把参数提取出来。

六、慢日志的清理与备份

删除：直接删除慢日志文件，执行flush logs（必须的），重新生成slow log。

备份：先用mv重命名文件（不要跨磁盘分区），然后执行flush logs（必须的），重新生成slow log。

另外修改系统变量slow_query_log_file也可以立即生效；

执行flush logs，系统会先close当前的句柄，然后重新open；mv , rm日志文件系统并不会报错，具体的原因可以Google下linux  i_count   i_nlink ；

 

https://www.cnblogs.com/yihr/p/7519731.html
Linux是通过link的数量来控制文件删除的，只有当一个文件不存在任何link的时候，这个文件才会被删除。
一般来说，每个文件都有2个link计数器:i_count 和 i_nlink。
i_count的意义是当前文件使用者（或被调用）的数量,i_nlink 的意义是介质连接的数量（硬链接的数量）；可以理解为i_count是内存引用计数器，i_nlink是磁盘的引用计数器。
当一个文件被某一个进程引用时，对应i_count数就会增加；当创建文件的硬链接的时候，对应i_nlink数就会增加。
对于删除命令rm而言，实际就是减少磁盘引用计数i_nlink

mysql删大表，给ibd文件加硬链接
这时候ibd的i_count为1，i_nlink为2
然后drop table 大表，
这时候ibd的i_count为0，i_nlink为1
然后rm -f  ibd文件，
这时候ibd的i_count为0，i_nlink为0
删大表完成

---

 

即使有慢查询系统也解决不了慢查询的两个原因

1、解决慢查询的周期长，比较复杂的慢查询一般需要半个月解决

2、慢日志里面慢查询没有优先级，不知道需要优先解决哪个慢查询

 

---

 

https://www.modb.pro/db/400794
1、语句开始， 记录开始时间点为 X
2、获取MDL LOCK   -> 正常语句如果本处超时（超过lock_wait_timeout）直接退出，也不会记录到下面一步记录的lock time时间中，因此lock time为0。
3、上MySQL层锁（比如myisam，记录lock time时间差量（1-3的时间差量nowtime-X = Y）
4、优化器优化语句。
5、执行器开始执行语句，与innodb层交互,  如果每行需要等待innodb行锁，记录每次获取的lock time时间差量（第5步的每次等待innodb行锁的时间差量综合为nowtime-X = Y）
6、语句结束，触发记录慢查询接口，并且获取当前时间点为（Z）
判定记录慢查询如下：
如果(Z-X)-Y > 慢查询设置的时间则需要记录
也就是慢查询 query time：Z-X  lock time为：Y
需要注意的是语句异常结束也会记录慢查询。

---

 

 

 

f