MYSQL同步报错故障处理方法总结

故障解决 专栏收录该内容
8 篇文章 0 订阅

前言

在发生故障切换后,经常遇到的问题就是同步报错,数据库很小的时候,dump完再导入很简单就处理好了,但线上的数据库都5T,如果用单纯的这种方法,成本太高,故经过一段时间的摸索,总结了几种处理方法。

生产环境架构图

目前现网的架构,保存着两份数据,通过异步复制做的高可用集群,两台机器提供对外服务。在发生故障时,切换到slave上,并将其变成master,坏掉的机器反向同步新的master,在处理故障时,遇到最多的就是主从报错。下面是我收录下来的报错信息。

常见错误

最常见的3种情况

这3种情况是在HA切换时,由于是异步复制,且sync_binlog=0,会造成一小部分binlog没接收完导致同步报错。

第一种:在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

第二种:主键重复。在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

第三种:在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 263

异步半同步区别

异步复制
简单的说就是master把binlog发送过去,不管slave是否接收完,也不管是否执行完,这一动作就结束了.

半同步复制
简单的说就是master把binlog发送过去,slave确认接收完,但不管它是否执行完,给master一个信号我这边收到了,这一动作就结束了。(谷歌写的代码,5.5上正式应用。)

异步的劣势
当master上写操作繁忙时,当前POS点例如是10,而slave上IO_THREAD线程接收过来的是3,此时master宕机,会造成相差7个点未传送到slave上而数据丢失。

特殊的情况

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

这种情况SLAVE在宕机,或者非法关机,例如电源故障、主板烧了等,造成中继日志损坏,同步停掉。

人为失误需谨慎:多台slave存在重复server-id
这种情况同步会一直延时,永远也同步不完,error错误日志里一直出现上面两行信息。解决方法就是把server-id改成不一致即可。

Slave: received end packet from server, apparent master shutdown:
Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.000012' at postion 106

问题处理

删除失败

在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;

如果这种情况很多,可用我写的一个脚本skip_error_replcation.sh,默认跳过10个错误(只针对这种情况才跳,其他情况输出错误结果,等待处理),这个脚本是参考maakit工具包的mk-slave-restart原理用shell写的,功能上定义了一些自己的东西,不是无论什么错误都一律跳过。)

主键重复

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

1

2

3

4

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; 先看下表结构:

1

2

3

4

5

6

7

mysql> desc hcy.t1;

+-------+---------+------+-----+---------+-------+

| Field | Type  | Null | Key | Default | Extra |

+-------+---------+------+-----+---------+-------+

| id  | int(11) | NO  | PRI | 0    |    |

| name | char(4) | YES |   | NULL  |    |

+-------+---------+------+-----+---------+-------+

 

删除重复的主键

1

2

3

4

5

6

7

8

9

10

11

12

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上找不到,丢失了数据。

1

2

3

4

5

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日志在干什么。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

/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 COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

 

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

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

然后再到master查看

1

2

3

4

5

6

7

mysql> select * from t1 where id=2;

+----+------+

| id | name |

+----+------+

| 2 | BTV |

+----+------+

1 row in set (0.00 sec)

 

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

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

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

……

 

中继日志损坏

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

1

2

3

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

 

手工修复

解决方法:找到同步的binlog和POS点,然后重新做同步,这样就可以有新的中继日值了。

例子:

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

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点为准。

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

48

49

50

51

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:

 

 

在异步或半同步的复制结构中,从库出现延迟是一件十分正常的事。
虽出现延迟正常,但是否需要关注,则一般是由业务来评估。
如:从库上有需要较高一致性的读业务,并且要求延迟小于某个值,那么则需要关注。

首先,简单概述一下复制逻辑:
1、主库将对数据库实例的变更记录到binlog中。  
2、主库会有binlog dump线程实时监测binlog的变更并将这些新的events推给从库(Master has sent all binlog to slave; waiting for more updates)
3、从库的IO Thread接收这些events,并将其记录入relaylog。
4、从库的SQL Thread读取relaylog的events,并将这些events应用(或称为重放)到从库实例。

上述为默认的异步复制逻辑,半同步复制又有些许不同,此处不再赘述。


此外,判断从库有延迟是十分简单的一件事:
在从库上通过SHOW SLAVE STATUS
检查Seconds_Behind_Master值即可。


产生延迟的原因及处理思路
〇 主库DML请求频繁(tps较大)

即主库写请求较多,有大量insert、delete、update并发操作,短时间产生了大量的binlog。

【原因分析】
主库并发写入数据,而从库SQL Thread为单线程应用日志,很容易造成relaylog堆积,产生延迟。

【解决思路】
做sharding,通过scale out打散写请求。或考虑升级到MySQL 5.7+,开启基于逻辑时钟的并行复制。

〇 主库执行大事务

 

比如大量导入数据,INSERT INTO $tb1 SELECT * FROM $tb2、LOAD DATA INFILE等
比如UPDATE、DELETE了全表等
Exec_Master_Log_Pos一直未变,Slave_SQL_Running_State为Reading event from the relay log
分析主库binlog,看主库当前执行的事务也可知晓。

【原因分析】
假如主库花费200s更新了一张大表,在主从库配置相近的情况下,从库也需要花几乎同样的时间更新这张大表,此时从库延迟开始堆积,后续的events无法更新。

【解决思路】
拆分大事务,及时提交。

〇 主库对大表执行DDL语句

现象和主库执行大事务相近。
检查Exec_Master_Log_Pos一直未动,也有可能是在执行DDL。
分析主库binlog,看主库当前执行的事务也可知晓。

【原因分析】
1、DDL未开始,被阻塞,SHOW SLAVE STATUS检查到Slave_SQL_Running_State为waiting for table metadata lock,且Exec_Master_Log_Pos不变。
2、DDL正在执行,SQL Thread单线程应用导致延迟增加。Slave_SQL_Running_State为altering table,Exec_Master_Log_Pos不变

【解决思路】
通过processlist或information_schema.innodb_trx来找到阻塞DDL语句的查询,干掉该查询,让DDL正常在从库执行。
DDL本身造成的延迟难以避免,建议考虑:
① 业务低峰期执行 
② set sql_log_bin=0后,分别在主从库上手动执行DDL(此操作对于某些DDL操作会造成数据不一致,请务必严格测试)

〇 主库与从库配置不一致:

【原因分析】
硬件上:主库实例服务器使用SSD,而从库实例服务器使用普通SAS盘、cpu主频不一致等
配置上:如RAID卡写策略不一致,OS内核参数设置不一致,MySQL落盘策略不一致等

【解决思路】
尽量统一DB机器的配置(包括硬件及选项参数)
甚至对于某些OLAP业务,从库实例硬件配置高于主库等

〇 表缺乏主键或唯一索引

binlog_format=row的情况下,如果表缺乏主键或唯一索引,在UPDATE、DELETE的时候可能会造成从库延迟骤增。
此时Slave_SQL_Running_State为Reading event from the relay log。
并且SHOW OPEN TABLES WHERE in_use=1的表一直存在。
Exec_Master_Log_Pos不变。
mysqld进程的cpu几近100%(无读业务时),io压力不大

【原因分析】
做个极端情况下的假设,主库更新一张500w表中的20w行数据,该update语句需要全表扫描
而row格式下,记录到binlog的为20w次update操作,此时SQL Thread重放将特别慢,每一次update可能需要进行一次全表扫描

【解决思路】
检查表结构,保证每个表都有显式自增主键,并建立合适索引。

〇 从库自身压力过大

【原因分析】
从库执行大量select请求,或业务大部分select请求被路由到从库实例上,甚至大量OLAP业务,或者从库正在备份等。
此时可能造成cpu负载过高,io利用率过高等,导致SQL Thread应用过慢。

【解决思路】
建立更多从库,打散读请求,降低现有从库实例的压力。

〇 MyISAM存储引擎

此时从库Slave_SQL_Running_State为Waiting for table level lock

【原因分析】
MyISAM只支持表级锁,并且读写不可并发操作。
主库在设置@@concurrent_insert对应值的情况下,能并发在select时执行insert,但从库SQL Thread重放时并不可并发,有兴趣可以再去看看myisam这块的实现。

【解决思路】
当然是选择原谅它了,既然选择了MyISAM,那么也应该要有心理准备。(还存在其他场景,也不推荐MyISAM在复制结构中使用)
改成InnoDB吧。
 

总结

通过SHOW SLAVE STATUS与SHOW PROCESSLIST查看现在从库的情况。(顺便也可排除在从库备份时这种原因)
若Exec_Master_Log_Pos不变,考虑大事务、DDL、无主键,检查主库对应的binlog及position即可。
若Exec_Master_Log_Pos变化,延迟逐步增加,考虑从库机器负载,如io、cpu等,并考虑主库写操作与从库自身压力是否过大。

如果上述原因都没有,那么请教请教DBA大佬们吧。

当然,Seconds_Behind_Master也不一定准确,存在在少部分场景下,虽Seconds_Behind_Master为0,但主从数据不一致的情况。

 

  • 1
    点赞
  • 0
    评论
  • 0
    收藏
  • 打赏
    打赏
  • 扫一扫,分享海报

©️2021 CSDN 皮肤主题: 技术黑板 设计师:CSDN官方博客 返回首页

打赏作者

jerry-89

你的鼓励将是我创作的最大动力

¥2 ¥4 ¥6 ¥10 ¥20
输入1-500的整数
余额支付 (余额:-- )
扫码支付
扫码支付:¥2
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、C币套餐、付费专栏及课程。

余额充值