如何解释MySQL生成的慢查询日志信息？

Question

所以我对慢查询日志的理解是,它记录了我们在my.conf文件中设置的> = time(以秒为单位)的所有查询的信息.

现在让我们来看3个不同的SELECT查询3个案例(针对具有INNODB引擎的表):

QUERY I: Query_time:32.937667 Lock_time:0.000081 Rows_sent:343 Rows_examined: 12714043

QUERY II: Query_time:12.937667 Lock_time:0.000081 Rows_sent:43 Rows_examined: 714043

QUERY III: Query_time:42.937667 Lock_time:0.000081 Rows_sent:18 Rows_examined: 483

对我来说,QUERY I和QUERY II看起来像是一个糟糕的查询或糟糕的索引(或缺少索引)或碎片化的表数据等(我可能错过的任何其他东西？)用户可能会看到以改善查询执行时间的可能情况.

但是对于QUERY III,我无法理解,我的意思是数据库真正错误的是它需要42秒才能检查483行并发送回其中的18行(锁定时间可忽略不计).当我看到它间歇性地发生时,这变得更加混乱.

所以我真正想问的是:

• 我该如何解释锁定时间信息？是否意味着查询必须在实际开始执行之前等待那么多秒？如果是,那么在我的示例中,查询III实际需要42秒来检查483行并发回其中的18行？
• 如果锁定时间可以忽略不计,但查询时间仍然非常庞大,只有几百行被检查并发回,我应该从哪里开始寻找问题？
• 可能是查询花了很多时间在一些后台IO活动中吗？说记录或bin-logging.
• 表的大小对查询性能有多大影响？例如,我们可以说MySQL足以处理200万行的表
• 是否有更好的工具或方法来监控DB活动,专门用于计算DB的后台活动？简而言之,要检查该查询的大部分时间在哪里.

可能有很多因素影响这种慢查询,所以如果你觉得你需要更多的信息来帮助我,那么请告诉我.

Answer 1

• 锁定时间是查询开始执行之前的花费时间.即,等待其他线程放弃对当前查询需要锁定的数据的锁定的时间.

• 查询时间是执行查询的时间.如果行尚未存在于缓冲池中,则可能涉及等待I/O. 在将数据加载到缓冲池之后,对相同数据重复相同的查询可能更快.

  如果您的查询在磁盘上为给定查询排序,即使它检查了几行,它也会变慢.

  如果您的I/O系统负担过重,您可能会出现间歇性缓慢.这也可能发生在虚拟化I/O上(例如,廉价的AWS实例).或者,如果您的磁盘开始出现故障,它们可能会间歇性地出错.

  监视iostat并观察队列长度,平均等待时间和服务时间.查看是否存在缓慢的时期,或者性能和吞吐量是否或多或少一致.

• 检查的行不反映获取给定行所需的多个I/O. 例如,如果该行在溢出页面上存储了大量大BLOB/TEXT/VARCHAR列.或者,如果事务需要访问回滚段以获取某些行的旧版本,则自该事务开始后它们已被修改.

  检查的行也没有告诉我们查询中的表达式有多复杂.你可能正在计算存储函数中的Fibonacci序列或类似的东西.

  在没有查看查询及其EXPLAIN报告的情况下,只有慢速查询日志中的那些数字,很难对泛化进行解释.

MySQL当然可以在一个表中存储2亿行,但是在这种规模下,即使索引可以将搜索减少到483行,你也会开始遇到性能问题.这是因为B树索引的深度和索引列的大小直接与查找这483行所需的I/O操作数相关.I/O越多,所需的时间就越长,并且这不会被检查的行反映出来.查询时间包括I/O时间,但不清楚I/O有多少查询时间.

其他一些寻找更详细诊断的地方是:

• MySQL性能架构

• MySQL Query Profiler(但请注意,这不赞成使用Performance Schema)

• Percona Server中增强的详细程度慢查询日志报告查询等待I/O所花费的时间.