MySQL主从同步机制与同步延时问题追查过程

桃扇骨 2022-02-22 11:58 281阅读 0赞

作为一名DBA，在工作中会经常遇到一些MySQL主从同步延迟的问题，这些同步慢的问题，其实原因非常多，可能是因为主从的网络问题导致，可能是因为网络带宽问题导致，可能是因为大事务导致，也可能是因为单线程复制导致的延迟。

今天遇到一个问题，Mysql持续报错，主从同步延时数过大或错误。所以这篇文章给大家分享下主从同步的机制原理以及问题排查思路。

**故障表现**

最直观的表现为：

[?][Link 1]

<table> 
 <tbody> 
 <tr> 
 <td> 1 2 3 4 5 6 7 </td> 
 <td> <code>mysql&gt; show slave status\G;</code> <code>&nbsp;</code><code>// 状态一</code> <code>&nbsp;</code><code>Seconds_Behind_Master: </code><code>NULL</code> <code>&nbsp;</code><code>// 状态二</code> <code>&nbsp;</code><code>Seconds_Behind_Master: 0</code> <code>&nbsp;</code><code>// 状态三</code> <code>&nbsp;</code><code>Seconds_Behind_Master: 79</code> </td> 
 </tr> 
 </tbody> 
</table>

连续查询，大部分时间该属性值=0，偶发性出现Null或者79等延时值。导致观察主从同步延时的监控持续报警。

**故障原因及解决方案**

多台备机的server-id一致，导致主机无法长时间同某一台备机连接，进而无法正常同步。

修改server-id后，重启数据库恢复。

**主从同步机制**

[![201921593847733.jpg_201911594011][]][201921593847733.jpg_201911594011]

MySQL的主从同步，又称为复制（replication），是一种内置的高可用高性能集群解决方案，主要功能有：

*  数据分布：同步不需要很大带宽，可以实现多数据中心复制数据。
 *  读取的负载均衡：通过服务器集群，可以通过DNS轮询、Linux LVS等GSLB（全局负载均衡）方式，降低主服务器的读压力。
 *  数据库备份：复制是备份的一部分，但并不能代替备份。还需要与快照相结合。
 *  高可用性和故障转移：从服务器可以快速切换为主服务器，减少故障的停机时间和恢复时间。

主从同步分为3步：

1.  主服务器（master）把数据更改记录到二进制日志（binlog）中。
2.  从服务器（slave）把主服务器的二进制日志复制到自己的中继日志（relay log）中。
3.  从服务器重做中继日志中的日志，把更改应用到自己的数据库上，达到数据的一致性。

主从同步是一个异步实时的同步，会实时的传输，但存在执行上的延时，如果主服务器压力很大，延时也会相应扩大。

通过上面的图，可以看到一共需要3个线程：

1.  主服务器的日志传送线程：负责将二进制日志增量传送到备机
2.  从服务器的I/O线程：负责读取主服务器的二进制日志，并保存为中继日志
3.  从服务器的SQL线程，负责执行中继日志

**查看MySQL线程**

我们可以使用`show full processlist;`命令来查看MySQL的状态：

主机的状态：

[![201921594629581.png_201911594639][]][201921594629581.png_201911594639]

备机的状态：

[![201921594647063.png_201911594654][]][201921594647063.png_201911594654]

可以看到，我的集群架构为1台主机、4台备机，所以在主机中有4个同步线程（已经发送所有的binlog数据到备机，等待binlog日志更新），1个查看命令线程（show full processlist）。在备机中有1个查看命令线程，1个I/O线程（等待主机发送同步数据事件），1个SQL线程（已经读取了所有中继日志，等待I/O线程来更新它）。

**查看同步状态**

因为主从同步是异步实时的，也就是会存在延时的情况，我们可以通过show slave status;来查看备机上的同步延时：

![201921594713727.jpg_201911594733][]

在主从同步中我们需要关注的一些属性，已经给大家标红了：

*  Slave\_IO\_State: 当前I/O线程的状态
 *  Master\_Log\_File: 当前同步的主服务器的二进制文件
 *  Read\_Master\_Log\_Pos: 当前同步的主服务器的二进制文件的偏移量，单位为字节，如图中为已经同步了12.9M(13630580/1024/1024)的内容
 *  Relay\_Master\_Log\_File: 当前中继日志同步的二进制文件
 *  Slave\_IO\_Running: 从服务器中I/O线程的运行状态，YES为运行正常
 *  Slave\_SQL\_Running: 从服务器中SQL线程的运行状态，YES为运行正常
 *  Exec\_Master\_Log\_Pos: 表示同步完成的主服务器的二进制日志偏移量
 *  Seconds\_Behind\_Master: 表示从服务器数据比主服务器落后的持续时长

同样可以通过show master status;命令来查看主服务器的运行状态：

[![201921594758322.png_20191159487][]][201921594758322.png_20191159487]

正常运行的主从同步状态：

> Slave\_IO\_Running: YES  
> Slave\_SQL\_Running: YES  
> Seconds\_Behind\_Master: 0

**问题排查**

在理解了主从同步的机制后，再来看今天遇到的问题，通过查看备机状态，我们观察在三种状态下的几个关键属性值：

[?][Link 1]

<table> 
 <tbody> 
 <tr> 
 <td> 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 </td> 
 <td> <code>mysql&gt; show slave status\G;</code> <code>#状态一：</code> <code>&nbsp;</code><code>Slave_IO_State: Reconnecting </code><code>after</code> <code>a failed master event </code><code>read</code> <code>&nbsp;</code><code>Slave_IO_Running: </code><code>No</code> <code>&nbsp;</code><code>Slave_SQL_Running: Yes</code> <code>&nbsp;</code><code>Seconds_Behind_Master: </code><code>NULL</code> <code>#状态二：</code> <code>&nbsp;</code><code>Slave_IO_State: Waiting </code><code>for</code> <code>master </code><code>to</code> <code>send event</code> <code>&nbsp;</code><code>Slave_IO_Running: Yes</code> <code>&nbsp;</code><code>Slave_SQL_Running: Yes</code> <code>&nbsp;</code><code>Seconds_Behind_Master: 0</code> <code>#状态三：</code> <code>&nbsp;</code><code>Slave_IO_State: Queueing master event </code><code>to</code> <code>the relay log</code> <code>&nbsp;</code><code>Slave_IO_Running: Yes</code> <code>&nbsp;</code><code>Slave_SQL_Running: Yes</code> <code>&nbsp;</code><code>Seconds_Behind_Master: 636</code> </td> 
 </tr> 
 </tbody> 
</table>

通过[MySQL主从复制线程状态转变][MySQL]，我们可以看到三种状态的不同含义：

[?][Link 1]

<table> 
 <tbody> 
 <tr> 
 <td> 1 2 3 4 5 6 7 8 9 10 </td> 
 <td> <code># 状态一</code> <code># 线程正尝试重新连接主服务器，当连接重新建立后，状态变为Waiting </code><code>for</code> <code>master </code><code>to</code> <code>send event。</code> <code>Reconnecting </code><code>after</code> <code>a failed master event </code><code>read</code> <code># 状态二</code> <code># 线程已经连接上主服务器，正等待二进制日志事件到达。如果主服务器正空闲，会持续较长的时间。如果等待持续slave_read_timeout秒，则发生超时。此时，线程认为连接被中断并企图重新连接。</code> <code>Waiting </code><code>for</code> <code>master </code><code>to</code> <code>send event</code> &nbsp; <code># 状态三</code> <code># 线程已经读取一个事件，正将它复制到中继日志供SQL线程来处理。</code> <code>Queueing master event </code><code>to</code> <code>the relay log</code> </td> 
 </tr> 
 </tbody> 
</table>

在这里，我们可以猜测，由于某些原因，从服务器不断的和主服务器进行断开并尝试重连，重连成功后又再次断开。

我们再看看主机的运行情况：

[![201921594816659.jpg_201911594838][]][201921594816659.jpg_201911594838]

发现问题出在10.144.63.\*和10.144.68.\*两台机器上，我们查看其中一台的错误日志：

> 190214 11:33:20 \[Note\] Slave: received end packet from server, apparent master shutdown:   
> 190214 11:33:20 \[Note\] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.005682' at postion 13628070

拿到关键字Slave: received end packet from server, apparent master shutdown: Google搜索一下，在文章[Confusing MySQL Replication Error Message][]中可以看到原因为两台备机的server-id重复。

> One day it happen to me, and took me almost an hour to find that out.  
> Moving foward I always use a base my.cnf to I copy to any other server and the first thing is to increase the server-id.  
> Could MySQL just use the servername intead of a numeric value?

**问题修复**

定位了问题，我们确认下是否重复，发现两台备机的该字段确实相同：

[?][Link 1]

<table> 
 <tbody> 
 <tr> 
 <td> 1 2 3 4 5 6 7 </td> 
 <td> <code>vim my.cnf</code> &nbsp; <code>#replication</code> <code>log-bin=mysql-bin</code> <code># 这个随机数字相同导致的</code> <code>server-</code><code>id</code><code>=177230069</code> <code>sync_binlog=1</code> </td> 
 </tr> 
 </tbody> 
</table>

更改一个其他不同的数字，保存，重启MySQL进程，报警恢复。

**总结**

最终来看，这个问题的解决非常简单，但从刚开始的迷茫到最后的思路清晰，都是我们排查问题所常见的，这篇文章的主要收获是让你明白主从同步的机制和追查问题的思路，希望下次我们都能很快的解决主从同步带给我们的问题。

好了，以上就是这篇文章的全部内容了，希望本文的内容对大家的学习或者工作具有一定的参考学习价值，如果有疑问大家可以留言交流，谢谢大家对脚本之家的支持。

[Link 1]: https://www.jb51.net/article/156310.htm#
[201921593847733.jpg_201911594011]: https://files.jb51.net/file_images/article/201902/201921593847733.jpg?201911594011
[201921594629581.png_201911594639]: https://files.jb51.net/file_images/article/201902/201921594629581.png?201911594639
[201921594647063.png_201911594654]: https://files.jb51.net/file_images/article/201902/201921594647063.png?201911594654
[201921594713727.jpg_201911594733]: https://files.jb51.net/file_images/article/201902/201921594713727.jpg?201911594733
[201921594758322.png_20191159487]: https://files.jb51.net/file_images/article/201902/201921594758322.png?20191159487
[MySQL]: https://www.jb51.net/article/156311.htm
[201921594816659.jpg_201911594838]: https://files.jb51.net/file_images/article/201902/201921594816659.jpg?201911594838
[Confusing MySQL Replication Error Message]: https://www.percona.com/blog/2008/06/04/confusing-mysql-replication-error-message/