记一次MySQL从节点服务器宕机重启后，从节点出现主键冲突异常的处理

65 0 0

环境

MySQL 5.7 非GTID模式多线程复制。

现象

某MySQL数据库从节点因故障宕机（因故障直接宕机，非正常关闭），重启之后发现复制状态异常，show slave的结果中Slave_SQL_Running为No，错误代码为1062 error code，从系统表performance_schema.replication_applier_status_by_worker以及error log中显示某条数据因为已存在于从节点，主从复制的sql线程试图再次插入这个数据从而导致从节点上数据的主键冲突而失败

原因分析

上述故障发生之前，确信从节点不会写入数据，既然确信从节点的数据不是外界写入的，那么为什么从节点会在回放relay log过程中出现主键冲突错误？
这里在排除从节点的数据是外部写入的情况下，怀疑是sql线程“重复”回放relay log同一条事务造成的。

先梳理一下复制相关的几个重点参数的含义：

mysql> show slave status G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host:                      
                  Master_User:                                             
                  Master_Port: 
                Connect_Retry: 
              Master_Log_File: ***.000066            --从节点IO线程读到的master节点的binlog file
          Read_Master_Log_Pos: 64117146              --从节点IO线程读到的master节点的binlog file 的坐标位
               Relay_Log_File: ***.000143            --从节点正在apply哪个relaylog
                Relay_Log_Pos: 38472356              --从节点正在apply relaylog的坐标位，复制的过程会一直变化
        Relay_Master_Log_File: ***.000049            --从节点apply本地的relay log事件，在master上对应的master binlog file
             Slave_IO_Running: Yes
            Slave_SQL_Running: No
                   Last_Errno: 1062
                   Last_Error:
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 38472155             --从节点apply relay log事件位置在master上对应的master binlog file的位点（如何确定Exec_Master_Log_Pos会在回放relay log时同步更新？异常宕机之后呢？）
              Relay_Log_Space: 1848930175

再简单梳理一下从节点异常宕机，重新启动后复制的启动过程：
MySQL服务启动后，主从复制进程会自动启动（skip_slave_start = off）
1，IO 线程会根据Master_Log_File+Read_Master_Log_Pos继续去主节点拉binlog。
2，SQL 线程会根据Relay_Master_Log_File+Exec_Master_Log_Pos确定当前节点已经回放的relay log的文件和具体的位置，基于此坐标点位继续回放relay log。
如果回放relay log与更新坐标位是绝对准确的，那么MySQL重启后，SQL线程会继续基于这个坐标位点继续回放，理论上不会出错。
设想一下：一个事物已经“回放”过了，但是没有同步更新Relay_Master_Log_File+Exec_Master_Log_Pos坐标位点的情况下宕机，此时重启后会继续基于这个位点做回放，此时就会出现重复回放某个事务日志，其结果就会造成上面的逐渐冲突错误

事实上是不是这样呢？从这里：https://dev.mysql.com/doc/refman/8.0/en/show-replica-status.html，
发现官方文档对Exec_Master_Log_Pos（MySQL 8.0.23之后改名为Exec_Source_Log_Pos）的解释如下：
The position in the current source binary log file to which the replication SQL thread has read and executed, marking the start of the next transaction or event to be processed. This is set to zero for a replication channel with the GTID_ONLY setting after a server start. It will be updated when a transaction is executed or skipped.
You can use this value with the CHANGE REPLICATION SOURCE TO statement's SOURCE_LOG_POS option (from MySQL 8.0.23) or the CHANGE MASTER TO statement's MASTER_LOG_POS option (before MySQL 8.0.23) when starting a new replica from an existing replica, so that the new replica reads from this point. The coordinates given by (Relay_Source_Log_File, Exec_Source_Log_Pos) in the source's binary log correspond to the coordinates given by (Relay_Log_File, Relay_Log_Pos) in the relay log.
Inconsistencies in the sequence of transactions from the relay log which have been executed can cause this value to be a “low-water mark”. In other words, transactions appearing before the position are guaranteed to have committed, but transactions after the position may have committed or not. If these gaps need to be corrected, use START REPLICA UNTIL SQL_AFTER_MTS_GAPS. See Section 17.5.1.34, “Replication and Transaction Inconsistencies” for more information

翻译过来大概意思是：

复制SQL线程读取并执行了当前源二进制日志文件中的位置，标记了要处理的下一个事务或事件的开始。对于具有GTID_ONLY设置的复制通道，在服务器启动后，此值将设置为零。当事务被执行或跳过时，此值将被更新。

你可以在从一个现有副本开始新副本时使用此值（指的是Exec_Master_Log_Pos）与CHANGE REPLICATION SOURCE TO语句的SOURCE_LOG_POS选项（从MySQL 8.0.23开始）或CHANGE MASTER TO语句的MASTER_LOG_POS选项（在MySQL 8.0.23之前）一起使用，以便新副本从此点（指的是Exec_Master_Log_Pos）开始读取。源的二进制日志中的（Relay_Source_Log_File，Exec_Source_Log_Pos）坐标对应于中继日志中的（Relay_Log_File，Relay_Log_Pos）坐标。

从中继日志中已执行的事务序列（ the sequence of transactions）中的不一致可能会导致此值成为“低水位标记”（low-water mark）。换句话说就是：出现在该位置之前的事务确实是被提交了的，但位置之后的事务可能已经提交或未提交。如果需要纠正这些差距，请使用START REPLICA UNTIL SQL_AFTER_MTS_GAPS。有关更多信息，请参阅第17.5.1.34节“复制和事务不一致性”。

继续参阅第17.5.1.34节“复制和事务不一致性： https://dev.mysql.com/doc/refman/8.0/en/replication-features-transaction-inconsistencies.html中提到
Source binary log position lag.Even in the absence of gaps, it is possible that transactions after Exec_master_log_pos have been applied. That is, all transactions up to point N have been applied, and no transactions after N have been applied, but Exec_master_log_pos has a value smaller than N. In this situation, Exec_master_log_pos is a “low-water mark” of the transactions applied, and lags behind the position of the most recently applied transaction. This can only happen on multithreaded replicas. Enabling replica_preserve_commit_order or slave_preserve_commit_order does not prevent source binary log position lag.

源binlog位置延迟。即使没有gaps，也可能会出现Exec_master_log_pos之后的事务被回放的情况（笔者注：从节点上Exec_master_log_pos比实际apply的log位置要小的情况）。也就是说，所有N 点位之前的事务都已applied，并且N之后的事务都没有被应用，但Exec_master_log_pos的值小于N。在这种情况下，Exec_master_log_pos是已应用事务的“低水位标记”（low-water mark），并且落后于最近应用的事务的位置。这只能在多线程复制上发生。启用replica_preserve_commit_order或slave_preserve_commit_order不会阻止源二进制日志位置延迟。

事实上，多种情况下都潜在 Replication and Transaction Inconsistencies

上述文档证支持上面的猜测：
因为Exec_Master_Log_Pos是延迟更新的，MySQL slave节点重启后，sql线程在“重复”回放relay log同一条事务造成的主键冲突，在从节点宕机之前，某一条事务（insert操作）已经被回放并写入数据库中，此时没来得及更新Exec_Master_Log_Pos信息的情况下宕机，从其之后从Exec_Master_Log_Pos开始回放relay，但是当前Exec_Master_Log_Pos之后的一个或者多个事务在（宕机之前）已经被回访过，(重启之后)再次回放的过程就会发生逐渐冲突错误。