说明:主要用简单的例子来说明,slow log里的lock_time和query_time的关系,得出的结论是:
当一个sql的执行时间(排除lock_time)大于long_query_time的时候,才会被记录到slow log中,并且query_time是累计了lock_time的(如果有lock_time),大概真正的执行时间需要减去lock_time的时间,当一个sql的执行时间(排除lock_time)小于long_query_time的时候(即使他锁等待了3个小时),也不会记录到slow log中的,故锁等待的时间并不决定记不记录slow log,下面的测试多是基于自建mysql进行
有时在查slow log的信息时,可能会遇到,下面这种情况:
或者:
上面的信息,都出现了lock_time的时间很长的情况,并且sql的执行时间(query_time)也会出现时间很长的情况
构建测试数据,手动造成锁等待,复现下这类问题
无自建主键测试数据,locking Reads的结果和执行时间:
上图可以大概判断,select count(1) from MOCK_DATA for update;的执行时间一般会大于小于15S且大于5S
进行如下测试:
Session1:
Session1执行查询,不提交,不回滚
Session2:
Session2被阻塞
等待一段时间后Session1回滚(不要超过锁等待超时时间)
Session2执行完成,执行时间是28.95sec
Session3:
查询mysql.slow_log,看下结果:
没有看到session2执行的for update操作的sql
重复测试1的测试:
Session 1执行查询,不提交不回滚
Session2阻塞
Session2执行完成,执行时间是47.66sec
从上图可以看到,session2执行的for update操作的sql记录下来了,其中执行时间(query_time)是47s,在这47s里,锁定的时间(lock_time)是38s
当一个无自建主键的sql的执行时间(排除lock_time)大于long_query_time的时候,才会被记录到slow log中,并且query_time是累计了lock_time的,大概真正的执行时间需要减去lock_time的时间才是(该测试中,执行时间=47s-38s=9s,这个计算可能会有偏差),当一个sql的执行时间(排除lock_time)小于long_query_time的时候(即使他锁等待了3个小时),就不会记录到slow log中
有自建主键测试数据,locking Reads的结果和执行时间:
上图可以大概判断,select count(1) from MOCK_DATA where id<10000000 lock in share
mode;的执行时间一般会大于小于15S且大于5S,
Session2执行完成,执行时间是31.04sec
没有看到最新测试的session2执行的for update操作的sql,只有之前测试的那条记录
Session2执行完成,执行时间是1min 0.40sec
从上图可以看到,最新测试的session2执行的for update操作的sql记录下来了,其中执行时间(query_time)是1分钟,在这1分钟里,锁定的时间(lock_time)是51s
当使用主键查询的一个sql的执行时间(排除lock_time)大于long_query_time的时候,才会被记录到slow log中,并且query_time是累计了lock_time的,大概真正的执行时间需要减去lock_time的时间,当一个sql的执行时间(排除lock_time)小于long_query_time的时候(即使他锁等待了3个小时),就不会记录到slow log中
Secondary index测试数据,locking
Reads的结果和执行时间:
上图可以大概判断,select count(1) from MOCK_DATA where ram_num=7 for update;的执行时间一般会大于小于10S且大于1S,
Session2执行完成,执行时间是1min
44.02sec
Session2执行完成,执行时间是1min 6.66sec
从上图可以看到,最新测试的session2执行的for update操作的sql记录下来了,其中执行时间(query_time)是1分06秒,在这1分06秒里,锁定的时间(lock_time)是1分02秒
当使用secondary index查询的一个sql的执行时间(排除lock_time)大于long_query_time的时候,才会被记录到slow log中,并且query_time是累计了lock_time的,大概真正的执行时间需要减去lock_time的时间,当一个sql的执行时间(排除lock_time)小于long_query_time的时候(即使他锁等待了3个小时),就不会记录到slow log中