1问题的引出


当我们在处理 MySQL 复制故障时,经常遇到1032、1062错误,多数情况下属于人为连到从库执行了DML操作导致, 少数情况是由于主库挂了,数据没有正常同步,角色切换后,数据没有补齐导致。

  

mysql 主从1236 mysql主从1032_mysql 主从1236

处理方法如下几种:

1. 1062错误时,在从库把重复的数据删除即可,处理起来最方便;

2. 1032错误时,根据“show slave status”的结果去主库分析 

binlog,找到对应的数据,把数据插入到从库即可。少量的数据插入或更新操作起来也方便;批量数据操作时,人工确定哪一行有错误的话就比较累了,干脆就重新搭建主从环境。

3. 跳过当前事务,使用 pt 工具去校验数据。这个操作起来有限制,不能在业务高峰时操作,因为是全量比较。可以全库,也可以全表。


2四个测试 


                                                                                                                                          针对上面的痛点,我们先做些测试。这边不测试事务的跳过,因为跳过不确定会有什么新坑在等着我们。

一、环境介绍:

5.7.13-log MySQL Community Server
Master: 192.168.1.5
Slave: 192.168.1.4

二、 数据准备:

CREATE TABLE `test_repl` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `a` varchar(10) DEFAULT NULL,
  `b` varchar(10) DEFAULT NULL,
  `c` varchar(20) DEFAULT NULL,
  `d` datetime DEFAULT NULL,
  PRIMARY KEY (`id`),
  UNIQUE KEY `uiq_index` (`a`,`b`)
);

insert into test_repl (a, b, c, d) values('aa', 'bb', 'cc', now());
insert into test_repl (a, b, c, d) values('aaa', 'bbb', 'ccc', now());
insert into test_repl (a, b, c, d) values('aaaa', 'bbbb', 'cccc', now());
insert into test_repl (a, b, d) values('a1', 'b1', now());
insert into test_repl (a, b, d) values('a2', 'b2', now());
insert into test_repl (a, b, d) values('a3', 'b3', now());

mysql> select * from test_repl;
+----+------+------+------+---------------------+
| id | a    | b    | c    | d                   |
+----+------+------+------+---------------------+
|  1 | aa   | bb   | cc   | 2017-08-15 14:42:19 |
|  2 | aaa  | bbb  | ccc  | 2017-08-15 14:42:19 |
|  3 | aaaa | bbbb | cccc | 2017-08-15 14:42:19 |
|  4 | a1   | b1   | NULL | 2017-08-15 14:42:19 |
|  5 | a2   | b2   | NULL | 2017-08-15 14:42:19 |
|  6 | a3   | b3   | NULL | 2017-08-15 14:42:20 |
+----+------+------+------+---------------------+
6 rows in set (0.00 sec)

三、测试的故障类型

1. 测试1062,主键数据重复;

2. 测试1062,复合唯一索引数据重复;

3. 测试1032,更新时记录不存在;

4. 测试1032,删除时记录不存在。


:在每次测试前,使用之前准备好的数据。

测试一:测试1062,主键数据重复

id=7

insert into test_repl values(7, 'a4', 'b4', 'c4', now());
  1. 在主库也插入上面语句
insert into test_repl values(7, 'a4', 'b4', 'c4', now());
  1. 同步报错,部分日志如下:
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: Could not execute Write_rows event on table test.test_repl; Duplicate entry '7' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log binlog.000057, end_log_pos 256531451
  1. 修复思路,直接去从库把重复记录删除, 删除前记得保存下,保不定哪天查出来操作有误呢!
delete from test.test_repl where id = 7;
 start slave;
  1. 查看结果
Slave_IO_Running: Yes
             Slave_SQL_Running: Yes

测试二、 测试1062,复合唯一索引数据重复

id=7

insert into test_repl values(7, 'a4', 'b4', 'c4', now());

id=8,a='a4', b='b4', c='c4', r_time=now()

  1. 的记录
insert into test_repl values(8, 'a4', 'b4', 'c4', now());
  1. 同步报错,部分内容如下:
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: Could not execute Write_rows event on table test.test_repl; Duplicate entry 'a4-b4' for key 'uiq_index', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log binlog.000057, end_log_pos 256534236
  1. 修复思路

uiq_index

  •  (a,b)
  • 获取错误中的显示的重复记录,’a4-b4’
  • 使其顺序对应,这边的结果为 a=’a4’, b=’b4’,这边作为条件,去从库删除数据
delete from test.test_repl where a='a4' and b='b4';
start slave;
  1. 查看结果,部分内容
Slave_IO_Running: Yes
             Slave_SQL_Running: Yes

测试三: 测试1032,更新时记录不存在

id=4

  1. 的记录
delete from test_repl where id = 4;

id=4

update test_repl set a='new_a1111' where id = 4;
  1. 同步报错,部分内容如下:
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: 1032
                    Last_Error: Could not execute Update_rows event on table test.test_repl; Can't find record in 'test_repl', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log binlog.000057, end_log_pos 256538982
                  Skip_Counter: 0
           Exec_Master_Log_Pos: 256538707

这个时候我们无法知道是哪条记录出了问题, 得去分析下 主库的 binlog,也可以去分析 relary log,但是,无法知道这个事务在 relay log中的结束位置,只知道开始位置,所以不建议去分析 relary log。

这个事务的位置可以通过上面信息去主库的 binlog 文件里面查询,start-pos = Exec_Master_Log_Pos, stop-pos = Last_Error 里面的 end_log_pos。 拿着这两个信息,去主库分析 binlog。

4. 分析主库 binlog

[mysql@mq5 mysqlData]$ mysqlbinlog  -v --base64-output=decode-row binlog.000057 --start-position=256538707 stop-position=256538982
 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
 DELIMITER /*!*/;
 # at 256538707
 #170815 15:13:10 server id 5  end_log_pos 256538772 CRC32 0x376dfc56     GTID    last_committed=3052    sequence_number=3053 SET @@SESSION.GTID_NEXT= 'df101ae3-6f23-11e6-ab0d-9c5c8ed1c335:2264390'/*!*/;
 # at 256538772
 #170815 15:13:10 server id 5  end_log_pos 256538844 CRC32 0x8eae63a5     Query    thread_id=784    exec_time=0    error_code=0 SET TIMESTAMP=1502781190/*!*/;
 SET @@session.pseudo_thread_id=784/*!*/;
 SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
 SET @@session.sql_mode=1436549152/*!*/;
 SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
 /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
 SET @@session.lc_time_names=0/*!*/;
 SET @@session.collation_database=DEFAULT/*!*/;
 BEGIN
 /*!*/;
 # at 256538844
 #170815 15:13:10 server id 5  end_log_pos 256538907 CRC32 0xaf0ebe48     Table_map: `test`.`test_repl` mapped to number 575
 # at 256538907
 #170815 15:13:10 server id 5  end_log_pos 256538982 CRC32 0x6c8220fd     Update_rows: table id 575 flags: STMT_END_F
 ### UPDATE `test`.`test_repl`
 ### WHERE
 ###   @1=4
 ###   @2='a1'
 ###   @3='b1'
 ###   @4=NULL
 ###   @5='2017-08-15 15:12:32'
 ### SET
 ###   @1=4
 ###   @2='new_a1111'
 ###   @3='b1'
 ###   @4=NULL
 ###   @5='2017-08-15 15:12:32'
 # at 256538982
 #170815 15:13:10 server id 5  end_log_pos 256539013 CRC32 0x15d15eef     Xid = 166042
 COMMIT/*!*/;
 mysqlbinlog: File 'stop-position=256538982' not found (Errcode: 2 - No such file or directory)
 SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
 DELIMITER ;
 # End of log file
 /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

5. 拿着分析出来的binlog,加上对应的列名去从库验证数据是否在

mysql> select 1 from `test`.`test_repl` WHERE id = 4 and a='a1' and b='b1' and c is NULL and d='2017-08-15 15:12:32';
 Empty set (0.00 sec)

 mysql> select * from test_repl;
 +----+------+------+------+---------------------+
 | id | a    | b    | c    | d                   |
 +----+------+------+------+---------------------+
 |  1 | aa   | bb   | cc   | 2017-08-15 15:12:32 |
 |  2 | aaa  | bbb  | ccc  | 2017-08-15 15:12:32 |
 |  3 | aaaa | bbbb | cccc | 2017-08-15 15:12:32 |
 |  5 | a2   | b2   | NULL | 2017-08-15 15:12:32 |
 |  6 | a3   | b3   | NULL | 2017-08-15 15:12:32 |
 +----+------+------+------+---------------------+
 5 rows in set (0.00 sec)

6. 插入不存在的数据

INSERT INTO `test`.`test_repl` VALUES( 4 , 'a1' , 'b1' , NULL , '2017-08-15 15:12:32');
 start slave;

7. 查看结果,部分内容

Slave_IO_Running: Yes
             Slave_SQL_Running: Yes

测试四: 测试1032,删除时记录不存在

id=2

delete from test_repl where id = 2;
  1. 在主库也执行同样的操作
delete from test_repl where id = 2;
  1. 同步报错,部分内容如下:
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: 1032
                    Last_Error: Could not execute Delete_rows event on table test.test_repl; Can't find record in 'test_repl', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log binlog.000057, end_log_pos 256541184
                  Skip_Counter: 0
           Exec_Master_Log_Pos: 256540927

同样去分析 主库的binlog

  1. 分析主库binlog
[mysql@mq5 mysqlData]$ mysqlbinlog  -v --base64-output=decode-row binlog.000057 --start-position=256540927 --stop-position=256541184
 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
 /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
 DELIMITER /*!*/;
 # at 256540927
 #170815 15:35:12 server id 5  end_log_pos 256540992 CRC32 0x3890a134     GTID    last_committed=3060    sequence_number=3061
 SET @@SESSION.GTID_NEXT= 'df101ae3-6f23-11e6-ab0d-9c5c8ed1c335:2264398'/*!*/;
 # at 256540992
 #170815 15:35:12 server id 5  end_log_pos 256541064 CRC32 0xa3b6d7d7     Query    thread_id=784    exec_time=0    error_code=0
 SET TIMESTAMP=1502782512/*!*/;
 SET @@session.pseudo_thread_id=784/*!*/;
 SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
 SET @@session.sql_mode=1436549152/*!*/;
 SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
 /*!\C utf8 *//*!*/;
 SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
 SET @@session.lc_time_names=0/*!*/;
 SET @@session.collation_database=DEFAULT/*!*/;
 BEGIN
 /*!*/;
 # at 256541064
 #170815 15:35:12 server id 5  end_log_pos 256541127 CRC32 0x1b26e71f     Table_map: `test`.`test_repl` mapped to number 576
 # at 256541127
 #170815 15:35:12 server id 5  end_log_pos 256541184 CRC32 0xa6eb491b     Delete_rows: table id 576 flags: STMT_END_F
 ### DELETE FROM `test`.`test_repl`
 ### WHERE
 ###   @1=2
 ###   @2='aaa'
 ###   @3='bbb'
 ###   @4='ccc'
 ###   @5='2017-08-15 15:30:35'
 ROLLBACK /* added by mysqlbinlog */ /*!*/;
 SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
 DELIMITER ;
 # End of log file
 /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
  1. 拿着 binlog 里面的记录去从库查询,确定数据是否存在
    ` mysql> select 1 from `test`.`test_repl` where id=2 and a='aaa' and b='bbb' and c='ccc' and d='2017-08-15 15:30:35'; Empty set (0.00 sec)
  2. 从库插入不存在的记录
insert into `test`.`test_repl` values(2, 'aaa', 'bbb', 'ccc', '2017-08-15 15:30:35');
  1. 查看结果,部分内容如下:
Slave_IO_Running: Yes
             Slave_SQL_Running: Yes

3测试结论  


经过上面四个实验,可以得出处理思路就是: 数据重复,在从库删除重复数据,数据不存在,在从库插入不存在的记录。

具体要怎么删除,怎么插入,还得去具体分析,过程还是会有点累的,下面给出四种方案的具体分析方法                                                                                

  1. 主键重复时,根据直接主键列去删除记录就好,这个列需要从表结构中获取,并不是所有的主键列都是id;
  2. 唯一索引重复时,思路也是跟主键一样,需要获取具体的列,特别是复合索引时,有多个列,列与值需要对应起来;
  3. 更新记录不存在是,需要把根据 show slave status
  4. 删除时记录不存在,处理方法与第三个方法一样, 只能一条条试。

附:根据上面四种问题的分析思路,将处理步骤写成了脚本,使用方式与环境在脚本的最上面有说明。

如何减少 1062、1032 错误出现的次数?

  1. 从库设置只读
  2. 应用账号的权限不能 super 权限
  3. 定期使用 pt 工具校验数据一致性