开发者

mysqldump 搭建复制报错原因解析

开发者 https://www.devze.com 2023-11-19 12:27 出处:网络 作者: 爱可生云数据库
目录故障现象问题排查问题解决问题复现环境信息操作步骤原理分析改进建议关于 SQLESQLE 获取故障现象
目录
  • 故障现象
  • 问题排查
  • 问题解决
  • 问题复现
    • 环境信息
    • 操作步骤
  • 原理分析
    • 改进建议
      • 关于 SQLE
      • SQLE 获取

    故障现象

    某客户反馈,使用 mysqldump 搭建从库,启动复制后,复制报错:

    Could not execute Write_rows event on table xxx; Duplicate entry 'xxx' for key 'PRIMARY'。

    客户使用的命令(看起来没啥问题)。

    -- 主库备份
    shell> mysqldump -uroot -pxxx --master-data=2 --single-transaction -A --routines --events --triggers >/tmp/xxx.sql
    -- 从服务器还原备份并启动复制
    mysql>reset master;
    mysql>reset slave all;
    mysql>source /tmp/xxx.sql ;
    mysql&pythongt;change master to master_host='xxx',master_port=3306,master_user='xxx',master_password='xxx',master_auto_position=1;
    mysql>start slave;

    问题排查

    查看复制报错表的表结构,发现表的存储引擎为 MyISAM 引擎。

    根据客户反馈,表访问比较频繁,mysqldump --single-transaction 选项,只能保证 InnoDB 引擎表备份的一致性,无法保证 MyISAM 引擎表备份的一致性,问题可能就出在这。

    问题解决

    修改表的存储引擎为 InnoDB 后,重新备份恢复,可以正常搭建从库。

    问题复现

    下面我们来复现一下该问题。

    环境信息

    操作系统Centos linux release 7.5.1804 (Core)
    版本MySQL 5.7.25
    主库10.186.60.187
    从库10.186.60.37
    主从开启 GTID

    操作步骤

    在主库,使用 Sysbench 造一张 1000w 数据的 InnoDB 引擎的表 testdb_innodb.sbtest1(造 1000w 数据主要目的是让备份 InnoDB 引擎表的时间拉长)。

    shell> sysbench /usr/share/sysbench/tests/include/oltp_legacy/oltp.Lua \
    --mysql-host=10.186.60.187 --mysql-port=3307 --mysql-user=root \
    --mysql-password=1 --mysql-db=testdb_innodb --oltp-table-size=10000000 --oltp-tables-count=1 --threads=4    --report-interval=3 prepare
    -- 表结构如下
    mysql> show create table  testdb_innodb.sbtest1;
    CREATE TABLE `sbtest1` (
      `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
      `k` int(10) unsigned NOT NULL DEFAULT '0',
      `c` char(120) COLLATE utf8mb4_bin NOT NULL DEFAULT '',
      `pad` char(60) COLLATE utf8mb4_bin NOT NULL DEFAULT '',
      PRIMARY KEY (`id`),
      KEY `k_1` (`k`)
    ) ENGINE=InnoDB AUTO_INCREMENT=10000001 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
    -- 表总行数如下:
    mysql> select count(*) from testdb_innodb.sbtest1;
    +----------+
    | count(*) |
    +----------+
    | 10000000 |
    +----------+

    在主库,造一张 MyISAM 引擎的表 testdb_myisam.sbtest2

    -- 表结构如下:
    mysql> CREATE TABLE testdb_myisam.`sbtest2` (
      `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
      `k` int(10) unsigned NOT NULL DEFAULT '0',
      `c` char(120) COLLATE utf8mb4_bin NOT NULL DEFAULT '',
      `pad` char(60) COLLATE utf8mb4_bin NOT NULL编程 DEFAULT '',
      PRIMARY KEY (`id`),
      KEY `k_1` (`k`)
    ) ENGINE=myisam AUTO_INCREMENT=1 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin

    在主库,开始 mysqldump 逻辑备份,并在执行备份 testdb_innodb.sbtest1 期间(备份的顺序:先备份 testdb_innodb 库),往 testdb_myisam.sbtest2 表插入一条数据。

    -- 执行 mysqldump 备份
    shell> /data/mysql/base/5.7.25/bin/mysqldump -h10.186.60.187 -P3307 -uroot -p1 --master-data=2 --single-transaction -A --routines --events --triggers  >/tmp/dump.sql
    -- 执行备份 testdb_innodb.sbtest1 期间,往 testdb_myisam.sbtest2 表插入一条数据
    mysql> insert into testdb_myisam.`sbtest2`(k,c,pad)  values(2,'myisam','myisam');
    -- 通过 MySQL general_log 观察备份情况
    2023-07-11T16:15:50.900581+08:00         2692 Connect   root@10.186.60.187 on  using TCP/IP
    2023-07-11T16:15:50.901124+08:00         2692 Query     /*!40100 SET @@SQL_MODE='' */
    2023-07-11T16:15:50.901529+08:00         2692 Query     /*!40103 SET TIME_ZONE='+00:00' */
    2023-07-11T16:15:50.901743+08:00         2692 Query     FLUSH /*!40101 LOCAL */ TABLES
    2023-07-11T16:15:50.938083+08:00         2692 Query     FLUSH TABLES WITH READ LOCK
    2023-07-11T16:15:50.938281+08:00         2692 Query     SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
    2023-07-11T16:15:50.938410+08:00         2692 Query     START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */
    2023-07-11T16:15:50.938678+08:00         2692 Query     SHOW VARIABLES LIKE 'gtid\_mode'
    2023-07-11T16:15:50.980335+08:00         2692 Query     SELECT @@GLOBAL.GTID_EXECUTED
    2023-07-11T16:15:50.980566+08:00         2692 Query     SHOW MASTER STATUS
    2023-07-11T16:15:50.980758+08:00         2692 Query     UNLOCK TABLES
    ...略
    2023-07-11T16:15:51.541911+08:00         2692 Init DB   testdb_innodb
    2023-07-11T16:15:51.542012+08:00         2692 Query     SHOW CREATE DATABASE IF NOT EXISTS `testdb_innodb`
    2023-07-11T16:15:51.542139+08:00         2692 Query     SAVEPOINT sp
    2023-07-11T16:15:51.542224+08:00         2692 Query     show tables
    2023-07-11T16:15:51.542405+08:00         2692 Query     show table status like 'sbtest1'
    2023-07-11T16:15:51.543353+08:00         2692 Query     SET SQL_QUOTE_SHOW_CREATE=1
    2023-07-11T16:15:51.543467+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:15:51.543548+08:00         2692 Query     show create table `sbtest1`
    2023-07-11T16:15:51.543729+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:15:51.543837+08:00         2692 Query     show fields from `sbtest1`
    2023-07-11T16:15:51.544172+08:00         2692 Query     show fields from `sbtest1`
    2023-07-11T16:15:51.544477+08:00         2692 Query     SELECT /*!40001 SQL_NO_CA编程客栈CHE */ * FROM `sbtest1`
    2023-07-11T16:15:57.603435+08:00         2683 Query     insert into testdb_myisam.`sbtest2`(k,c,pad)  values(2,'myisam','myisam')
    2023-07-11T16:16:27.456357+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:16:27.471239+08:00         2692 Query     use `testdb_innodb`
    2023-07-11T16:16:27.471589+08:00         2692 Query     select @@collation_database
    2023-07-11T16:16:27.472065+08:00         2692 Query     SHOW TRIGGERS LIKE 'sbtest1'
    2023-07-11T16:16:27.506025+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:16:27.506225+08:00         2692 Query     ROLLBACK TO SAVEPOINT sp
    2023-07-11T16:16:27.506383+08:00         2692 Query     RELEASE SAVEPOINT sp
    2023-07-11T16:16:27.506538+08:00         2692 Query     show events
    2023-07-11T16:16:27.507226+08:00         2692 Query     use `testdb_innodb`
    2023-07-11T16:16:27.507346+08:00         2692 Query     select @@collation_database
    2023-07-11T16:16:27.507457+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:16:27.507629+08:00         2692 Query     SHOW FUNCTION STATUS WHERE Db = 'testdb_innodb'
    2023-07-11T16:16:27.621194+08:00         2692 Query     SHOW PROCEDURE STATUS WHERE Db = 'testdb_innodb'
    2023-07-11T16:16:27.622726+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:16:27.622900+08:00         2692 I编程客栈nit DB   testdb_myisam
    2023-07-11T16:16:27.623005+08:00         2692 Query     SHOW CREATE DATABASE IF NOT EXISTS `testdb_myisam`
    2023-07-11T16:16:27.623102+08:00         2692 Query     SAVEPOINT sp
    2023-07-11T16:16:27.623211+08:00         2692 Query     show tables
    2023-07-11T16:16:27.623566+08:00         2692 Query     show table status like 'sbtest2'
    2023-07-11T16:16:27.624197+08:00         2692 Query     SET SQL_QUOTE_SHOW_CREATE=1
    2023-07-11T16:1python6:27.624314+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:16:27.624401+08:00         2692 Query     show create table `sbtest2`
    2023-07-11T16:16:27.624518+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:16:27.624605+08:00         2692 Query     show fields from `sbtest2`
    2023-07-11T16:16:27.625027+08:00         2692 Query     show fields from `sbtest2`
    2023-07-11T16:16:27.625391+08:00         2692 Query     SELECT /*!40001 SQL_NO_CACHE */ * FROM `sbtest2`
    2023-07-11T16:16:27.636073+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:16:27.636213+08:00         2692 Query     use `testdb_myisam`
    2023-07-11T16:16:27.636317+08:00         2692 Query     select @@collation_database
    2023-07-11T16:16:27.636429+08:00         2692 Query     SHOW TRIGGERS LIKE 'sbtest2'
    2023-07-11T16:16:27.636923+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:16:27.637034+08:00         2692 Query     ROLLBACK TO SAVEPOINT sp
    2023-07-11T16:16:27.637116+08:00         2692 Query     RELEASE SAVEPOINT sp
    2023-07-11T16:16:27.637195+08:00         2692 Query     show events
    2023-07-11T16:16:27.637517+08:00         2692 Query     use `testdb_myisam`
    2023-07-11T16:16:27.637631+08:00         2692 Query     select @@collation_database
    2023-07-11T16:16:27.637741+08:00         2692 Query     SET SESSION character_set_results = 'binary'
    2023-07-11T16:16:27.637839+08:00         2692 Query     SHOW FUNCTION STATUS WHERE Db = 'testdb_myisam'
    2023-07-11T16:16:27.639206+08:00         2692 Query     SHOW PROCEDURE STATUS WHERE Db = 'testdb_myisam'
    2023-07-11T16:16:27.640377+08:00         2692 Query     SET SESSION character_set_results = 'utf8'
    2023-07-11T16:16:27.663274+08:00         2692 Quit

    在从服务器,使用上述 mysqldump 逻辑备份文件执行恢复,搭建从库。

    -- 从库查看数据库
    mysql> show databases;
    +--------------------+
    | Database           |
    +--------------------+
    | information_schema |
    | mysql              |
    | performance_schema |
    | sys                |
    +--------------------+
    -- 清空从库 binlog 和 gtid 信息
    mysql> reset master;
    -- 查看确认
    mysql> show master status\G;
    *************************** 1. row ***************************
                 File: mysql-bin.000001
             Position: 154
         Binlog_Do_DB:
     Binlog_Ignore_DB:
    Executed_Gtid_Set:
    1 row in set (0.00 sec)
    -- 执行 mysqldump 逻辑备份文件恢复
    mysql> source /tmp/dump.sql;
    -- 建立复制,并启动复制
    mysql> change master to MASTER_HOST='10.186.60.187',MASTER_PORT=3307,master_user='repl',master_password='1',MASTER_AUTO_POSITION=1;
    mysql> start slave;
    -- 查看复制状态
    mysql> show slave status\G;
    *************************** 1. row ***************************
                   Slave_IO_State: Waiting for master to send event
                      Master_Host: 10.186.60.187
                      Master_User: repl
                      Master_Port: 3307
                    Connect_Retry: 60
                  Master_Log_File: mysql-bin.000015
              Read_Master_Log_Pos: 190088135
                   Relay_Log_File: mysql-relay.000002
                    Relay_Log_Pos: 414
            Relay_Master_Log_File: mysql-bin.000015
                 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 '19112042-1f97-11ee-bf09-02000aba3cbb:3747' at master log mysql-bin.000015, end_log_pos 190087781. 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: 190087413
                  Relay_Log_Space: 1339
                  Until_Condition: None
                   Until_Log_File:
                    Until_Log_Pos: 0
               Master_SSL_Allowed: No
               Master_SSL_CA_File:
               Master_SSL_CA_Path:
                  Master_SSL_Cert:
                Master_SSL_Cipher:
                   Master_SSL_Key:
            Seconds_Behind_Master: NULL
    Master_SSL_Verify_Server_Cert: No
                    Last_IO_Errno: 0
                    Last_IO_Error:
                   Last_SQL_Errno: 1062
                   Last_SQL_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 1 failed executing transaction '19112042-1f97-11ee-bf09-02000aba3cbb:3747' at master log mysql-bin.000015, end_log_pos 190087781. See error log and/or   performance_schema.replication_applier_status_by_worker table for more details about this failure or others, if any.
      Replicate_Ignore_Server_Ids:
                 Master_Server_Id: 629181509
                      Master_UUID: 19112042-1f97-11ee-bf09-02000aba3cbb
                 Master_Info_File: mysql.slave_master_info
                        SQL_Delay: 0
              SQL_Remaining_Delay: NULL
          Slave_SQL_Running_State:
               Master_Retry_Count: 86400
                      Master_Bind:
          Last_IO_Error_Timestamp:
         Last_SQL_Error_Timestamp: 230711 17:03:01
                   Master_SSL_Crl:
               Master_SSL_Crlpath:
               Retrieved_Gtid_Set: 19112042-1f97-11ee-bf09-02000aba3cbb:3747-3748
                Executed_Gtid_Set: 19112042-1f97-11ee-bf09-02000aba3cbb:1-3746
                    Auto_Position: 1
             Replicate_Rewrite_DB:
                     Channel_Name:
               Master_TLS_Version:
    1 row in set (0.00 sec)
    -- 查看复制具体报错内容
    mysql> select * from  performance_schema.replication_applier_status_by_worker\G;
    *************************** 1. row ***************************
             CHANNEL_NAME:
                WORKER_ID: 1
                THREAD_ID: NULL
            SERVICE_STATE: OFF
    LAST_SEEN_TRANSACTION: 19112042-1f97-11ee-bf09-02000aba3cbb:3747
        LAST_ERROR_NUMBER: 1062
       LAST_ERROR_MESSAGE: Worker 1 failed executing transaction '19112042-1f97-11ee-bf09-02000aba3cbb:3747' at master log mysql-bin.000015, end_log_pos 190087781; Could not execute Write_rows event on table testdb_myisam.sbtest2; Duplicate entry '2' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 190087781
     LAST_ERROR_TIMESTAMP: 2023-07-11 17:03:01

    原理分析

    • 当 mysqldump 开始备份,并获取一致性位点后,UNLOCK TABLES 前,记为 T1 时刻。
    • 备份 InnoDB 表完成(假设先备份 InnoDB 表),记为 T2 时刻。
    • 备份 MyISAM 引擎表完成,记为 T3 时刻。
    • 在 T1 和 T2 之间,如果 MyISAM 引擎表有 INSERT 操作,会有 binlog 产生,mysqldump 也会把 T1 到 T2 之间对 MyISAM 引擎表的 INSERT 数据备份下来。
    • 这样就产生了,启动复制后,由于 SQL 线程会回放 T1 到 T2 期间的 binlog,而这部分数据已经在备份文件里了,并恢复到从库了,导致 SQL 线程回放报重复键的问题。
    • 使用该选项时:mysqldump --single-transaction 获取一致性备份只适用于 InnoDB 引擎,对于 InnoDB 引擎表的备份,获取的是 T1 时刻的快照,对于非 InnoDB 引擎表的备份,获取的是当前最新数据。

    mysqldump 搭建复制报错原因解析

    改进建议

    • 把业务库的非 InnoDB 引擎表,修改为 InnoDB,重新备份后搭建从库( 修改表的存储引擎开销较大,需要考虑改存储引擎对在线业务的影响,适合表可以改为 InnoDB 引擎的情况)。
    • 改用 Xtrabacku

    p 备份工具。如果非 InnoDB 的表比较大,备份 MyISAM 引擎期间, 备份线程持有实例的全局读锁(FLUSH TABLES WITH READ LOCK)时间将增加,将影响数据库可用性,选择业务低峰时执行。(适合短时间内无法修改表存储引擎的情况)。

    更多技术文章,请访问:https://www.jb51.net/

    关于 SQLE

    爱可生开源社区的 SQLE 是一款面向数据库使用者和管理者,支持多场景审核,支持标准化上线流程,原生支持 MySQL 审核且数据库类型可扩展的 SQL 审核工具。

    SQLE 获取

    类型地址
    版本库https://github.com/actiontech/sqle
    文档https://actiontech.github.io/sqle-docs/
    发布信息https://github.com/actiontech/sqle/releases
    数据审核插件开发文档https://actiontech.github.io/sqle-docs/docs/dev-manual/plugin...

    以上就是mysqldump 搭建复制报错原因解析的详细内容,更多关于mysqldump 搭建复制报错的资料请关注编程客栈(www.devze.com)其它相关文章!

    0

    精彩评论

    暂无评论...
    验证码 换一张
    取 消

    关注公众号