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

达了个蛋

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

1.背景概述

目前需要将生产数据恢复到一个单实例，再将单实例和生产节点配置主从关系，由于单表数据量较大，时间比较有限，考虑到导入导出的时间，并且GreatSQL支持XtraBackup备份恢复，能够加速数据的恢复，因此决定使用XtraBackup备份工具进行数据的迁移；
在数据恢复完成后进行数据同步，从库发生报错 1062 主键冲突，通过解析relaylog，根据relaylog中的insert记录，以主键id字段为查询条件进行查询，发现从库中存在该条记录；回到恢复完成时，解析当前binlog发现该条记录写入binlog时间和数据库启动时间相近，且error日志中存在slave等关键字，进一步确认发现复制关系已自动建立，导致关闭期间主库新增数据依然正常同步到从库，从而导致从库报错.
2.问题复现

本次测试基于 GreatSQL 8.0.32
2.1 初始化3个单机实例

初始化过程略，其中前两个实例为主从关系，第三个实例是备份恢复完成后原从库的从库
2.2 主节点创建测试表

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

复制代码

2.3 从节点查询数据

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

复制代码

2.4 执行全量备份

在从节点执行备份任务

1. $ /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 备份恢复

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

1. ##解压备份文件
2. $ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --decompress --remove-original --target-dir=/data/backup/20240813
4. ##准备数据
5. $ /data/tool/percona-xtrabackup-8.0.32-26-34cf2908-linux-x86_64-glibc2.17/bin/xtrabackup --prepare --target-dir=/data/backup/20240813
7. ##拷贝数据（需要将源目录进行备份，且恢复目录要为空）
8. $ /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
10. ##启动数据库实例
11. $ /data/app/GreatSQL-8.0.32-25-Linux-glibc2.17-x86_64/bin/mysqld_safe --defaults-file=/data/my5506.cnf --user=greatdb &

复制代码

继续在主节点插入新数据

1. greatsql> INSERT INTO t1 values (6,'小紫',21,'2024-08-12');

复制代码

从节点查询数据

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

复制代码

注意：这里的从节点是指原主从环境的从节点，而不是利用备份文件恢复后配置的从节点。原主从环境是正常同步的，不做其他的操作。
2.6 新实例建立复制关系

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

1. greatsql> RESET MASTER;
2. Query OK, 0 rows affected (0.04 sec)
4. greatsql> RESET SLAVE ALL;
5. Query OK, 0 rows affected, 1 warning (0.03 sec)
7. greatsql> SET GLOBAL GTID_PURGED='28093c86-5631-11ef-87f4-00163eab83df:1-3';
8. Query OK, 0 rows affected (0.00 sec)
10. greatsql> SHOW MASTER STATUS;
11. +---------------+----------+--------------+------------------+------------------------------------------+
12. | File          | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                        |
13. +---------------+----------+--------------+------------------+------------------------------------------+
14. | binlog.000001 |      157 |              |                  | 28093c86-5631-11ef-87f4-00163eab83df:1-3 |
15. +---------------+----------+--------------+------------------+------------------------------------------+
16. 1 row in set (0.00 sec)
18. 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';
19. Query OK, 0 rows affected, 7 warnings (0.02 sec)
21. greatsql> START SLAVE FOR CHANNEL 'slave_5506';
22. Query OK, 0 rows affected, 1 warning (0.04 sec)

复制代码

2.7 查看复制状态

1. greatsql> SHOW SLAVE STATUS \G
2. *************************** 1. row ***************************
3.                Slave_IO_State: Waiting for source to send event
4.                   Master_Host: 172.17.134.93
5.                   Master_User: replabd
6.                   Master_Port: 5506
7.                 Connect_Retry: 60
8.               Master_Log_File: binlog.000002
9.           Read_Master_Log_Pos: 963
10.                Relay_Log_File: gip-relay-bin-slave_5506.000002
11.                 Relay_Log_Pos: 323
12.         Relay_Master_Log_File: binlog.000002
13.              Slave_IO_Running: Yes
14.             Slave_SQL_Running: No
15.               Replicate_Do_DB:
16.           Replicate_Ignore_DB:
17.            Replicate_Do_Table:
18.        Replicate_Ignore_Table:
19.       Replicate_Wild_Do_Table:
20.   Replicate_Wild_Ignore_Table:
21.                    Last_Errno: 1062
22.                    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.
23.                  Skip_Counter: 0
24.           Exec_Master_Log_Pos: 197
25.               Relay_Log_Space: 1308
26. ...
28. greatsql> SELECT * FROM performance_schema.replication_applier_status_by_worker limit 1\G
29. *************************** 1. row ***************************
30.                                            CHANNEL_NAME: slave_5506
31.                                               WORKER_ID: 1
32.                                               THREAD_ID: NULL
33.                                           SERVICE_STATE: OFF
34.                                       LAST_ERROR_NUMBER: 1062
35.                                      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
36. ......

复制代码

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

1. SET @@SESSION.GTID_NEXT= '28093c86-5631-11ef-87f4-00163eab83df:4'/*!*/;
2. # at 409
3. #240814 14:14:35 server id 135506  end_log_pos 353 CRC32 0x8fe3125e     Query   thread_id=9     exec_time=0     error_code=0
4. SET TIMESTAMP=1723616075/*!*/;
5. SET @@session.pseudo_thread_id=9/*!*/;
6. SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
7. SET @@session.sql_mode=1168637984/*!*/;
8. SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
9. /*!\C utf8mb4 *//*!*/;
10. SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=255/*!*/;
11. SET @@session.lc_time_names=0/*!*/;
12. SET @@session.collation_database=DEFAULT/*!*/;
13. /*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;
14. BEGIN
15. /*!*/;
16. # at 479
17. #240814 14:14:35 server id 135506  end_log_pos 428 CRC32 0x0ac8f16a     Rows_query
18. # insert into t1 values
19. #  (6,'小紫',21,'2024-08-12')
20. # at 554
21. #240814 14:14:35 server id 135506  end_log_pos 487 CRC32 0x46a55e3a     Table_map: `test`.`t1` mapped to number 89
22. # has_generated_invisible_primary_key=1
23. # at 613
24. #240814 14:14:35 server id 135506  end_log_pos 549 CRC32 0x82672058     Write_rows: table id 89 flags: STMT_END_F
25. ### INSERT INTO `test`.`t1`
26. ### SET
27. ###   @1=6 /* LONGINT meta=0 nullable=0 is_null=0 */
28. ###   @2=6 /* INT meta=0 nullable=1 is_null=0 */
29. ###   @3='小紫' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */
30. ###   @4=21 /* INT meta=0 nullable=1 is_null=0 */
31. ###   @5='2024:08:12' /* DATE meta=0 nullable=0 is_null=0 */
32. # at 675
33. #240814 14:14:35 server id 135506  end_log_pos 580 CRC32 0xbf6d9a69     Xid = 11
34. COMMIT/*!*/;
35. # at 706
36. #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
37. /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;

复制代码

可以看到，insert 插入的具体记录
2.9 根据relay log中的内容去从库查询数据

1. greatsql> SELECT * FROM test.t1 where id = 6;
2. +------+--------+------+-------------+
3. | id   | name   | age  | insert_time |
4. +------+--------+------+-------------+
5. |    6 | 小紫   |   21 | 2024-08-12  |
6. +------+--------+------+-------------+
7. 1 row in set (0.00 sec)

复制代码

从库确实存在这条记录，那为什么数据会重复呢？
2.10 回到备份恢复完成时

查看新实例当前gtid

1. greatsql> SHOW MASTER STATUS \G
2. *************************** 1. row ***************************
3.              File: binlog.000005
4.          Position: 963
5.      Binlog_Do_DB:
6. Binlog_Ignore_DB:
7. Executed_Gtid_Set: 28093c86-5631-11ef-87f4-00163eab83df:1-5
8. 1 row in set (0.00 sec)

复制代码

查询数据

1. greatsql> SELECT * FROM test.t1 where id = 6;
2. +------+--------+------+-------------+
3. | id   | name   | age  | insert_time |
4. +------+--------+------+-------------+
5. |    6 | 小紫   |   21 | 2024-08-12  |
6. +------+--------+------+-------------+
7. 1 row in set (0.00 sec)

复制代码

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

1. # at 126
2. #240814 15:11:53 server id 2295506  end_log_pos 197 CRC32 0xd635e779    Previous-GTIDs
3. # 28093c86-5631-11ef-87f4-00163eab83df:1-3
4. # at 197
5. #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
6. /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
7. # original_commit_timestamp=1723616075269734 (2024-08-14 14:14:35.269734 CST)
8. # immediate_commit_timestamp=1723619515286089 (2024-08-14 15:11:55.286089 CST)
9. /*!80001 SET @@session.original_commit_timestamp=1723616075269734*//*!*/;
10. /*!80014 SET @@session.original_server_version=80032*//*!*/;
11. /*!80014 SET @@session.immediate_server_version=80032*//*!*/;
12. SET @@SESSION.GTID_NEXT= '28093c86-5631-11ef-87f4-00163eab83df:4'/*!*/;
13. # at 283
14. #240814 14:14:35 server id 135506  end_log_pos 353 CRC32 0x7fd5bbc9     Query   thread_id=7     exec_time=3440  error_code=0
15. SET TIMESTAMP=1723616075/*!*/;
16. SET @@session.pseudo_thread_id=7/*!*/;
17. SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
18. SET @@session.sql_mode=1168637984/*!*/;
19. SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
20. /*!\C utf8mb4 *//*!*/;
21. SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=255/*!*/;
22. SET @@session.lc_time_names=0/*!*/;
23. SET @@session.collation_database=DEFAULT/*!*/;
24. /*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;
25. BEGIN
26. /*!*/;
27. # at 353
28. #240814 14:14:35 server id 135506  end_log_pos 428 CRC32 0x0ac8f16a     Rows_query
29. # insert into t1 values
30. #  (6,'小紫',21,'2024-08-12')
31. # at 428
32. #240814 14:14:35 server id 135506  end_log_pos 487 CRC32 0x6ab5cc7d     Table_map: `test`.`t1` mapped to number 86
33. # has_generated_invisible_primary_key=1
34. # at 487
35. #240814 14:14:35 server id 135506  end_log_pos 549 CRC32 0xa97243cd     Write_rows: table id 86 flags: STMT_END_F
36. ### INSERT INTO `test`.`t1`
37. ### SET
38. ###   @1=6 /* LONGINT meta=0 nullable=0 is_null=0 */
39. ###   @2=6 /* INT meta=0 nullable=1 is_null=0 */
40. ###   @3='小紫' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */
41. ###   @4=21 /* INT meta=0 nullable=1 is_null=0 */
42. ###   @5='2024:08:12' /* DATE meta=0 nullable=0 is_null=0 */
43. # at 549
44. #240814 14:14:35 server id 135506  end_log_pos 580 CRC32 0x6c8881dc     Xid = 3
45. COMMIT/*!*/;

复制代码

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

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

1. greatsql> SHOW SLAVE STATUS \G
2. *************************** 1. row ***************************
3.                Slave_IO_State: Waiting for source to send event
4.                   Master_Host: 172.17.140.13
5.                   Master_User: replabc
6.                   Master_Port: 5506
7.                 Connect_Retry: 60
8.               Master_Log_File: binlog.000002
9.           Read_Master_Log_Pos: 959
10.                Relay_Log_File: gip-relay-bin-master_5506.000002
11.                 Relay_Log_Pos: 1129
12.         Relay_Master_Log_File: binlog.000002
13.              Slave_IO_Running: Yes
14.             Slave_SQL_Running: Yes
15. ...

复制代码

可以看到新实例恢复完成后，复制关系已经建立，且同步正常，为什么会出现这种情况？
2.13 查看复制元数据信息和启动参数

1. greatsql> SELECT * FROM slave_master_info \G
2. *************************** 1. row ***************************
3.                 Number_of_lines: 33
4.                 Master_log_name: binlog.000002
5.                  Master_log_pos: 197
6.                            Host: 172.17.140.13
7.                       User_name: replabc
8.                   User_password: !QAZ2wsx
9.                            Port: 5506
10.                   Connect_retry: 60
11.                     Enabled_ssl: 0
12.                          Ssl_ca:
13.                      Ssl_capath:
14.                        Ssl_cert:
15.                      Ssl_cipher:
16.                         Ssl_key:
17.          Ssl_verify_server_cert: 0
18.                       Heartbeat: 30
19.                            Bind:
20.              Ignored_server_ids: 0
21.                            Uuid: 28093c86-5631-11ef-87f4-00163eab83df
22.                     Retry_count: 86400
23.                         Ssl_crl:
24.                     Ssl_crlpath:
25.           Enabled_auto_position: 1
26.                    Channel_name: master_5506
27.                     Tls_version:
28.                 Public_key_path:
29.                  Get_public_key: 0
30.               Network_namespace:
31.    Master_compression_algorithm: uncompressed
32.   Master_zstd_compression_level: 3
33.                Tls_ciphersuites: NULL
34. Source_connection_auto_failover: 0
35.                       Gtid_only: 0
36. 1 row in set (0.00 sec)
38. greatsql> SELECT * FROM slave_relay_log_info \G
39. *************************** 1. row ***************************
40.                              Number_of_lines: 14
41.                               Relay_log_name: ./gip-relay-bin-master_5506.000002
42.                                Relay_log_pos: 1129
43.                              Master_log_name: binlog.000002
44.                               Master_log_pos: 959
45.                                    Sql_delay: 0
46.                            Number_of_workers: 64
47.                                           Id: 1
48.                                 Channel_name: master_5506
49.                    Privilege_checks_username: NULL
50.                    Privilege_checks_hostname: NULL
51.                           Require_row_format: 0
52.              Require_table_primary_key_check: STREAM
53. Assign_gtids_to_anonymous_transactions_type: OFF
54. Assign_gtids_to_anonymous_transactions_value:
55. 1 row in set (0.01 sec)
57. greatsql> SHOW VARIABLES LIKE '%skip%start%';
58. +--------------------+-------+
59. | Variable_name      | Value |
60. +--------------------+-------+
61. | skip_replica_start | OFF   |
62. | skip_slave_start   | OFF   |
63. +--------------------+-------+
64. 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 解决方法

• 新实例恢复完成后，启动前在配置文件中添加参数skip_replica_start=1或启动时加上--skip-replica-start=1
  
• 配置同步，再次查看同步正常
  

1. greatsql> SHOW SLAVE STATUS \G
2. *************************** 1. row ***************************
3.                Slave_IO_State: Waiting for source to send event
4.                   Master_Host: 172.17.134.93
5.                   Master_User: replabd
6.                   Master_Port: 5506
7.                 Connect_Retry: 60
8.               Master_Log_File: binlog.000004
9.           Read_Master_Log_Pos: 197
10.                Relay_Log_File: gip-relay-bin-slave_5506.000009
11.                 Relay_Log_Pos: 363
12.         Relay_Master_Log_File: binlog.000004
13.              Slave_IO_Running: Yes
14.             Slave_SQL_Running: Yes
15. ...
16. 1 row in set, 1 warning (0.00 sec)

复制代码

3.总结

• 在进行维护或修改从库配置时，可能需要从库停止复制。这时设置skip-replica-starts可以确保从库在重启时不会自动启动复制进程，从而避免在未完成配置调整前意外启动复制。
  
• 当需要在从库上进行数据恢复或其他涉及数据修改的操作时，停止复制是必要的。设置skip-replica-starts=1可以确保在操作完成并手动启动复制前，复制进程不会自动启动。
  

Enjoy GreatSQL
来源:https://www.cnblogs.com/greatsql/p/18571746
免责声明：由于采集信息均来自互联网，如果侵犯了您的权益，请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容，谢谢合作！