复制一直是 MySQL 的核心功能,数十年来一直支持高可用性。但是,您仍可能会遇到让您彻夜难眠的复制错误。最常见且最难处理的错误之一是:“从二进制日志读取数据时出现致命错误 1236 ”。
这篇博文是一次全新的尝试,旨在解释此错误的典型原因以及处理该问题的方法。
错误的 GTID
如今,典型的复制设置使用GTID模式,完整的错误消息如下所示:
代码语言:txt复制mysql > show replica statusG
*************************** 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,尽管它并没有增加太多内容:
代码语言:txt复制$ 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 详细信息则提供了更精确的见解:“ ”。the missing transactions are '00022739-2222-2222-2222-222222222222:1-2'
进一步挖掘,我们可以看到主服务器在gtid_executed中有两个 GTID 集,而副本服务器只有一个:
主库
代码语言:txt复制mysql > select @@global.gtid_executed,@@global.gtid_purgedG
*************************** 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)
从库
代码语言:txt复制mysql > select @@global.gtid_executed,@@global.gtid_purgedG
*************************** 1. row ***************************
@@global.gtid_executed: 00022738-1111-1111-1111-111111111111:1-370
@@global.gtid_purged:
1 row in set (0.00 sec)
此外,这个额外的集合被标记为已清除。因此,它无法提供给副本。我们称之为错误事务。
由于二进制日志已被清除,我们无法调查这两个额外事务的含义,除非源实例二进制日志已备份并且我们可以在历史记录中找到它们。
假设没有办法检查这些内容。在这种情况下,恢复复制的快速解决方案是插入具有相同 GTID 的空事务,然后检查实例是否存在不一致(即使用pt-table-checksum)。为了实现这一点,在副本上,我们可以这样做:
代码语言:txt复制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_purgedG
*************************** 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 statusG
*************************** 1. row ***************************
...
Replica_IO_Running: Yes
Replica_SQL_Running: Yes
出现这种情况的典型原因是,错误的事务首先出现在副本上,一段时间之后,同一个副本被提升为新的源。
如果所有副本都以只读模式运行,为什么会发生这种情况?好吧,这是我的测试副本的情况:
代码语言:txt复制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
TIPS: 经在percona 8.0.36-28上测试,这个flush hosts已经不会写binlog了,并且会给出warning警告,建议使用TRUNCATE TABLE performance_schema.host_cache 。
max_allowed_packet 太小了?
错误 1236 的另一种可能情况是 MySQL 报告超出了允许的最大数据包大小。副本状态的示例错误状态可能如下所示:
代码语言:txt复制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.'
副本端对应的错误日志条目为:
代码语言:txt复制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),也会打印该错误:
代码语言:txt复制mysql > select @@max_allowed_packet;
----------------------
| @@max_allowed_packet |
----------------------
| 1073741824 |
----------------------
1 row in set (0.00 sec)
在副本端,默认情况下,最大数据包大小通过replica_max_allowed_packet设置(也是 1G)。
首先,检查罪魁祸首二进制日志是否确实大于 1 GB 非常重要,因为如果不是,则错误很可能与日志损坏有关,例如,当源突然重新启动并且 sync_binlog<>1 时。无论如何,都应使用 mysqlbinlog工具测试 binlog 文件是否完全可解析。当 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应最大限度地降低损坏的风险。
缺少二进制日志文件
导致相同错误的另一个常见原因可能是这样的:
代码语言:txt复制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 模式但禁用auto_position功能时,都可能发生这种情况。因此,复制 IO 线程正在查看二进制日志文件和位置。
原因很简单——在副本能够下载所需的二进制日志之前,源服务器已经轮换了该日志。因此,例如,在源服务器上,有:
代码语言:txt复制mysql > show binary logs;
------------------ ----------- -----------
| Log_name | File_size | Encrypted |
------------------ ----------- -----------
| mysql-bin.000005 | 1674 | No |
------------------ ----------- -----------
1 row in set (0.00 sec)
但副本需要前一个文件才能继续:
代码语言:txt复制mysql > show replica statusG
*************************** 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 ),因为很难预测磁盘空间使用情况,这取决于实际写入量而不是时间。我认为使用 Percona 的扩展和变量binlog_space_limit可以更轻松地更好地利用 binlog 的专用磁盘空间!
磁盘空间不足
源上的磁盘空间问题可能会导致另一种错误,例如:
代码语言:txt复制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 缓存文件无法写入磁盘,结果 二进制日志条目被损坏,导致副本失败并出现相同的错误。
参考:
https://bugs.mysql.com/bug.php?id=86991 https://bugs.mysql.com/bug.php?id=72457
其他活动错误导致 binlog 损坏并打印相同错误消息的示例: https://bugs.mysql.com/bug.php ?id= 75746 https://bugs.mysql.com/bug.php?id=75507
概括
一般来说,处理这种复制错误类别可能具有挑战性。在某些情况下,最好从源备份重新创建副本数据。实现此目的的快速方法包括XtraBackup或克隆插件。
但在其他情况下,您可以尝试使用我们的工具以更轻量级的方式识别和同步表差异,如下所示:https: //www.percona.com/blog/mysql-replication-primer-with-pt-table-checksum-and-pt-table-sync/