MySQL的慢查询及其原因分析

                                                                                 

关注公众号ITwords，了解更多的java，大数据的相关知识，大家一起学习，一起进步。

经过之前介绍的锁的知识，接下来介绍一些慢查询的实例。

先看一条SQL语句：

 select * from t where c=50000 limit 1;

由于字段c上没有索引，这个语句只能走id主键顺序扫描，因此需要扫描5万行。

作为确认，你可以看一下慢查询日志。注意，这里为了把所有语句记录到slow log里，我在连接后先执行了 set long_query_time=0，将慢查询日志的时间阈值设置为0。

补充：

设置慢查询的日志

 1.set global slow_query_log='ON';// 打开慢日志
 2.set global slow_query_log_file='F:/data/slow_query.log';// 设置日志的存放位置
 3.set global long_query_time=1;// 设置慢查询的之间，这里设置1秒，为了今天的演示效果，大家可以设置成0秒。

检验设置是否成功，在刚刚设置的路径下查看慢日志，是否存在：

以上的设置方法，是临时设置，再次启动时候，会失效，如果想永久有效的话，需要去mysqld的配置文件中添加一下的代码，并且重启MySQL进行验证，笔者只是为了讲解使用，所以就简单的进行临时设置。

 

我们线上一般都配置超过1秒才算慢查询。但是要知道的一点是：坏查询不一定是慢查询。如果扫描十万行需要10毫秒，那么随着行数的增多，时间自然就会增加，行数越多，执行的越慢了。

但是接下来，我们再看一个只扫描一行，但是执行很慢的语句。

 select * from t where id=1；

虽然扫描行数是1，但执行时间却长达800毫秒。

是不是有点奇怪呢，这些时间都花在哪里了？

如果我把这个slow log的截图再往下拉一点，你可以看到下一个语句，select * from t where id=1 lock in share mode，执行时扫描行数也是1行，执行时间是0.2毫秒。

第一个语句的查询结果里c=1，带lock in share mode的语句返回的是c=1000001。看到这里应该有更多的同学知道原因了。如果你还是没有头绪的话，也别着急。我先跟你说明一下复现步骤，再分析原因。

你看到了，session A先用start transaction with consistent snapshot命令启动了一个事务，之后session B才开始执行update 语句。

session B执行完100万次update语句后，id=1这一行处于什么状态呢？你可以从下图中找到答案。

session B更新完100万次，生成了100万个回滚日志(undo log)。

带lock in share mode的SQL语句，是当前读，因此会直接读到1000001这个结果，所以速度很快；而select * from t where id=1这个语句，是一致性读，因此需要从1000001开始，依次执行undo log，执行了100万次以后，才将1这个结果返回。

注意，undo log里记录的其实是“把2改成1”，“把3改成2”这样的操作逻辑，画成减1的目的是方便你看图。

喜欢的同学，可以关注ITwords公众号，大家一起学习，一起进步。