MySQL事务还没提交，Canal就能读到消息了？

【问题描述】

开发有天碰到一个很奇怪的问题，他的场景是这样子的：
通过Canal来订阅MySQL的binlog, 当捕获到有数据变化时，回到数据库，反查该数据的明细，然后做进一步处理。
有一次，他碰到一个诡异的现象：

1.  Canal收到消息，有一条主键id=31019319的数据插入
2.  11:19:51.081, 应用程序去反查数据库，11:19:51.084查询完毕，发现id=31019319的数据为空
3.  过几分钟后，开发去手工查数据库，发现id=31010319的数据是存在的，每次插入的时候，我们会在数据库记录插入时间，发现插入的时间是11:19:51.059。

让开发感到困惑的是11:19:51.059写入的数据，11:19:51.081去查询，应该是能查到数据的呀。我们首先排除了读写分离，主从分离等场景，Canal订阅和数据库查询都是在Master上，所以这个问题就变得非常诡异了。

【问题分析】

因为中间夹杂着Canal, 而Canal是通过binlog读取的，这个问题我们可以简化为：当我们在master插入一条数据，该数据在master还没落库，但是在Slave却能查到。我们尝试重现这种场景。因为我们是采用GTID模式，GTID也就是全局事务编号，我们通过跟踪GTID来调试问题。

我们创建一个测试表如下：

CREATE TABLE `gtid_debug` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `name` varchar(10) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8

此时，在Master和Slave上，分别收集到的GTID信息如下：

角色	@@global_gtid_executed	@@port
Master	be7945f1-3613-11ec-8353-98039ba5775a:1-16	3306
Slave	be7945f1-3613-11ec-8353-98039ba5775a:1-16	3307

我们在Master上开启gdb调试，在函数ReplSemiSyncMaster::commitTrx上设置断点。

步骤1：

在Master上，开启Session1, 插入一条数据：

insert into gtid_debug(name)values('test1'); 

此时会hit到断点。

步骤2：

在Slave上，开启Session2, 查看GTID:

角色	@@global_gtid_executed	@@port
Slave	be7945f1-3613-11ec-8353-98039ba5775a:1-17	3307

也就是说，事务在Slave上，开始走字了。
我们进行如下查询：可以看到，在Slave这条记录能被查询到。

slave>select * from test.gtid_debug;
| ID   | NAME  |
| ---- | ----- |
| 1    | test1 |

步骤3：

在Master上，我们开启Session3, 查看GTID, 这个session也会被断点中断，我们继续执行下一步，直到查询结果返回。注意，此时Session1还停留在断点上，未提交成功。

角色	@@global_gtid_executed	@@port
Master	be7945f1-3613-11ec-8353-98039ba5775a:1-16	3306

并进行如下查询，返回结果为空：

master>select * from test.gtid_debug;
Empty set 

所以我们重现了问题，也就是说，在Master插入数据，事务还没有提交，但在Slave就能查到了。 Slave跑的比Master还快。

【原因分析】

重现了问题后，我们对问题进行分析，并查看了相应代码，发现是半同步复制的模式导致，半同步复制有两种模式: After_Sync(5.7版本默认)模式和After_Commit（5.6版本默认）模式。我们线上的版本是5.7，所以采用的是After_Sync模式。

从上图可以看到，一个事务在半同步模式下提交，无论是after_sync还是after_commit，都要经历4个阶段：

1. InnoDB Redo File Prepare Write
2. Binlog File Flush & Sync
3. InnoDB Redo File Commit (同时释放事务持有的锁)
4. Send binlog to Slave

After_Commit模式的四个阶段顺序为: 1->2->3->4, 而after_sync模式的顺序为1->2->4->3.

在5.7默认的after_sync模式下，确实存在先发送binlog到Slave, 然后再进行事务提交的场景。这时候大家会问了，为啥5.7把半同步复制改为after_sync模式了？这主要是因为after_commit机制存在数据丢失的风险。我们可以设想一下，在3->4的T1时间段，新数据对其它Session已经可见，突然Master挂了，MySQL进行主从切换，这时事务在Master上完成，如在Slave上不存在，切换后，业务会发现之前能查到的数据又没了。

而在after_sync模式下，其执行的顺序为1->2->4->3. 也就是说Master在收到Slave的应答之后，才Commit事务。在3->4的T1时间段内，因事务还未Commit，新数据对其它Session还不可见，所以看上去像比Slave跑的更慢。具体可以参考网上关于这两种模式的讨论。

【解决建议】

我们分析清楚问题之后，解决的方法就比较简单了。不建议改为after_commit模式，虽然改为after_commit模式，可以保证事务在Master落地后，Canal才会读到消息，但存在主从切换事务丢失的风险。我们的解决方法，是在Canal消息处理时，延后1秒再处理。这样解决方法比较合理。因为一般来讲，业务对消息的实时性不是特别高。