第31问：慢日志觉得一个 SQL 很慢，但 binlog 不这么觉得，怎么办？

问题：

在小伙伴们学习的过程中，执行了一个 insert，然后发现了以下现象：

首先在 binlog 中，发现这条 SQL 运行了 2 秒。（上一问中, 我们知道 BEGIN 的 exec_time 等于事务第一个 SQL 的 exec_time，本例中就是 insert 的 exec_time）

但在慢日志中,发现这条 SQL 的 query_time 为 10 秒:

那么 binlog 和慢日志谁的时间更准确一些？

实验

首先我们按照第 02 问的步骤，准备一个慢 IO 的设备，使读操作和写操作都延迟 2000ms（在 02 问中是 100ms，需要调整 dmsetup 那一步的参数），此处省略步骤。

这是我们的慢 IO 设备和挂载点：

宽油建立一个数据库：

下个 SQL 看看：

观察 binlog，binlog 认为 SQL 执行了 2 秒：

观察慢日志，慢日志认为 SQL 执行了 10 秒：

与我们问题中的情况相同。

从实验结果猜测：慢日志更准确一些，而 binlog 中的执行时间不包括由于 binlog 带来的延迟。

原理

MySQL 实际上的执行步骤跟我们猜测的类似，一个 SQL 涉及以下几个时间点：

1. SQL 开始

2. 记录 general log

3. SQL 解析

4. SQL 执行过程中，生成 binlog event

5. binlog 刷盘

6. 记录慢日志

binlog 中的 SQL 执行时间，是从 1 到 4 的时间，而慢日志中的 SQL 执行时间，是从 1 到 6 的时间。

本实验中，我们通过慢 IO 拖慢了步骤 5，使得两个时间的差异比较明显。

正常运维过程中，大家也可以通过两个时间戳的差异，来猜测 binlog 刷盘效率是否出了问题。