mysql 执行时间过长_分析一个执行时间很长的sql

背景

在查bug时发现有两个相似sql查询速度相差巨大：

SELECT * FROM news_basic WHERE category =43 AND status in (1,7) AND source in (11,12,13)

ORDER BY publish_time DESC LIMIT 6;

SELECT * FROM news_basic WHERE category =8 AND status in (1,7) AND source in (11,12,13)

ORDER BY publish_time DESC LIMIT 6;

区别仅在于 category 一个是43，一个是8。(后面方便阐述称第一个sql为Q43，第二个sql为Q8。)

Q43的query速度：0.00347175秒；Q8是21.150秒。

数据库版本：5.6.28

当然，在实际业务中，WHERE status in (1,7) AND source in (11,12,13) 的数据子集的category 取值分布在[10,1000]。所以，Q8的结果集必定是空的，从业务上讲是个不符合业务的sql。

但这两个sql为什么速度差这么多呢？

首先对比下数据库中两个category的记录数，数据量差距并不大。排除两category数据量相差过大造成的影响。

数据库中记录对比

再对比下执行计划 EXPLAIN

很奇怪，两sql的执行计划一致。

查询过程先走publish_time的索引再回表，没有疑问。只是rows估计扫过行数都是24，Q8也这么少吗？

Q8执行计划

Q43执行计划

进行猜测

最后使用show profile 验证一下

打开profile： set profiling = 1;

执行两条sql语句

执行show profiles;

show profile for query N; (这里N=1，2).

结果如图所示(左侧Q8，右侧Q43)

左侧Q8，右侧Q43

时间都消耗在sending data上了，执行器耗时巨长。

注：Sending data 并不一定是指“正在发送数据”，而可能是处于执行器过程中的任意阶段.(林晓斌 MySQL实战45讲，33讲)

所以，虽然Q45结果集是空，但sending data仍可能很长。

继续深入下： 执行show profile ALL for query N;

将部分差异明显的内容整理成表格，如下所示：

二者show profile主要的差异对比

结论：

可以看出，Q8 执行的主要耗时是statistics过程中，此过程中读入了若干block 。

先进行publish_time 的排序，然后回表根据where做检索。当检索的条数等于limit_count 时，检索停止，返回数据。

Q8会触发mysql对limit的优化策略mysql5.6官方对limit的优化。所以在筛选到6条记录后进行返回了。

Q43先通过publisth_time进行排序，然后全表检索，Q43每条记录都不符合where的限定条件。耗时都在sending data阶段。【为什么不是execting阶段？】

该过程block_ops_in 高达1733k。后文估计了表内所有数据大约占 239k个block，这个数字远小于1733k，显然是有重复读入的。

仍存的疑问：

官方对block_ops 解释过于简单，有没有更详细的说法。

为什么block_ops_in会重复读入，与耗时成正比呢？对block_ops 的

两次执行Q8的对比

当然，表格标黄处都与query耗时成正比，时间越长，cpu时间 上下文切换肯定会越高的。

为什么Q8会有block_ops_out？

官网对block_ops_in 和block_ops_out的解释

The number of block input and output operations.

ops是operation per second吗？

execting和sending data的区别。

估算表内数据占多少block

page 和 block 是一个概念。库中pagesize是默认值 16384，也就是16k。news_basic表数据所占共3.65GB。

数据长度

很粗略地估计一下(如果表中有长字段，那么每行的size会更小，实际页数会更少)。

其他的发现

navicat的“概况”

navicat在执行完一批次查询后有个“概况”标签，与show profile类似，但是实际结果二者不太相同。

navicat会执行sql进行统计：

SELECT STATE AS `Status`, ROUND(SUM(DURATION),7) AS `Duration`, CONCAT(ROUND(SUM(DURATION)/0.002964*100,3), '') AS `Percentage`

FROM INFORMATION_SCHEMA.PROFILING

WHERE QUERY_ID=102

GROUP BY SEQ, STATE

ORDER BY SEQ

navicat分析Q8，大量的时间在execting下，sending data 会很小。