mysqldump 搭建复制报错，竟然是因为这个！

2023-07-25 708

作者详细分析了一个 mysqldump 搭建复制失败的问题分析过程和改进建议。

作者：李富强

爱可生 DBA 团队成员，熟悉 MySQL，TiDB，OceanBase 等数据库。相信持续把对的事情做好一点，会有不一样的收获。

本文来源：原创投稿

爱可生开源社区出品，原创内容未经授权不得随意使用，转载请联系小编并注明来源。

故障现象

某客户反馈，使用 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>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_CACHE */ * 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 Init 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:16: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 引擎表的备份，获取的是当前最新数据。

改进建议

把业务库的非 InnoDB 引擎表，修改为 InnoDB，重新备份后搭建从库（修改表的存储引擎开销较大，需要考虑改存储引擎对在线业务的影响，适合表可以改为 InnoDB 引擎的情况）。
改用 Xtrabackup 备份工具。如果非 InnoDB 的表比较大，备份 MyISAM 引擎期间，备份线程持有实例的全局读锁（FLUSH TABLES WITH READ LOCK）时间将增加，将影响数据库可用性，选择业务低峰时执行。（适合短时间内无法修改表存储引擎的情况）。

更多技术文章，请访问：https://opensource.actionsky.com/

关于 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/plugins/howtouse

微信关注我们

原文链接：https://my.oschina.net/actiontechoss/blog/10090762

转载内容版权归作者及来源网站所有！

低调大师中文资讯倾力打造互联网数据资讯、行业资源、电子商务、移动互联网、网络营销平台。持续更新报道IT业界、互联网、市场资讯、驱动更新,是最及时权威的产业资讯及硬件资讯报道平台。

全链路灰度的挑战、实现思路与解决方案

微服务架构下的灰度发布挑战在传统的单体应用架构中，灰度发布相对简单。只需要在服务的流量入口处进行分流，通过使用 K8s Service 或各种类型的网关即可实现。然而，微服务架构引入了新的复杂性，服务之间的依赖关系错综复杂。有时候，某个功能的发布可能依赖于多个服务，要求灰度流量在整个调用链中准确路由到灰度版本的服务。传统的单个服务流量入口设置分流的做法无法满足这一需求。为了解决微服务架构下的灰度发布问题，全链路灰度发布引入了泳道（Lane）的概念。泳道将灰度视角从单个服务扩展到整个请求的调用链上，确保流量能够精确地在一组指定规则的服务之间流动，就像在预先设置好的泳道中一样。全链路灰度发布方案专为微服务架构设计，旨在应对微服务架构下的灰度发布挑战。全链路灰度发布的实现思路全链路灰度发布的核心在于流量泳道概念的实现，而泳道正如上文所说，是对满足指定规则的流量定下一个活动范围，它有以下两种实现思路：第一种思路：完整环境隔离泳道实现的主要难点在于，流量在服务间调用的过程中如何路由到正确的服务版本，但有一个简单的实现思路可以规避这个问题：复制一个包含所有微服务的完整环境，将需要灰度的服...

2023-07-25

409

作者：苏琳多点DMALL 供应链补货团队负责人多点DMALL 成立于 2015 年。从创立伊始，就致力于以大数据、云计算、AI 等数字技术改变零售业，是一站式全渠道数字零售解决方案服务商，数字化解构重构零售产业，提供端到端的商业 SaaS 解决方案。多点DMALL 通过 DMALL OS 提供零售云一站式解决方案，帮助零售商和品牌商数字化转型，实现线上线下一体化；同时通过多点 App 等工具赋能全渠道经营能力，并提供各类增值服务。需求概述商家要求支持 4 个月的日志查询，目前线上只支持 1 个月。每天日志是 400 万行项，1 个月的日志量是 1.2 亿，考虑到后续业务的增长，预计每月日志数据量会增长到 2.5亿；4 个月的日志量是 10 亿行项左右。现采用的 MongoDB 集群因资源受限无法支持 10 亿行项存储及查询，急需寻找另外的解决方案。 Databend的介绍及优势 Databend 是一个开源的、完全面向云架构的新式数仓，它提供快速的弹性扩展能力，并结合云的弹性、简单性和低成本，使 Data Cloud 构建变得更加容易。Databend 把数据存储在 AWS...

2023-07-25

779

资源下载

更多资源

优质分享App

近一个月的开发和优化，本站点的第一个app全新上线。该app采用极致压缩，本体才4.36MB。系统里面做了大量数据访问、缓存优化。方便用户在手机上查看文章。后续会推出HarmonyOS的适配版本。

Mario

马里奥是站在游戏界顶峰的超人气多面角色。马里奥靠吃蘑菇成长，特征是大鼻子、头戴帽子、身穿背带裤，还留着胡子。与他的双胞胎兄弟路易基一起，长年担任任天堂的招牌角色。

腾讯云软件源

为解决软件依赖安装时官方源访问速度慢的问题，腾讯云为一些软件搭建了缓存服务。您可以通过使用腾讯云软件源站来提升依赖包的安装速度。为了方便用户自由搭建服务架构，目前腾讯云软件源站支持公网访问和内网访问。

Rocky Linux

Rocky Linux（中文名：洛基）是由Gregory Kurtzer于2020年12月发起的企业级Linux发行版，作为CentOS稳定版停止维护后与RHEL（Red Hat Enterprise Linux）完全兼容的开源替代方案，由社区拥有并管理，支持x86_64、aarch64等架构。其通过重新编译RHEL源代码提供长期稳定性，采用模块化包装和SELinux安全架构，默认包含GNOME桌面环境及XFS文件系统，支持十年生命周期更新。