问题:

在小伙伴们学习的过程中,执行了一个 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 刷盘效率是否出了问题。

关于 MySQL 的技术内容,你们还有什么想知道的吗?赶紧留言告诉小编吧!