复制延迟问题排查 一、常见原因 产生延迟的根本原因在于MySQL复制是基于逻辑日志binlog进行异步的数据复制的，事务的binlog日志要通过网络传输到从库，再在从库上完成一次逻辑的回放，各个阶段的耗时都有可能被放大，导致延迟。在我们的经验中，诱发延迟的常见原因有： 1.主从配置不一致,从库配置较低导致回放过慢 2.主从库之间的网络带宽太低 3.主库的QPS过高(应用负载高),从库回放时无法达到主库的并发程度 4.主库对无主键的表做全表更新或全表删除操作，row-based binlog replication 时，从库回放这个事务时会做n次全表扫描，n为表的总行数(常见于业务数据库处理时临时表的清理) 5.主库在某时间段执行大量的大事务(大量的插入，更新，删除操作，如跑批操作) 6.主库在对表做DDL操作 7.从库备份触发Waiting For Global Read Lock导致从库回放线程在备份时间内无法回放数据 8.从库没有配置并行复制 二、IO线程排查 排查IO线程是否存在延迟主要是判断从库接收到的binlog(从库叫Relay Log)是否与主库当前最新的binlog保持一致或者仅仅细微的差别,可以通过以下方式分析 1. 获取主库当前的binlog name、position、executed_gtid_set root@localhost[(none)]> show master statusG *************************** 1. row *************************** File: mysql-bin.000001 Position: 149654676 Binlog_Do_DB: Binlog_Ignore_DB: Executed_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-67963 2. 获取从库当前读取的binlog位置 root@localhost[(none)]> show slave statusG *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 10.186.61.162 Master_User: repl Master_Port: 3306 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 149654676 Relay_Log_File: mysql-relay.000003 Relay_Log_Pos: 149654881 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes ... 输出内容过多,部分输出已省略 Seconds_Behind_Master: 1000 ... 输出内容过多,部分输出已省略 Retrieved_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-67963 Executed_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-42311 3. 结果比对 最后通过对比主从参数是否有明显的差异来判断IO线程是否有延迟。 主库： File、Position、Executed_Gtid_Set 从库： Master_Log_File 、Read_Master_Log_Pos、Retrieved_Gtid_Set 如示例中从库读取的binlog位置和主库当前最新的binlog位置均是mysql-bin.000001，Position点均为149654676,表示当前IO线程无延迟,需做进一步分析SQL线程情况。 也可通过主库中标红的Executed_Gtid_Set（主库当前已提交的事务GTID集合）和从库中Retrieved_Gtid_Set（从库读取到的事务GTID集合）的差值来做比。 三、SQL线程排查 主从延迟大部分原因在于从库的SQL线程回放过慢,这也是我们主要关注的排查点。 查看从库的复制状态 root@localhost[(none)]> show slave statusG *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 10.186.61.162 Master_User: repl Master_Port: 3306 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 149654676 Relay_Log_File: mysql-relay.000003 Relay_Log_Pos: 149654881 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes Slave_SQL_Running: Yes ... 输出内容过多,部分输出已省略 Exec_Master_Log_Pos: 148451632 Seconds_Behind_Master: 1000 Slave_SQL_Running_State: system lock ... 输出内容过多,部分输出已省略 Retrieved_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-67963 Executed_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-42311 关注示例中的两组状态：Master_Log_File、Read_Master_Log_Pos、Relay_Master_Log_File、Exec_Master_Log_Pos、Retrieved_Gtid_Set、Executed_Gtid_Set a) binlog位置 读取到的主库binlog的位置： Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 149654676 从库当前回放的位置（对应在主库的binlog位置）： Relay_Master_Log_File: mysql-bin.000001 Exec_Master_Log_Pos: 148451632 这里只差了1203044个position，没有binlog级别的落后，说明延迟不特别大。 b) 事务的GTID集合 读取到的主库的事务GTID集合： Retrieved_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-67963 从库已经回放的事务GTID集合： Executed_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-42311 这里说明从库上总共读取到了67963个事务的binlog，但是只回放到第42311个事务，如果IO线程没有延迟，则从库与主库相比延迟了25652个事务。 查看从库单位时间内的回放速度 在这个阶段可以反复执行show slave statusG，查看从库SQL线程位置的变化，或者通过这样的SQL查看一段时间内从库回放了多少个事务： mysql> select @@global.gtid_executed;select sleep(60);select @@global.gtid_executed; 如果Executed_Gtid_Set或者gtid_executed无变化，则说明从库卡在某个大事务上，60s都没有回放完，需要解析binlog查看回放的事务具体操作。 如果Executed_Gtid_Set有变化,但十分缓慢，比如60s统计内只回放了100个事务，可能也存在较大的事务，或者这批事务没有并发回放，也需要解析binlog进一步分析。当然也可能是从库服务器IO负载高、服务器配置低等原因。 如果统计到这60s内回放事务非常多，则说明当前位置回放速度正常，延迟可能是之前的事务导致的，而且主库QPS较高产生了较多的binlog，堆积到现在。这种情况可以持续观察，应该会慢慢的消除延迟。 解析主库binlog 如果从库回放的速度很慢，甚至slave_sql线程长时间停滞在一个位置，则我们需要根据这个位置去主库上解析binlog，分析这个位置是什么事务。 从show slave status输出中，找出这个几个位置： Relay_Master_Log_File: mysql-bin.000001 Exec_Master_Log_Pos: 148451632 Executed_Gtid_Set: 56929ffe-5d09-11ea-bb4e-02000aba3da2:1-42311 然后到主库上，解析mysql-bin.000001中从库正在回放的56929ffe-5d09-11ea-bb4e-02000aba3da2:42312这个事务，42312即42311的下一个事务: mysqlbinlog -vv --include-gtids='56929ffe-5d09-11ea-bb4e-02000aba3da2:42312' mysql-bin.000001|grep -v "# at"|less 注意要开启binlog_rows_query_log_events参数（意思为row格式时，binlog会以注释的形式记录具体的SQL语句，方便DBA排查问题）， 进一步判断该事务中涉及的DML操作数量（是否为大事务）： mysqlbinlog -vv --include-gtids='56929ffe-5d09-11ea-bb4e-02000aba3da2:42312' mysql-bin.000001|egrep "### UPDATE|### DELETE|### INSERT"|wc -l 最后附带一个binlog分析统计命令，可统计指定binlog中DML操作的数量： mysqlbinlog --no-defaults --base64-output=decode-rows -v -v mysql-bin.000001| awk '/###/ {if($0~/UPDATE|INSERT|DELETE/)count[$2" "$NF]++}END{for(i in count) print i," ",count[i]}' | column -t | sort -k2nr 三、解决方法 通用方法 针对MySQL复制延迟的问题，在选择硬件配置、存储引擎，设计业务逻辑和MySQL参数配置方面应使用以下指导思想，下列方法更多的是预防复制延迟的出现，在平时的巡检过程中，应该时刻关注客户现场的相关配置，例如是否有非innodb的表，是否没有开启并行复制，业务中是否存在大事务等等。 1.保持主从配置一致,也有利于主从切换后性能不会出现明显下降 2.开启并行复制等提升复制效率的参数，如下 slave-parallel-type=LOGICAL_CLOCK slave-parallel-workers=16 master_info_repository=TABLE relay_log_info_repository=TABLE relay_log_recovery=ON 3.确保所有表都有主键且全表清除使用truncate操作 4.将批量操作中大事务拆分为小事务执行,充分利用MySQL并行复制特性提升回放效率 5.使用gh-ost或POSC工具执行DDL,增加DDL的执行时间但减缓主从延迟问题 6.保证数据库中表的存储引擎为InnoDB,减少备份锁定时间 7.MySQL8.0版本的新特性中推出了binlog压缩功能，可降低带宽的消耗（新特性待验证） 临时方法 在主从复制延迟已经很严重的情况下，可使用如下方法来降低复制延迟，需要注意的是，在复制延迟的问题解决后，务必记得将大部分参数还原到原先的配置（以数据安全性为主的配置），并根据通用方法的思想来排查导致复制延迟问题的具体原因，并对症下药。 修改innodb_flush_log_at_trx_commit参数 此参数设置为0时表示MySQL会将日志缓冲区中的数据每秒一次地写入日志文件中，并且日志文件的刷盘操作同时进行。该模式下在事务提交的时候，不会主动触发写入磁盘的操作，效率最高，但是安全性也比较低，可能会丢失数据； mysql> SET @@GLOBAL.innodb_flush_log_at_trx_commit = 0; 修改sync_binlog参数 修改binlog的刷盘时机，当sync_binlog=0时，事务提交之后，MySQL不做fsync之类的磁盘同步指令刷新binlog_cache中的信息到磁盘，而让Filesystem自行决定什么时候来做同步，或者cache满了之后才同步到磁盘，这个是性能最好的。 mysql> SET @@global.sync_binlog = 0; 增加从库的change buffer缓冲池比例 innodb_change_buffer_max_size控制着change buffer的大小，默认为buffer pool的25%，最大可以设置为50% mysql> set global innodb_change_buffer_max_size = 50;