mysql内核测试,MySQL 5.7内核复制中的一个小坑

问题背景

最近在写一个作为MySQL Slave的角色的程序，连接到MySQL Master使用MySQL复制协议来Dump Binlog事件流。很自然，这个程序在第一次运行的时候，其事务GTIDSet是空的，那么在和Master建立主从连接的时候，是无法正常建立的。原因是：

参考：https://github.com/mysql/mysql-server/blob/5.7/sql/rpl_binlog_sender.cc

Master判断一个Slave Dump请求合法必须满足两个条件：Slave请求的GTIDSet是Master Executed GTIDSet的一个子集

Master Purged GTIDSet是Slave请求的GTIDSet的一个子集

显然，程序第一次运行的时候无法满足条件2(只要Master存在Purged GTIDSet)，一个比较自然的错误处理逻辑是：

如果Slave程序发现连接到Master报的错误码是ER_MASTER_HAS_PURGED_REQUIRED_GTIDS，对应错误信息是：The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.的时候，我们查询Master的Purged GTIDSet，将这个GTIDSet merge到本地，以merge后的GTIDSet作为新的开始位置请求Dump。把这个特殊场景考虑进程序的一个逻辑中，避免手动来处理。

但测试发现，MySQL Server(5.7.17)返回的错误码为：ER_MASTER_FATAL_ERROR_READING_BINLOG，但错误信息为：The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.。而ER_MASTER_FATAL_ERROR_READING_BINLOG其实是一个很宽泛的错误码，关键是在这个场景中，Master Dump线程还在check阶段(Binlog_sender::check_start_file()这个函数中)，根本没到读取Binlog文件的环节。所以我们认为这是一个小坑！

Root cause追踪

参考：rpl_binlog_sender.cc，我们可以看到，当Master的Purged GTIDSet不是Slave请求GTIDSet的一个子集的时候，errmsg被设置为了期望的“The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.”。但error code是在set_fatal_error函数中设置的，我们继续看这个函数：

742     if (!gtid_state->get_lost_gtids()->is_subset(m_exclude_gtid))

743 {

744 errmsg= ER(ER_MASTER_HAS_PURGED_REQUIRED_GTIDS);

745 global_sid_lock->unlock();

746 set_fatal_error(errmsg);

747       return 1;

748 }

set_fatal_error函数实现：rpl_binlog_sender.h，可以看到error code被设置成了ER_MASTER_FATAL_ERROR_READING_BINLOG，也就是MySQL Server返回给应用程序的错误码和错误信息不匹配。

382   void set_fatal_error(const char *errmsg)

383 {

384 set_error(ER_MASTER_FATAL_ERROR_READING_BINLOG, errmsg);

385 }

最后是我们写的程序，期望根据error code来写处理逻辑行不通，只好修改成strcasecmp来字符串匹配。

642 len = cli_safe_read(g_mysql_, NULL);

643       if (len == packet_error || (long)len < 1) {

644 LOG_ERR("cli_safe_read failed: (%d - %d - %s).",

645 mysql_errno(g_mysql_),

646 ER_MASTER_HAS_PURGED_REQUIRED_GTIDS,

647 mysql_error(g_mysql_));

648         // TODO: why errno is incorrect!

649if (ER_MASTER_HAS_PURGED_REQUIRED_GTIDS == mysql_errno(g_mysql_)){

650 LOG_INF("Will try to merge purged gtidset next round!");

651 new_master_purged = true;

652 }

653         goto err_t;

654 }

上面这段程序，测试会得到MySQL Server端返回error code 1236，但是其实错误信息是error code 1789的内容。

cli_safe_read failed: (1236 - 1789 - The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.).