第30问:binlog 说一个 begin 执行了 5 秒,是谁错了? - 技术分享 - 新闻资讯 - 爱可生

第30问:binlog 说一个 begin 执行了 5 秒,是谁错了?

发布时间:2021-03-02 浏览次数:323

关键字:MySQL建立数据库MySQL课程MySQL连接数据库

问题

编辑搜图


一段 binlog 如上图,为什么这个 BEGIN 执行了 5 秒,是数据库卡了还是统计错了?


实验

先宽油做一个数据库:

编辑搜图

为了实验方便,我们改一下 mysql 的提示符,将命令行的当前时间显示在上面,

编辑搜图


将 binlog 格式改为 statement:

编辑搜图


创建一个实验表:

编辑搜图


跑一个事务:

编辑搜图


解开对应的 binlog:

编辑搜图

得到结果:

编辑搜图


我们看到三组时间:

1. 黄色部分:

每个 binlog event 前都会带有一个时间戳,这个时间戳和我们执行每个语句时的开始时间对应(截图中会偶尔偏差 1s,是因为 SQL 是手工敲的,需要一些时间)

2. 红色部分:

exec_time,每个语句的 exec_time 与语句的执行时间对应,本例中是与 sleep 的时长对应,
而 BEGIN 语句的 exec_time 始终与第一个句子的执行时间相同,其原因是 BEGIN 是在第一个语句执行时,与第一个语句同时写入 binlog 的,这就引起了 exec_time 统计的偏差:BEGIN 的 exec_time 实际上是其后第一个语句的执行时间。

3. 每个语句前会有一个 SET TIMESTAMP,我们都知道其会影响语句中的时间函数,比如 now() 函数的时间基准。

我们重做一次实验,验证一下手工 SET TIMESTAMP 的影响:




如上图,我们改变了 timestamp。来看一下 binlog 的表现:

从图中可以看到:

1. binlog event 的时间戳随着 timestamp 变化,不再表示语句的实际开始时间,而是都置为设定的时间。

2. exec_time 计算出现了错误,不再表示实际的运行时间

由上面的实验,我们得到如下结论:

1. exec_time 是语句的运行时间。会受到 set timestamp 影响变得不准确

2. binlog event 的时间戳,是语句实际的开始时间。会受到 set timestamp 影响失去意义。

关键字:MySQL建立数据库MySQL课程MySQL连接数据库

相关推荐

产品试用 产品试用
400-820-6580 免费电话