返回

剖析 MySQL 复制中断案例,深入揭示故障根源

见解分享

正文:

在上周四(2018-07-05),下午1点左右,我们收到一位客户的反馈,称其业务数据库复制中断。该客户使用了我们的 easydb 产品,当时 easydb 上的主备状态信息如下:

mysql> show slave statusG;
+--------------------+-----------------+
| Slave_IO_State   | Waiting for binlog to be purged |
+--------------------+-----------------+

通过 show slave statusG 命令可以查看复制线程详细的工作状态,对于判断复制中断的原因有一些指导性意义。

+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Variable        | Value                                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Slave_IO_Running | Yes                                                                                                                                                             |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Slave_SQL_Running | No                                                                                                                                                              |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Last_IO_Error    | Got fatal error 1236 from master when reading data from binary log                                                                                                |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Last_SQL_Error   | Got fatal error 1236 from master when reading data from binary log                                                                                                |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Slave_IO_Retry_Cnt | 46                                                                                                                                                           |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Slave_SQL_Retry_Cnt | 14                                                                                                                                                           |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Seconds_Behind_Master | NULL                                                                                                                                                         |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Master_Host     | 10.0.100.1                                                                                                                                                    |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Master_User     | repl                                                                                                                                                           |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Master_Port     | 3306                                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Connect_Retry    | 60                                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Master_LogFile   | mysql-bin.000003                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Read_Master_Log_Pos | 117                                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Exec_Master_Log_Pos | 117                                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Relay_Log_File   | relay-bin.000001                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Relay_Log_Pos   | 2245472                                                                                                                                                        |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Relay_Master_Log_File | mysql-bin.000003                                                                                                                                            |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| SQL_Delay        | 0                                                                                                                                                             |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Slave_SQL_Running_State | thread_killed                                                                                                                                                 |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Last_IO_Error_Timestamp | 2018-07-05 13:05:16                                                                                                                                   |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+
| Last_SQL_Error_Timestamp | 2018-07-05 13:05:16                                                                                                                                   |
+------------------+-----------------------------------------------------------------------------------------------------------------------------------------------+

show slave statusG 命令的输出可以看出,复制中断的原因是 "Got fatal error 1236 from master when reading data from binary log"。这表明复制线程在从主库读取二进制日志时遇到了错误 1236。

mysql> show binary logs;
+-----------------+-----------+
| Log_name       | File_size |
+-----------------+-----------+
| mysql-bin.000001 | 1024      |
| mysql-bin.000002 | 1024      |
| mysql-bin.000003 | 4096      |
+-----------------+-----------+

接着,我们检查了主库的二进制日志文件。发现 mysql-bin.000003 文件大小为 4096 字节,而从库的 Relay_Log_Pos 为 2245472,这表明从库已经将 mysql-bin.000003 文件前 2245472 字节的内容复制到了中继日志中。

为了进一步定位问题,我们查看了 mysql-bin.000003 文件的第 2245472 字节附近的内容。发现该处有一条 DELETE 语句,删除了表 user 中的一条记录。

DELETE FROM `user` WHERE `id` = 1234;

我们怀疑这条 DELETE 语句可能导致了复制中断。因为从库在执行这条语句时,发现表 user 中没有 id 为 1234 的记录,因此无法执行删除操作。

为了验证我们的猜测,我们使用如下命令在主库上执行了这条 DELETE 语句:

DELETE FROM `user` WHERE `id` = 1234;

结果发现,这条语句执行成功,并没有导致主库的复制中断。这表明我们的猜测是错误的。

我们继续排查问题,最终发现复制中断的原因是主库上的磁盘空间不足。当主库上的磁盘空间不足时,MySQL 会停止写入二进制日志,导致从库无法获取二进制日志的内容,从而引发复制中断。

我们为客户扩大了主库的磁盘空间,并重新启动了 MySQL 服务。复制中断的问题得到了解决。

通过这个案例,我们可以总结出以下几点经验:

  1. 在遇到复制中断问题时,首先要查看 show slave statusG 命令的输出,了解复制中断的原因。
  2. 如果复制中断的原因是 "Got fatal error 1236 from master when reading data from binary log",则需要检查主库的二进制日志文件,定位导致复制中断的具体语句。
  3. 如果主库上的磁盘空间不足,可能会导致复制中断。因此,需要定期检查主库的磁盘空间使用情况,避免磁盘空间不足的情况发生。
  4. 当复制中断问题得到解决后,需要重新启动 MySQL 服务,以便复制线程能够重新启动。

希望这个案例能够对您有所帮助,让您在遇到复制中断问题时能够快速定位问题并解决问题。