“Replication”作为MySQL原生的数据同步功能，在MySQL的高可用架构中起着至关重要的作用。本文梳理了UCloud在运维公司MySQL高可用产品UDB过程中遇到的复制问题，总结了复制异常时复制异常的排查方法。一、错误检查1、收集复制信息当复制出现异常时，首先收集与复制和错误相关的信息，主要通过以下方式收集。1.1查看showslavestatus执行命令“showslavestatus”查看复制相关信息，主要关注几条信息：Master_Log_File:MySQL-bin.000063Read_Master_Log_Pos:282657539IO线程读取主库的binlog文件名和位置在二进制日志中。这两个字段表示复制过程中binlog从主库传输到备库的进度。Relay_Log_File:MySQL-relay.000002Relay_Log_Pos:313885SQL线程执行到中继日志文件名和中继日志中的位置。Relay_Master_Log_File:MySQL-bin.000002Exec_Master_Log_Pos:316585SQL线程执行到binlog文件名对应的relaylog以及binlog在主库的位置。这四个字段表示复制过程中主库数据在备库上的回放进度。Slave_IO_Running:YesSlave_SQL_Running:No当前问题出在哪个线程？IO线程或SQL线程。Retrieved_Gtid_Set:ed7c5ee4-762d-11e6-ab9e-6c92bf24c36a:14-3920163Executed_Gtid_Set:04ffb4f5-762e-11e6-81e4-6c92bf26c5c2:1这两个字段只有开启GTID后才有意义。表示binlog中IO线程收到的事务对应的GTID和SQL线程执行的事务对应的GTID。这里的GTID不会因为复制而改变，即主库的GTID对应的事务必须在主库执行完后通过复制发送。备库GTID对应的事务必须由备库执行。Last_Errno/Last_IO_Errno/Last_SQL_ErrnoLaset_Error/Last_IO_Error/Last_SQL_ErrorIO/SQL线程错误描述说明1.2查看错误日志错误日志记录了mysqld的错误信息，即replication的错误信息，同时也记录了replicationstart和replication的相关信息stop,record位置可以通过以下方式查看：在错误日志中，主要关注以下信息。(1)启动复制(startslave)从库启动复制时，错误日志会记录复制的起始位置，包括IO线程读取主库binlog的起始位置和从库的起始位置由SQL线程执行的中继日志。同时错误日志也会记录复制开始的具体时间。2017-04-17T14:47:19.691088Z7[Note]SlaveI/Othreadforchannel'':connectedtomaster'repl@192.168.150.21:30001',replicationstartedinlog'binlog001.000002'atposition1942017-04-17T14:47:19.68ZlaveSQLlaveSQLlaveSthreadNote377''initialized,startingreplicationinlog'binlog001.000002'atposition194,relaylog'./relaylog002.000217'position:407(2)停止复制(stopslave)当从库停止复制时，错误日志会记录IO时读取的信息threadstopsmasterbinlog的位置，以及停止复制的时间。2017-04-18T03:05:52.920750Z14[注意]Errorreadingrelaylogeventforchannel'':slaveSQLthreadwaskilled2017-04-18T03:05:52.922007Z13[注意]SlaveI/Othreadkilledwhilereadingeventforchannel''2017-04-18T03:02[Note/51.9123I/Othreadkilledwhilereadingeventforchannel]otthreadexitingforchannel'',readuptolog'binlog001.000002',position443(3)复制错误信息复制错误信息的描述会在showslavestatus的last_error中显示，但是如果错误信息比较长（尤其是多线程的情况下）-threadedreplication),showslavestatus没有完全显示所有的错误信息，需要查看错误日志才能查看完整的错误信息。例如：Last_Errno:1007Last_Error:Coordinatorstoppedbecausetherewereerror(s)intheworker(s).Themostrecentfailurebeing:Worker0failedexecutingtransaction'0c1b77a7-c113-11e6-9bd6-d4ae52a34783:4'atmasterlogbinlog001.000002,end_log_pos605.Seeerrorlogand/orperformance_schema.replication_applier_status_by_workertableformoredetailsaboutthisfailureorothers,ifany.Skip_Counter:0上记错误该信息不是对错误信息的完整描述，但是可以在错误日志中看到更完整的信息描述和错误发生的时间。2017-04-18T03:19:00.037806Z23[ERROR]SlaveSQLforchannel'':Worker0failedexecutingtransaction'0c1b77a7-c113-11e6-9bd6-d4ae52a34783:4'atmasterlogbinlog001.000002,end_log_pos605;databasemyiststcreatedatabase'Can'tcreatedatabase'错误'Defaultdatabase:'mydb3'.Query:'createdatabasemydb3',Error_code:10071.3查看二进制日志文件这里的二进制日志文件包括主库的binlog和从库的中继日志和binlog。主库的binlog是指主库执行的事务记录的binlog日志。从库的relaylog是指从库接收到主库的binlog日志。从库的binlog是指从从库的SQL线程（开启log-slave-updates）重现relaylog后记录的日志，以及从库执行的事务记录的binlog日志。二进制日志文件中记录的日志是以事件为单位执行的。例如，一条DML语句通常由4-5个事件组成，而一条DDL语句通常由2个事件组成。可以使用“showbinlogevents”命令或MySQLbinlog工具将二进制日志文件转换为可识别的格式。showbinlogevents的格式如下：上图为ROW格式binlog记录的内容，包含一条DML语句和一条DDL语句。DML语句包含GTID、QUERY、TABLEMAP、WRITEROW和XID五个事件，DDL语句包含GTID和QUERY两个事件。MySQLbinlog工具同样可以解析binlog，提供与showbinlogevent类似的event信息，以其中一个event为例来说明：#17041723:18:37serverid30001end_log_pos412CRC320x818b4058Write_rows:tableid110flags:STMT_END_FBINLOG'zdz0WBMxdQAALQAAAHQBAAAAAG4AAAAAAAEABG15ZGIAAkkxAAEDAAF0sqv/zdz0WB4xdQAAKAAAAJwBAAAAAG4AAAAAAAEAAgAB//4KGgAAWECLgQ=='/*!*/;###INSERTINTO`mydb`.`I1`###SET###@1=6666#at412(1)事件时间为主库执行事务的时间，与relaylog和binlog无关从库的时间，都是主库执行事务的时间。(2)Event的server_id记录是执行事务的数据库的server_id，可以用来区分事务是主库还是从库执行的。(3)Event的结束logpos。从库relaylog中的endlogpos就是主库中binlog对应的event的真实文件位置。在主库和从库的binlog中，endlogpos是binlog文件的真实位置。(4)EVENT的atxxxatxxx表示事件在文件中的真实位置。对于以上二进制日志文件的内容，我们需要关注的信息包括：Previous_gtidsevents记录了当前binlog之前执行的所有gtid信息，用于定位具体的gtid。GTID事件中对应的GTID与事务一一对应，表示该事务是主库执行的还是从库执行的。发生错误时，事务执行的时间，事务的执行和具体的语句。主库执行数据库操作后，相关日志记录在主库的binlog中。备库的IO线程收到主库传来的binlog日志后，将这些日志记录到relaylog中。如果在备库上启用了logslaveupdates选项，则SQL线程会在replaylog的重放过程中记录相关的binlog日志。这三个二进制文件日志的执行内容应该是一样的。1.4查看其他变量查看其他复制相关的系统变量或状态，如：执行“showvariableslike'gtid_mode'”查看是否启用了gtid；执行“showstatuslike'Rplsemisyncmasterstatus'”查看半同步复制的状态。这里就不一一列举了。2、排查错误收集到以上复制信息后，主要采用以下方法排查复制错误：2.1查看showslavestatus，查看是哪个线程（IO线程或SQL线程）出错，并排查出错原因。如果IO线程发生错误，记录错误发生时收到的binlog文件的名称和位置（如果启用了GTID，则记录GTID）；如果SQL线程发生错误，记录错误发生时执行的中继日志文件的名称和位置（如果启用了GTID，则记录GTID）。2.2查看错误日志，进一步确认错误原因。有些原因只会记录在错误日志中，不会在showslavestatus中显示。比如空间不足导致IO线程错误，网络中断导致IO线程异常。检查是否其他用户正常关闭复制或杀死复制相关线程导致复制不可用。检查是否是刚刚开始复制和错误发生时的语句，是否是第一次复制时执行的语句。如果是第一条语句，则需要考虑复制异常是否是由于构建复制错误导致的，以及复制相关的二进制日志文件是否由于意外宕机等其他因素导致的不正确。对比主库和备库的错误日志，查看是否出现了相同的复制错误，主库是否进行了特殊的错误处理。2.3比较二进制日志文件，比较备库正在接收的binlog和主库正在执行的binlog是否有冲突（备库接收的binlog文件和位置比主库执行的要大）数据库）。如果启用了GTID，则检查备库自身是否执行过数据库操作生成GTID，同时检查备库是否执行过比主库多的GTID，备库是否执行过其他主机的GTID。根据出错时的binlog文件和位置（或GTID），解析主库和备库的二进制文件，当相同文件和位置（或相同的GTID）。查看备库的二进制文件，查看备库是否进行了与主库冲突的操作。2.总结正常复制，应该是如下状态：查看复制状态，应该是正常的。例如showslavestatus显示IO线程和SQL线程的运行状态都是YES。比如半同步复制，showstatuslike“rpl%”表示半同步复制状态为ON。主库和备库都没有报复制相关的错误信息。二进制文件中记录的数据库操作内容主库和备库的日志文件要一致，主库和备库的数据内容要一致，通过以上信息对比分析，查看异常状态或日志可以为我们提供更多的帮助3.版本和配置一般情况下，不同的版本和配置只会导致各种信息的显示格式不同，不会对以上方法造成太大的影响。1.版本以上示例信息收集分析均在MySQL-5.7版本上进行，信息内容或提示可能存在一定差异不同大版本的存储方式。MySQL-5.6和MySQL-5.7在replication相关信息上有如下区别：Log：MySQL-5.6停止replication时，errorlog会记录错误信息：2017-04-1817:32:46682[注意]ERRERREADINGINGRAYLOGEVENT：SLAVESQLTHREADWASKILLED2017-04-1817：32：46682[错误]ErrorreRearreadingPacketFromserver：LosteNectionTomysqlServerDuringQuery（server_errno=2013）2017-04-1817：32：32：466666666682[nirnnonote172：466682]otthreadexiting,readuptolog'b5620.000004',position151GTID：MySQL-5.6的gtid_executed以全局系统变量的形式显示，MySQL-5.7以MySQL.gtid_executed表的形式显示。BINLOG：MySQL-5.6版本使用自增ID时，会使用如下事件记录自增ID#17041911:27:12serverid30061end_log_pos494CRC320x7a9f75c6IntvarSETINSERT_ID=1/*!*/;2、配置主要体现gtidmode和binlogformat的区别。(1)gtid_mode启用gtid时，gtid作为判断谁执行了事务，是否已经执行，事务接收，执行进度的判断标准。同时可以通过showslavestatus直观的看到gtid的接收和执行。当gtid关闭时，file和pos作为接收和执行的标准，serverid作为谁执行事务的标准。但是该笔交易对应的serverid并没有全部显示出来，所以我们很难排查问题。(2)binlog_formatbinlog_format影响binlog中记录的日志内容的格式。以同一条INSERT语句为例，binlog中记录的语句格式格式如下（仅显示差异）：#17041817:47:06serverid30001end_log_pos730CRC320xdaf9a789Querythread_id=154exec_time=0error_code=0SETTIMESTAMP=1492508826/*!*/;insertintomydb.m1values(13)/*!*/;rowformatrecordedinthebinlogformatisasfollows:#17041817:46:25serverid30001end_log_pos376CRC320xcfdad7cdTable_map:`mydb`.`m1`mappedtonumber114#at3717041817:46:25serverid30001end_log_pos416CRC320xed08eabeWrite_rows:tableid114flags:STMT_END_FBINLOG'ceD1WBMxdQAALQAAAHgBAAAAAHIAAAAAAAAEAABG15ZGIAAm0xAAEDAAHN19rPceD1WB4xdQAAKAAAAKABAAAAHIAAAAAAAAEAAgAB//4NAAAAvuoI7Q=='/*!*/;###INSERTINTO`mydb`.`m1`###SET###1=13#at416的作者专栏组织【本是《大U的技术课堂》，请微信联系作者♂(ucloud2012)】点此查看作者更多好文
