【问题描述】
通过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上,所以这个问题就变得非常诡异了。
【问题分析】
我们创建一个测试表如下:
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 |
步骤1:
在Master上,开启Session1, 插入一条数据:
insert into gtid_debug(namevalues('test1';
此时会hit到断点。
步骤2:
角色 | @@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还快。