MySQL 复制环境如何处理 'Got Fatal Error 1236' 或 MY-013114 Error

2024-06-28 17:39 abce 阅读(497) 评论(0) 编辑收藏举报

MySQL 复制环境可能会遇到以下错误："Got fatal error 1236 from source when reading data from binary log"。

本文试图重新解释导致这一错误的典型原因以及处理这一问题的方法。

错误事务(errant transaction)

比如开始GTID的复制：

mysql > show replica status\G
*************************** 1. row ***************************
...
           Replica_IO_Running: No
          Replica_SQL_Running: Yes
...
                   Last_IO_Errno: 13114
                Last_IO_Error: Got fatal error 1236 from source when reading data from binary log: 'Cannot replicate because the source purged required binary logs. Replicate the missing transactions from elsewhere, or provision a new replica from backup. Consider increasing the source's binary log expiration period. The GTID set sent by the replica is '00022738-1111-1111-1111-111111111111:1-370', and the missing transactions are '00022739-2222-2222-2222-222222222222:1-2''

可以查看errno 13114的额外信息，但其实也不是很详细：

1 2	`$ perror 13114` `MySQL error code MY-013114 (ER_SERVER_SOURCE_FATAL_ERROR_READING_BINLOG): Got fatal error %d` `from` `source` `when` `reading data` `from` `binary` `log:` `'%-.512s'`

上面的错误消息提示说明了，源节点不再拥有复制所需的二进制日志，而GTID提示了缺失的具体事务：00022739-2222-2222-2222-222222222222:1-2

深入查看源节点，可以看到变量gtid_executed中包含两个GTID集，而复制节点只有一个GTID集。

源节点：

mysql > select @@global.gtid_executed,@@global.gtid_purged\G
*************************** 1. row ***************************
@@global.gtid_executed: 00022738-1111-1111-1111-111111111111:1-370,
00022739-2222-2222-2222-222222222222:1-2
  @@global.gtid_purged: 00022738-1111-1111-1111-111111111111:1-357,
00022739-2222-2222-2222-222222222222:1-2
1 row in set (0.00 sec)

复制节点：

mysql > select @@global.gtid_executed,@@global.gtid_purged\G
*************************** 1. row ***************************
@@global.gtid_executed: 00022738-1111-1111-1111-111111111111:1-370
  @@global.gtid_purged: 
1 row in set (0.00 sec)

源节点比复制节点多出的GTID集已经被清除。因此因此，它不能提供给副本。我们称之为错误事务(errant transaction)。

由于二进制日志已被清除，除非备份了源节点的二进制日志并能在历史记录中找到它们，否则我们无法调查这两个额外事务的内容。

假设没有办法检查这两个事务的内容。在这种情况下，恢复复制的快速解决方案是插入具有相同 GTID 的空事务，然后检查实例是否存在不一致（pt-table-checksum）。要做到这一点，我们可以在复制节点上这样做：

mysql > set gtid_next='00022739-2222-2222-2222-222222222222:1';
Query OK, 0 rows affected (0.00 sec)
 
mysql > begin; commit;
Query OK, 0 rows affected (0.00 sec)
 
Query OK, 0 rows affected (0.01 sec)
 
mysql > set gtid_next='00022739-2222-2222-2222-222222222222:2';
Query OK, 0 rows affected (0.00 sec)
 
mysql > begin; commit;
Query OK, 0 rows affected (0.00 sec)
 
Query OK, 0 rows affected (0.01 sec)
 
mysql > set gtid_next=automatic;
Query OK, 0 rows affected (0.00 sec)
 
mysql > select @@global.gtid_executed,@@global.gtid_purged\G
*************************** 1. row ***************************
@@global.gtid_executed: 00022738-1111-1111-1111-111111111111:1-370,
00022739-2222-2222-2222-222222222222:1-2
  @@global.gtid_purged: 
1 row in set (0.00 sec)
 
mysql > start replica;
Query OK, 0 rows affected (0.00 sec)
 
mysql > show replica status\G
*************************** 1. row ***************************
...
           Replica_IO_Running: Yes
          Replica_SQL_Running: Yes

出现这种情况的一个典型原因是，错误的事务(errant transaction)先在一个复制节点上被引入，然后过了一段时间，同一个复制节点被提升为新的源节点。

如果所有复制节点都以只读模式运行，为什么会出现这种情况呢？下面是我的测试副本的情况：

mysql > select @@super_read_only,@@read_only;
+-------------------+-------------+
| @@super_read_only | @@read_only |
+-------------------+-------------+
|                 1 |           1 |
+-------------------+-------------+
1 row in set (0.00 sec)
 
mysql > flush hosts;
Query OK, 0 rows affected, 1 warning (0.00 sec)
 
mysql > show binlog events in 'mysql-bin.000002';
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                                              |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
| mysql-bin.000002 |   4 | Format_desc    |     22739 |         126 | Server ver: 8.0.37, Binlog ver: 4                                 |
| mysql-bin.000002 | 126 | Previous_gtids |     22739 |         197 | 00022738-1111-1111-1111-111111111111:1-357                        |
| mysql-bin.000002 | 197 | Gtid           |     22739 |         274 | SET @@SESSION.GTID_NEXT= '00022739-2222-2222-2222-222222222222:1' |
| mysql-bin.000002 | 274 | Query          |     22739 |         351 | flush hosts                                                       |
| mysql-bin.000002 | 351 | Gtid           |     22739 |         428 | SET @@SESSION.GTID_NEXT= '00022739-2222-2222-2222-222222222222:2' |
| mysql-bin.000002 | 428 | Query          |     22739 |         505 | flush hosts                                                       |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------+
6 rows in set (0.00 sec)

即使打开了 super_read_only，也有可能添加带有本地服务器 UUID 的 binlog 事件。因此，当 binlog 被轮换，实例被升级时，其他副本将无法同步这些事件！这个问题多年前就有报告，至今仍然有效： https://bugs.mysql.com/bug.php?id=88720

max_allowed_packet配置太小

error 1236 的另一种可能情况是 MySQL 超出了允许的最大数据包大小。复制节点状态中的错误状态示例如下：

Last_IO_Errno: 13114

Last_IO_Error: Got fatal error 1236 from source when reading data from binary log: 'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on source; the first event '' at 4, the last event read from './mysql-bin.000002' at 7628, the last byte read from './mysql-bin.000002' at 7647.'

从该节点的错误日志中可以看到对应如下报错信息：

2024-06-05T14:19:57.956581Z 10 [ERROR] [MY-010557] [Repl] Error reading packet from server for channel '': log event entry exceeded max_allowed_packet; Increase max_allowed_packet on source; the first event '' at 4, the last event read from './mysql-bin.000002' at 7628, the last byte read from './mysql-bin.000002' at 7647. (server_errno=1236)

2024-06-05T14:19:57.956622Z 10 [ERROR] [MY-013114] [Repl] Replica I/O for channel '': Got fatal error 1236 from source when reading data from binary log: 'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on source; the first event '' at 4, the last event read from './mysql-bin.000002' at 7628, the last byte read from './mysql-bin.000002' at 7647.', Error_code: MY-013114

现在，上述建议以及增加源节点上 max_allowed_packet 设置可能完全不合理。即使源节点已将其设置为最大可能值，即 1GB，也会被打印出来：

mysql > select @@max_allowed_packet;
+----------------------+
| @@max_allowed_packet |
+----------------------+
|           1073741824 |
+----------------------+
1 row in set (0.00 sec)

在复制节点方面，默认情况下，最大数据包大小通过 replica_max_allowed_packet 设置（也是 1G）。

首先检查二进制日志是否确实大于 1GB，这一点很重要，因为如果不是，错误很可能与日志损坏有关，例如，源节点被突然重启时，sync_binlog<>1。无论如何，如果 binlog 文件可以解析，则应使用 mysqlbinlog 工具进行测试。当 binlog 文件没有完全写入磁盘时（由于突然断电），错误信息可能看起来完全一样。

如果 binlog 文件大小为 1 GB 或更大，并且没有损坏，则可能是遇到了以下错误（至今仍然有效）：

https://bugs.mysql.com/bug.php?id=107113 - 当单行足够大时

https://bugs.mysql.com/bug.php?id=55231 - 当 binlog 文件超过 4GB 时

为避免出现这种错误变体，应避免非常大的事务，sync_binlog=1 应将损坏风险降至最低。

缺失二进制日志文件

出现相同错误的另一个常见原因是

1 2	`Last_IO_Errno: 13114` `Last_IO_Error: Got fatal error 1236` `from` `source` `when` `reading data` `from` `binary` `log:` `'Could not find first log file name in binary log index file'`

在非 GTID 模式下，以及启用 GTID 模式但禁用自动定位功能时，通常会出现这种情况。因此，复制 IO 线程会查看二进制日志文件并进行定位。

原因很简单--在复制节点能够下载之前，源节点会 rotate 所需的二进制日志。因此，举例来说，在源节点上有

mysql > show binary logs;
+------------------+-----------+-----------+
| Log_name         | File_size | Encrypted |
+------------------+-----------+-----------+
| mysql-bin.000005 |      1674 | No        |
+------------------+-----------+-----------+
1 row in set (0.00 sec)

但是复制节点需要之前的日志日志文件：

mysql > show replica status\G
*************************** 1. row ***************************
             Replica_IO_State: 
                  Source_Host: 127.0.0.1
                  Source_User: rsandbox
                  Source_Port: 22738
                Connect_Retry: 60
              Source_Log_File: mysql-bin.000004
          Read_Source_Log_Pos: 716
               Relay_Log_File: mysql-relay.000004
                Relay_Log_Pos: 892
        Relay_Source_Log_File: mysql-bin.000004
           Replica_IO_Running: No
          Replica_SQL_Running: Yes
…
               Auto_Position: 0

应实施适当的日志轮换策略来避免这个问题。通常，MySQL 管理员会使用相对较短的保留设置（通过 binlog_expire_logs_seconds），因为很难预测磁盘空间的使用情况，这取决于实际写入量而非时间。

磁盘空间不足

磁盘空间问题会导致另一种不同的错误：

Last_IO_Errno: 1236

Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'binlog truncated in the middle of event; consider out of disk space on master; the first event '' at 4, the last event read from './mysqld-bin.000001' at 12826202, the last byte read from './mysqld-bin.000001' at 12826221.'

比较常见的情况是临时空间（tmpdir 或 innodb_tmpdir）被挂载在一个单独的小分区上。当这个分区满了，binlog 缓存文件就无法写入磁盘，结果二进制日志条目就会损坏，导致复制失败，并出现同样的错误。