主从同步UUID问题：found a zombie dump thread with the same UUID

Posted 2023-05-11

参考技术A 问题现象：

环境情况：

mysql:5.7.21架构1主2从M<-->M—>SLAVE

现象分析：

1、每60秒产生一次报警2、相同的uuid

问题原因分析：

原因

Uuid 重复问题

机器上的auto.conf id问题

网络问题

备份时停止同步问题

slave 超时时间slave_net_timeout

版本配置问题

排查思路：

1Uuid 重复问题都是唯一

2机器上的Auto.conf都是唯一

3网络问题利用iptables模拟

4备份停止时的操作备份时间不对

5Master 数据 不更新Slave 超时时间问题有的db组大量更新还是存在

6Slave 重启很像，但是凌晨没人重启

测试步骤：

根据上面的排查思路准备环境进行开始测试。

环境：

Master：10.110.10.31

Slave:10.110.10.30互为主从

Sysbench:用来测试插入数据配置同步（略）

测试

Uuid 与auto.conf 相同因为做主从配置时通常拷贝数据，因此有可能存在auto相同的情况，但是一一确认后发现不同。

测试slave 重启，master日志情况

在10.110.10.30 上执行如下

Stopslave;Startsalve;

发现日志如下：

Master 日志：

2020-08-05T17:48:46.033859+08:00 63510[Note] While initializing dump thread for slavewithUUID,founda zombie dumpthreadwiththe same UUID.Masteriskilling the zombie dumpthread(8398).2020-08-05T17:48:46.034067+08:0063510[Note]Startbinlog_dumptomaster_thread_id(63510)slave_server(9013100), pos(,4)

解说：

发现日志很符合线上报错的日志，但是查日志发现每60秒就会产生，线上也不可能频繁重启slave。

测试网络

在10.110.10.31 上执行IP tables 限制30访问，查看日志情况

iptables-IINPUT-s10.110.10.30-jDROP

slave 同步状态

mysql> show slave status\G;*************************** 1. row ***************************Slave_IO_State: Reconnecting after a failed master event readMaster_Host: 10.110.10.31Master_User: replicMaster_Port: 3070Connect_Retry: 60Master_Log_File: mysql-bin.000008Read_Master_Log_Pos: 2659Relay_Log_File: relay-bin.000010Relay_Log_Pos: 2832Relay_Master_Log_File: mysql-bin.000008Slave_IO_Running: ConnectingSlave_SQL_Running: Yes

30上日志：

2020-08-05T20:08:04.931077+08:0063498[Warning]Storing MySQL user nameorpassword informationinthe master info repositoryisnotsecureandisthereforenotrecommended. Please consider using the USERand PASSWORD connection optionsforSTART SLAVE; see the'START SLAVE Syntax'inthe MySQL Manualformore information.2020-08-05T20:08:34.869063+08:0063510[Note] Aborted connection63510to db:'unconnected'user:'replic'host:'10.110.10.30'(failed on flush_net())2020-08-05T20:08:34.925537+08:0063792[Note] Start binlog_dump tomaster_thread_id(63792) slave_server(9013100), pos(,4)

解说：

发现日志访问master 出现flush_net() 关键字，但是线上并没有，因此排除网络问题。

备份停止时的操作xtrabackup

因为备份是利用percona 的xtrabackup工具，加了slave信息保持一致性的参数 --slave-info 但是发现时间对应不上因此排除

 

思路中断

此时发现常规的想法已经实现不通，需要查下同步参数，翻阅官方文档发现同步参数slave_net_timeout，根据参数定义为slave 在没有收到master 数据时的超时时间，会再次重新连接master，感觉有点线索了。对slave_net_timeout开始进行测试。此值默认为60

缩短 slave 网络超时时间,但没数据

在10.110.10.30 上执行如下：

Stopslave;setglobalslave_net_timeout=5;startsalve;

测试日志：

10.110.10.31 上的日志:

2020-08-06T09:59:31.226156+08:00 65500 [Note] While initializingdump thread for slavewithUUID,founda zombie dumpthreadwiththe same UUID.Masteriskilling the zombiedumpthread(65499).2020-08-06T09:59:31.226273+08:0065500[Note]Startbinlog_dump tomaster_thread_id(65500) slave_server(901311100), pos(mysql-bin.000008,828)2020-08-06T09:59:32.237103+08:0065501[Note]Whileinitializing dump threadforslavewithUUID,foundazombie dumpthreadwiththe same UUID.Masteriskilling the zombie dumpthread(65500).2020-08-06T09:59:32.237253+08:0065501[Note]Startbinlog_dump tomaster_thread_id(65501) slave_server(901311100), pos(mysql-bin.000008,828)2020-08-06T09:59:33.245805+08:0065502[Note]Whileinitializing dump threadforslavewithUUID,foundazombie dumpthreadwiththe same UUID.Masteriskilling the zombie dumpthread(65501).2020-08-06T09:59:33.245910+08:0065502[Note]Startbinlog_dumptomaster_thread_id(65502)slave_server(901311100), pos(mysql-bin.000008,828)

10.110.10.30 上的日志:

2020-08-06T10:02:01.030159+08:0018[Warning] Storing MySQL usernameorpassword informationinthe master info repositoryisnotsecureandisthereforenotrecommended. Please consider using the USERandPASSWORDconnection optionsforSTART SLAVE; see the'START SLAVE Syntax'inthe MySQLManualformore information.

解说：

发现结果日志已经符合预期，当slave_net_timeout时间过短，会频繁重连，发现产生日志和问题一样，那么接下来我插入数据看下情况

缩短 slave 网络超时时间,但有数据插入

在10.110.10.30 上执行如下：

Stopslave;setglobalslave_net_timeout=5;startsalve;

插入数据：

sysbench/root/sysbench-1.0.19/tests/include/oltp_legacy/oltp.lua--mysql-host=10.110.10.30--mysql-user=root --mysql-password='xxx'--mysql-port=3070--mysql-db=sbtest  --oltp-table-size=10000000--oltp-tables-count=1--threads=1--events=500000--time=1200--report-interval=1prepare

日志：

解说：

发现已经没有日志输出，说明插入数据时，说明slave_net_timeout在有master 有binlog日志产生的情况下没问题，只有在空闲时会发生。

再次中断

可以验证slave_net_timeout 是产生问题的原因，但是线上有很多组db 没有日志产生也没有报错，反而写入量大的会存在问题，此时陷入迷惑中，因为此理由不能说服领导啊。继续看官方文档。发下如下信息

发现有个MASTER_HEARTBEAT_PERIOD参数，意思是多长时间对master 进行探测是否存活，默认为slave_net_timeout的一半也就是30，有线索了继续测试

MASTER_HEARTBEAT_PERIOD测试

对于发生问题的db机器进行查询MASTER_HEARTBEAT_PERIOD参数的值，发现为1800

而正常机器都是30，发现其中猫腻。

mysql> select * from mysql.slave_master_info\G*************************** 1. row ***************************Number_of_lines: 25Master_log_name: mysql-bin.000651Master_log_pos: 131563718Connect_retry: 60Heartbeat: 1800

在10.110.10.30slave上执行

slave：上

mysql>stop slave;Query OK, 0 rows affected (0.00 sec)mysql>change master to master_heartbeat_period = 1800;Query OK, 0 rows affected, 1 warning (0.11 sec)mysql>start slave;Query OK, 0 rows affected (0.00 sec)

查看日志：

Slave上：

Master上：

发现问题已经复现

这个确实是从5.5 升级到5.7 的版本，slave_net_timetou原来是3600，Heartbeat：1800，因此问题已经定位。

MySQL主从同步报错故障处理记录

前言

在发生故障切换后，经常遇到的问题就是同步报错，下面是最近收集的报错信息。

---

记录删除失败

在master上删除一条记录，而slave上找不到

Last_SQL_Error: Could not execute Delete_rows event on table hcy.t1;
Can‘t find record in ‘t1‘,
Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND;
the event‘s master log mysql-bin.000006, end_log_pos 254

解决方法：master要删除一条记录，而slave上找不到报错，这种情况主都已经删除了，那么从机可以直接跳过。

stop slave;
set global sql_slave_skip_counter=1;
start slave;

如果这种情况很多，需要针对这种错误专门写相关脚本。

---

主键重复

在slave已经有该记录，又在master上插入了同一条记录。

Last_SQL_Error: Could not execute Write_rows event on table hcy.t1; 
Duplicate entry ‘2‘ for key ‘PRIMARY‘, 
Error_code: 1062; 
handler error HA_ERR_FOUND_DUPP_KEY; the event‘s master log mysql-bin.000006, end_log_pos 924

解决方法：

在slave上用desc hcy.t1; 先看下表结构：

mysql> desc hcy.t1;
+-------+---------+------+-----+---------+-------+
| Field | Type    | Null | Key | Default | Extra |
+-------+---------+------+-----+---------+-------+
| id    | int(11) | NO   | PRI | 0       |       | 
| name  | char(4) | YES  |     | NULL    |       | 
+-------+---------+------+-----+---------+-------+

删除重复的主键

mysql> delete from t1 where id=2;
Query OK, 1 row affected (0.00 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)

mysql> show slave status\G;
……
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
……
mysql> select * from t1 where id=2;

在master上和slave上再分别确认一下。

---

更新丢失

在master上更新一条记录，而slave上找不到，丢失了数据。

Last_SQL_Error: Could not execute Update_rows event on table hcy.t1; 
Can‘t find record in ‘t1‘, 
Error_code: 1032; 
handler error HA_ERR_KEY_NOT_FOUND; 
the event‘s master log mysql-bin.000010, end_log_pos 794

解决方法：

在master上，用mysqlbinlog 分析下出错的binlog日志在干什么。

/usr/local/mysql/bin/mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS mysql-bin.000010 | grep -A ‘10‘ 794

#120302 12:08:36 server id 22  end_log_pos 794  Update_rows: table id 33 flags: STMT_END_F
### UPDATE hcy.t1
### WHERE
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2=‘bbc‘ /* STRING(4) meta=65028 nullable=1 is_null=0 */
### SET
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2=‘BTV‘ /* STRING(4) meta=65028 nullable=1 is_null=0 */
# at 794
#120302 12:08:36 server id 22  end_log_pos 821  Xid = 60
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET [email protected]_COMPLETION_TYPE*/;

在slave上，查找下更新后的那条记录，应该是不存在的。

mysql> select * from t1 where id=2;
Empty set (0.00 sec)

然后再到master查看

mysql> select * from t1 where id=2;
+----+------+
| id | name |
+----+------+
|  2 | BTV  | 
+----+------+
1 row in set (0.00 sec)

把丢失的数据在slave上填补，然后跳过报错即可。

mysql> insert into t1 values (2,‘BTV‘);
Query OK, 1 row affected (0.00 sec)

mysql> select * from t1 where id=2;    
+----+------+
| id | name |
+----+------+
|  2 | BTV  | 
+----+------+
1 row in set (0.00 sec)

mysql> stop slave ;set global sql_slave_skip_counter=1;start slave;
Query OK, 0 rows affected (0.01 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)

mysql> show slave status\G;
……
 Slave_IO_Running: Yes
 Slave_SQL_Running: Yes
……

---

1236错误, 二进制文件缺失

误删二进制文件等各种原因，导致主库mysql-bin.000012文件丢失，从库同步失败。

Master_Log_File: mysql-bin.000012
Slave_IO_Running: No
Slave_SQL_Running: Yes
Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: ‘Could not find first log file name in binary log index file‘

• 首先停止从库同步

  slave stop;
  

• 查看主库日志文件和位置

  mysql> show master logs;
  +------------------+-----------+
  | Log_name         | File_size |
  +------------------+-----------+
  | mysql-bin.000013 |       154 |
  +------------------+-----------+
  

• 回从库，使日志文件和位置对应主库

  CHANGE MASTER TO MASTER_LOG_FILE=‘log-bin.000013‘,MASTER_LOG_POS=154;
  

• 最后，启动从库：

    ```bash
    slave start;

    show slave status\G;

    Master_Log_File: mysql-bin.000013
    Slave_IO_Running: Yes
    Slave_SQL_Running: Yes
    Last_IO_Error:
    ```

---

中继日志损坏

slave的中继日志relay-bin损坏。

Last_SQL_Error: Error initializing relay log position: I/O error reading the header from the binary log
Last_SQL_Error: Error initializing relay log position: Binlog has bad magic number;  
It‘s not a binary log file that can be used by  this version of MySQL

1、手工修复
解决方法：找到同步的binlog和POS点，然后重新做同步，这样就可以有新的中继日值了。

例子：

mysql> show slave status\G;
*************************** 1. row ***************************
              Master_Log_File: mysql-bin.000010
          Read_Master_Log_Pos: 1191
               Relay_Log_File: vm02-relay-bin.000005
                Relay_Log_Pos: 253
        Relay_Master_Log_File: mysql-bin.000010
             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: 1593
                   Last_Error: Error initializing relay log position: I/O error reading the header from the binary log
                 Skip_Counter: 1
          Exec_Master_Log_Pos: 821

Slave_IO_Running ：接收master的binlog信息
                   Master_Log_File
                   Read_Master_Log_Pos

Slave_SQL_Running：执行写操作
                   Relay_Master_Log_File
                   Exec_Master_Log_Pos

以执行写的binlog和POS点为准。

Relay_Master_Log_File: mysql-bin.000010
Exec_Master_Log_Pos: 821

mysql> stop slave;
Query OK, 0 rows affected (0.01 sec)

mysql> CHANGE MASTER TO MASTER_LOG_FILE=‘mysql-bin.000010‘,MASTER_LOG_POS=821;
Query OK, 0 rows affected (0.01 sec)

mysql> start slave;
Query OK, 0 rows affected (0.00 sec)


mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.8.22
                  Master_User: repl
                  Master_Port: 3306
                Connect_Retry: 10
              Master_Log_File: mysql-bin.000010
          Read_Master_Log_Pos: 1191
               Relay_Log_File: vm02-relay-bin.000002
                Relay_Log_Pos: 623
        Relay_Master_Log_File: mysql-bin.000010
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: 
           Replicate_Do_Table: 
       Replicate_Ignore_Table: 
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 1191
              Relay_Log_Space: 778
              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: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
                Last_IO_Error: 
               Last_SQL_Errno: 0
               Last_SQL_Error: 

2、Ibbackup
各种大招都用上了，无奈slave数据丢失过多，ibbackup（需要银子）该你登场了。

Ibbackup热备份工具，是付费的。xtrabackup是免费的，功能上一样。

Ibbackup备份期间不锁表，备份时开启一个事务（相当于做一个快照），然后会记录一个点，之后数据的更改保存在ibbackup_logfile文件里，恢复时把ibbackup_logfile 变化的数据再写入到ibdata里。

Ibbackup 只备份数据（ ibdata、.ibd ），表结构.frm不备份。

MySQL主从复制常见故障及解决方法？

1.1.1故障1：从库数据与主库冲突

show slave status; 报错：且show slave status\G

Slave_I/O_Running:Yes

Slave_SQL_Running:No

Seconds_Behind_Master:NULL

Last_error:Error ‘Can‘t create database ‘xiaoliu‘; database exists‘ on query. Default  

database:‘xiaoliu‘.query:‘create database xiaoliu‘




解决方法1：

stop slave;

set global sql_slave_skip_counter = 1; #将同步指针向下移动一个，如果多次不同步可以重复操作

解决方法2：在从库配置文件中配置，直接跳过不影响业务的错误号

grep slave-skip /etc/my.cnf

slave-skip-errors = 1032,1062,1007

1.1.2故障2：MySQL主从复制延迟问题原因和解决方案

问题1：主库的从库太多，导致复制延迟

从库数量一般 3—5个为宜，要复制的节点过多，导致复制延迟

问题2：从库硬件配置比主库差，导致延迟

查看Master和Slave的配置，可能因为配置不当导致复制的延迟

问题3：慢SQL语句过多

假如一条语句执行时间超过2秒， 就需要进行优化进行调整

问题4：主从复制设计问题

主从复制单线程，如果主库的写入并发太大，来不及传送到从库就会导致延迟

更高版本的MySQL可以支持多线程复制，门户网站则会自己开发多线程同步功能

问题5：主从库之间的网络延迟

主从库网卡、网线、连接的交换机等网络设备都可能成为复制的瓶颈

导致复制延迟，另外跨公网主从复制很容易导致主从复制延迟

问题6：主库读写压力大，导致复制延迟

主库硬件要好一些，架构前端要加buffer缓存层