一个简单的sql,在慢日志中信息如下:
并且执行的语句很简单,比较奇怪了。
Lock_time:为0代表没有遇到MDL LOCK和ROW lock堵塞。
Rows_examined:为0代表没有在引擎层扫描数据。
Query_time: 180:执行时间比较长。
该语句查询没有扫描到任何数据,执行时间超过了3分钟,查看执行计划,虽然是全表扫描,但是表数据量只扫描到1行。
再次查询,发现并不慢,只是在某个时间执行的时候,花费了3分钟,该语句本身并不慢。
猜测:
(1)有没有可能是某个时间段,该表被锁住了,所以查询很慢,但是这个猜测并不成立,因为慢日志记录真实执行时间超过long_query_time的语句,不包含锁等待时间。
测试(一)
session 1
session 2
等待锁几秒后,将session1 提交,查看慢日志是否记录
发现慢日志并没有记录该sql
测试(二)
session 1
session2 ,在过几秒之后,将session 1提交
慢日志记录
结论:慢日志记录真实执行时间超过long_query_time的语句。
(2)既然不是锁等待,有没有可能锁超时报错,然后将锁等待时间记录到执行时间里面去了
锁超时有两个参数
innodb_lock_wait_timeout:innodb的dml操作的行级锁的等待时间。
lock_wait_timeout:数据结构ddl操作的锁的等待时间,代表MDL LOCK超时时间。
set global lock_wait_timeout=180;
set innodb_lock_wait_timeout=10;
测试(一)
session 1
session 2
session 3
查看慢日志,都记录进去了
测试(二)
session 1
session 2
慢日志中没有记录该慢sql
总结:
MySQL慢日志记录的是实际消耗的时间,不包含锁等待时间。
lock_wait_timeout参数,会导致锁超时异常的sql被误认为是慢sql,因为它将锁等待时间算成了真实执行时间。