写点什么

GreatSQL 自动开启复制导致同步报错

作者:GreatSQL
  • 2024-11-27
    福建
  • 本文字数:8909 字

    阅读完需:约 29 分钟

GreatSQL 自动开启复制导致同步报错

1.背景概述

目前需要将生产数据恢复到一个单实例,再将单实例和生产节点配置主从关系,由于单表数据量较大,时间比较有限,考虑到导入导出的时间,并且 GreatSQL 支持 XtraBackup 备份恢复,能够加速数据的恢复,因此决定使用 XtraBackup 备份工具进行数据的迁移;


在数据恢复完成后进行数据同步,从库发生报错 1062 主键冲突,通过解析 relaylog,根据 relaylog 中的 insert 记录,以主键 id 字段为查询条件进行查询,发现从库中存在该条记录;回到恢复完成时,解析当前 binlog 发现该条记录写入 binlog 时间和数据库启动时间相近,且 error 日志中存在 slave 等关键字,进一步确认发现复制关系已自动建立,导致关闭期间主库新增数据依然正常同步到从库,从而导致从库报错.

2.问题复现

本次测试基于 GreatSQL 8.0.32

2.1 初始化 3 个单机实例

初始化过程略,其中前两个实例为主从关系,第三个实例是备份恢复完成后原从库的从库

2.2 主节点创建测试表

greatsql> CREATE DATABASE test;greatsql> USE test;
greatsql> CREATE TABLE t1 (id INT,name VARCHAR(30),age INT,insert_time DATE not null,unique key (id)) ENGINE=INNODB;
greatsql> INSERT INTO t1 values(1,'小红',10,'2015-09-28'),(2,'小绿',11,'2016-09-29'),(3,'小黄',12,'2024-07-09'),(4,'小蓝',13,'2024-08-06'),(5,'小黑',14,'2024-08-07');
复制代码

2.3 从节点查询数据

greatsql> SELECT * FROM test.t1;+------+--------+------+-------------+| id   | name   | age  | insert_time |+------+--------+------+-------------+|    1 | 小红   |   10 | 2015-09-28  ||    2 | 小绿   |   11 | 2016-09-29  ||    3 | 小黄   |   12 | 2024-07-09  ||    4 | 小蓝   |   13 | 2024-08-06  ||    5 | 小黑   |   14 | 2024-08-07  |+------+--------+------+-------------+5 rows in set (0.01 sec)
复制代码

2.4 执行全量备份

在从节点执行备份任务


$ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --defaults-file=/data/my5506.cnf --user=root --password='!QAZ2wsx' --host=172.17.134.93 --port=5506 --backup --compress --target-dir=/data/backup/`date +%Y%m%d`/
复制代码

2.5 备份恢复

在第三个实例上利用备份文件恢复数据


##解压备份文件$ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --decompress --remove-original --target-dir=/data/backup/20240813
##准备数据$ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --prepare --target-dir=/data/backup/20240813
##拷贝数据(需要将源目录进行备份,且恢复目录要为空)$ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --datadir=/data/GreatSQL --copy-back --target-dir=/data/backup/20240813
##启动数据库实例$ /data/app/GreatSQL-8.0.32-25-Linux-glibc2.17-x86_64/bin/mysqld_safe --defaults-file=/data/my5506.cnf --user=greatdb &
复制代码


继续在主节点插入新数据


greatsql> INSERT INTO t1 values (6,'小紫',21,'2024-08-12');
复制代码


从节点查询数据


greatsql> SELECT * FROM t1;+------+--------+------+-------------+| id   | name   | age  | insert_time |+------+--------+------+-------------+|    1 | 小红   |   10 | 2015-09-28  ||    2 | 小绿   |   11 | 2016-09-29  ||    3 | 小黄   |   12 | 2024-07-09  ||    4 | 小蓝   |   13 | 2024-08-06  ||    5 | 小黑   |   14 | 2024-08-07  ||    6 | 小紫   |   21 | 2024-08-12  |+------+--------+------+-------------+6 rows in set (0.01 sec)
复制代码


注意:这里的从节点是指原主从环境的从节点,而不是利用备份文件恢复后配置的从节点。原主从环境是正常同步的,不做其他的操作。

2.6 新实例建立复制关系

新实例恢复完成后,根据备份文件 gtid 信息,配置和原从节点的同步


greatsql> RESET MASTER;Query OK, 0 rows affected (0.04 sec)
greatsql> RESET SLAVE ALL;Query OK, 0 rows affected, 1 warning (0.03 sec)
greatsql> SET GLOBAL GTID_PURGED='28093c86-5631-11ef-87f4-00163eab83df:1-3';Query OK, 0 rows affected (0.00 sec)
greatsql> SHOW MASTER STATUS;+---------------+----------+--------------+------------------+------------------------------------------+| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |+---------------+----------+--------------+------------------+------------------------------------------+| binlog.000001 | 157 | | | 28093c86-5631-11ef-87f4-00163eab83df:1-3 |+---------------+----------+--------------+------------------+------------------------------------------+1 row in set (0.00 sec)
greatsql> CHANGE MASTER to MASTER_HOST = '172.17.134.93',MASTER_USER = 'replabd',MASTER_PASSWORD = 'greatdb',MASTER_PORT = 5506,MASTER_LOG_FILE ='binlog.000002', MASTER_LOG_POS = 197 for CHANNEL 'slave_5506';Query OK, 0 rows affected, 7 warnings (0.02 sec)
greatsql> START SLAVE FOR CHANNEL 'slave_5506';Query OK, 0 rows affected, 1 warning (0.04 sec)
复制代码

2.7 查看复制状态

greatsql> SHOW SLAVE STATUS \G*************************** 1. row ***************************               Slave_IO_State: Waiting for source to send event                  Master_Host: 172.17.134.93                  Master_User: replabd                  Master_Port: 5506                Connect_Retry: 60              Master_Log_File: binlog.000002          Read_Master_Log_Pos: 963               Relay_Log_File: gip-relay-bin-slave_5506.000002                Relay_Log_Pos: 323        Relay_Master_Log_File: binlog.000002             Slave_IO_Running: Yes            Slave_SQL_Running: No              Replicate_Do_DB:           Replicate_Ignore_DB:            Replicate_Do_Table:        Replicate_Ignore_Table:       Replicate_Wild_Do_Table:   Replicate_Wild_Ignore_Table:                    Last_Errno: 1062                   Last_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 1 failed executing transaction '28093c86-5631-11ef-87f4-00163eab83df:4' at master log binlog.000002, end_log_pos 549. See error log and/or performance_schema.replication_applier_status_by_worker table for more details about this failure or others, if any.                 Skip_Counter: 0          Exec_Master_Log_Pos: 197              Relay_Log_Space: 1308...
greatsql> SELECT * FROM performance_schema.replication_applier_status_by_worker limit 1\G*************************** 1. row *************************** CHANNEL_NAME: slave_5506 WORKER_ID: 1 THREAD_ID: NULL SERVICE_STATE: OFF LAST_ERROR_NUMBER: 1062 LAST_ERROR_MESSAGE: Worker 1 failed executing transaction '28093c86-5631-11ef-87f4-00163eab83df:4' at master log binlog.000002, end_log_pos 549; Could not execute Write_rows event on table test.t1; Duplicate entry '6' for key 't1.PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 549 ......
复制代码


performance_schema.replication_applier_status_by_worker 表详细错误信息可以看到,从库在test.t1表,主键值为 6 上报 1062 主键冲突错误

2.8 解析从库 relay log

SET @@SESSION.GTID_NEXT= '28093c86-5631-11ef-87f4-00163eab83df:4'/*!*/;# at 409#240814 14:14:35 server id 135506  end_log_pos 353 CRC32 0x8fe3125e     Query   thread_id=9     exec_time=0     error_code=0SET TIMESTAMP=1723616075/*!*/;SET @@session.pseudo_thread_id=9/*!*/;SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;SET @@session.sql_mode=1168637984/*!*/;SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;/*!\C utf8mb4 *//*!*/;SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=255/*!*/;SET @@session.lc_time_names=0/*!*/;SET @@session.collation_database=DEFAULT/*!*/;/*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;BEGIN/*!*/;# at 479#240814 14:14:35 server id 135506  end_log_pos 428 CRC32 0x0ac8f16a     Rows_query# insert into t1 values#  (6,'小紫',21,'2024-08-12')# at 554#240814 14:14:35 server id 135506  end_log_pos 487 CRC32 0x46a55e3a     Table_map: `test`.`t1` mapped to number 89# has_generated_invisible_primary_key=1# at 613#240814 14:14:35 server id 135506  end_log_pos 549 CRC32 0x82672058     Write_rows: table id 89 flags: STMT_END_F### INSERT INTO `test`.`t1`### SET###   @1=6 /* LONGINT meta=0 nullable=0 is_null=0 */###   @2=6 /* INT meta=0 nullable=1 is_null=0 */###   @3='小紫' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */###   @4=21 /* INT meta=0 nullable=1 is_null=0 */###   @5='2024:08:12' /* DATE meta=0 nullable=0 is_null=0 */# at 675#240814 14:14:35 server id 135506  end_log_pos 580 CRC32 0xbf6d9a69     Xid = 11COMMIT/*!*/;# at 706#240814 14:14:36 server id 135506  end_log_pos 666 CRC32 0x7a9e84ef     GTID    last_committed=1        sequence_number=2       rbr_only=yes    original_committed_timestamp=1723616076007388   immediate_commit_timestamp=1723616076225999     transaction_length=383/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
复制代码


可以看到,insert 插入的具体记录

2.9 根据 relay log 中的内容去从库查询数据

greatsql> SELECT * FROM test.t1 where id = 6;+------+--------+------+-------------+| id   | name   | age  | insert_time |+------+--------+------+-------------+|    6 | 小紫   |   21 | 2024-08-12  |+------+--------+------+-------------+1 row in set (0.00 sec)
复制代码


从库确实存在这条记录,那为什么数据会重复呢?

2.10 回到备份恢复完成时

查看新实例当前 gtid


greatsql> SHOW MASTER STATUS \G*************************** 1. row ***************************             File: binlog.000005         Position: 963     Binlog_Do_DB:  Binlog_Ignore_DB: Executed_Gtid_Set: 28093c86-5631-11ef-87f4-00163eab83df:1-51 row in set (0.00 sec)
复制代码


查询数据


greatsql> SELECT * FROM test.t1 where id = 6;+------+--------+------+-------------+| id   | name   | age  | insert_time |+------+--------+------+-------------+|    6 | 小紫   |   21 | 2024-08-12  |+------+--------+------+-------------+1 row in set (0.00 sec)
复制代码


可以看到,当利用备份文件恢复完成后,查询该数据是存在的,且当前 gtid 信息和备份文件 xtrabackup_info 记录的 gtid 信息不一致,明显 gtid 值较大

2.11 解析当前 binlog

# at 126#240814 15:11:53 server id 2295506  end_log_pos 197 CRC32 0xd635e779    Previous-GTIDs# 28093c86-5631-11ef-87f4-00163eab83df:1-3# at 197#240814 14:14:35 server id 135506  end_log_pos 283 CRC32 0x29a5e5d0     GTID    last_committed=0        sequence_number=1       rbr_only=yes    original_committed_timestamp=1723616075269734   immediate_commit_timestamp=1723619515286089     transaction_length=383/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;# original_commit_timestamp=1723616075269734 (2024-08-14 14:14:35.269734 CST)# immediate_commit_timestamp=1723619515286089 (2024-08-14 15:11:55.286089 CST)/*!80001 SET @@session.original_commit_timestamp=1723616075269734*//*!*/;/*!80014 SET @@session.original_server_version=80032*//*!*/;/*!80014 SET @@session.immediate_server_version=80032*//*!*/;SET @@SESSION.GTID_NEXT= '28093c86-5631-11ef-87f4-00163eab83df:4'/*!*/;# at 283#240814 14:14:35 server id 135506  end_log_pos 353 CRC32 0x7fd5bbc9     Query   thread_id=7     exec_time=3440  error_code=0SET TIMESTAMP=1723616075/*!*/;SET @@session.pseudo_thread_id=7/*!*/;SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;SET @@session.sql_mode=1168637984/*!*/;SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;/*!\C utf8mb4 *//*!*/;SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=255/*!*/;SET @@session.lc_time_names=0/*!*/;SET @@session.collation_database=DEFAULT/*!*/;/*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;BEGIN/*!*/;# at 353#240814 14:14:35 server id 135506  end_log_pos 428 CRC32 0x0ac8f16a     Rows_query# insert into t1 values#  (6,'小紫',21,'2024-08-12')# at 428#240814 14:14:35 server id 135506  end_log_pos 487 CRC32 0x6ab5cc7d     Table_map: `test`.`t1` mapped to number 86# has_generated_invisible_primary_key=1# at 487#240814 14:14:35 server id 135506  end_log_pos 549 CRC32 0xa97243cd     Write_rows: table id 86 flags: STMT_END_F### INSERT INTO `test`.`t1`### SET###   @1=6 /* LONGINT meta=0 nullable=0 is_null=0 */###   @2=6 /* INT meta=0 nullable=1 is_null=0 */###   @3='小紫' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */###   @4=21 /* INT meta=0 nullable=1 is_null=0 */###   @5='2024:08:12' /* DATE meta=0 nullable=0 is_null=0 */# at 549#240814 14:14:35 server id 135506  end_log_pos 580 CRC32 0x6c8881dc     Xid = 3COMMIT/*!*/;
复制代码


可以看到 id 为 6 的记录写入 binlog 文件的时间和数据库实例启动时间基本一致,说明数据是在启动过程中写入的,且 error.log 中出现了关键字Slave I/O thread & Slave SQL thread不得不怀疑是否已经建立了复制关系?


2.12 新实例查询是否存在复制关系

greatsql> SHOW SLAVE STATUS \G*************************** 1. row ***************************               Slave_IO_State: Waiting for source to send event                  Master_Host: 172.17.140.13                  Master_User: replabc                  Master_Port: 5506                Connect_Retry: 60              Master_Log_File: binlog.000002          Read_Master_Log_Pos: 959               Relay_Log_File: gip-relay-bin-master_5506.000002                Relay_Log_Pos: 1129        Relay_Master_Log_File: binlog.000002             Slave_IO_Running: Yes            Slave_SQL_Running: Yes...
复制代码


可以看到新实例恢复完成后,复制关系已经建立,且同步正常,为什么会出现这种情况?

2.13 查看复制元数据信息和启动参数

greatsql> SELECT * FROM slave_master_info \G*************************** 1. row ***************************                Number_of_lines: 33                Master_log_name: binlog.000002                 Master_log_pos: 197                           Host: 172.17.140.13                      User_name: replabc                  User_password: !QAZ2wsx                           Port: 5506                  Connect_retry: 60                    Enabled_ssl: 0                         Ssl_ca:                      Ssl_capath:                        Ssl_cert:                      Ssl_cipher:                         Ssl_key:          Ssl_verify_server_cert: 0                      Heartbeat: 30                           Bind:              Ignored_server_ids: 0                           Uuid: 28093c86-5631-11ef-87f4-00163eab83df                    Retry_count: 86400                        Ssl_crl:                     Ssl_crlpath:           Enabled_auto_position: 1                   Channel_name: master_5506                    Tls_version:                 Public_key_path:                  Get_public_key: 0              Network_namespace:    Master_compression_algorithm: uncompressed  Master_zstd_compression_level: 3               Tls_ciphersuites: NULLSource_connection_auto_failover: 0                      Gtid_only: 01 row in set (0.00 sec)
greatsql> SELECT * FROM slave_relay_log_info \G*************************** 1. row *************************** Number_of_lines: 14 Relay_log_name: ./gip-relay-bin-master_5506.000002 Relay_log_pos: 1129 Master_log_name: binlog.000002 Master_log_pos: 959 Sql_delay: 0 Number_of_workers: 64 Id: 1 Channel_name: master_5506 Privilege_checks_username: NULL Privilege_checks_hostname: NULL Require_row_format: 0 Require_table_primary_key_check: STREAM Assign_gtids_to_anonymous_transactions_type: OFFAssign_gtids_to_anonymous_transactions_value: 1 row in set (0.01 sec)
greatsql> SHOW VARIABLES LIKE '%skip%start%';+--------------------+-------+| Variable_name | Value |+--------------------+-------+| skip_replica_start | OFF || skip_slave_start | OFF |+--------------------+-------+2 rows in set (0.00 sec)
复制代码


MySQL 手册介绍



副本服务器会创建多个信息存储库以用于复制过程,其中包括:


  • 副本连接元数据存储库,包含复制接收器线程连接到复制源服务器并从源的二进制日志检索事务所需的信息。连接元数据存储库被写入mysql.slave_master_info 表中。

  • 副本的应用程序元数据存储库,包含复制应用程序线程需要从副本的中继日志读取和应用事务的信息。应用程序元数据存储库被写入 mysql.slave_relay_log_info表中。



  • 从 MySQL 8.0.26 开始使用--skip-replica-start代替,之前的版本可以使用 --skip-slave-start,默认值为 OFF。

  • 告诉副本服务器在服务器启动时不要启动复制 I/O(接收器)和 SQL(应用程序)线程。若要稍后启动线程,请使用 START REPLICA 语句。


官方文档的这两段描述可以解释为什么在数据库服务启动之后,同步关系会自动建立,若主库状态正常,且 binlog 文件保存完整,则 I/O 和 SQL 线程状态都为 YES。

2.14 解决方法

  1. 新实例恢复完成后,启动前在配置文件中添加参数skip_replica_start=1或启动时加上--skip-replica-start=1

  2. 配置同步,再次查看同步正常


greatsql> SHOW SLAVE STATUS \G*************************** 1. row ***************************               Slave_IO_State: Waiting for source to send event                  Master_Host: 172.17.134.93                  Master_User: replabd                  Master_Port: 5506                Connect_Retry: 60              Master_Log_File: binlog.000004          Read_Master_Log_Pos: 197               Relay_Log_File: gip-relay-bin-slave_5506.000009                Relay_Log_Pos: 363        Relay_Master_Log_File: binlog.000004             Slave_IO_Running: Yes            Slave_SQL_Running: Yes...1 row in set, 1 warning (0.00 sec)
复制代码

3.总结

  1. 在进行维护或修改从库配置时,可能需要从库停止复制。这时设置skip-replica-starts可以确保从库在重启时不会自动启动复制进程,从而避免在未完成配置调整前意外启动复制。

  2. 当需要在从库上进行数据恢复或其他涉及数据修改的操作时,停止复制是必要的。设置skip-replica-starts=1可以确保在操作完成并手动启动复制前,复制进程不会自动启动。


发布于: 刚刚阅读数: 3
用户头像

GreatSQL

关注

GreatSQL社区 2023-01-31 加入

GreatSQL是由万里数据库维护的MySQL分支,专注于提升MGR可靠性及性能,支持InnoDB并行查询特性,是适用于金融级应用的MySQL分支版本。 社区:https://greatsql.cn/ Gitee: https://gitee.com/GreatSQL/GreatSQL

评论

发布
暂无评论
GreatSQL 自动开启复制导致同步报错_GreatSQL_InfoQ写作社区