操作解析:MySQL如何查看复制信息并排查问题(上)

开发 开发工具
本文梳理了UCloud在运维本公司MySQL高可用产品UDB过程中遇到的复制问题,并总结了当复制发生异常时,排查复制异常的方法。

“复制”作为MySQL原生的数据同步功能,在MySQL高可用架构中起着至关重要的作用。本文梳理了UCloud在运维本公司MySQL高可用产品UDB过程中遇到的复制问题,并总结了当复制发生异常时,排查复制异常的方法。

MySQL

一、错误排查

1. 收集复制信息

在复制发生异常时,首先要分别收集与复制、错误相关的信息,主要通过以下手段进行。

1.1 查看show slave status

执行命令“show slave status”查看复制相关信息,主要关注几条信息:

  1. Master_Log_File: MySQL-bin.000063 
  2. Read_Master_Log_Pos: 282657539 

IO线程读取到主库的binlog文件名和该binlog中的位置。这两个字段代表复制过程中binlog由主库传输到备库的进度。

  1. Relay_Log_File: MySQL-relay.000002 
  2. Relay_Log_Pos: 313885 

SQL线程执行到relay log文件名和该relay log中的位置。

  1. Relay_Master_Log_File: MySQL-bin.000002 
  2. Exec_Master_Log_Pos: 316585 

SQL线程执行到relay log对应主库中的binlog文件名和该binlog的位置。

这四个字段代表复制过程中,主库数据在备库上重放的进度。

  1. Slave_IO_Running: Yes 
  2. Slave_SQL_Running: No 

当前发生问题的是哪个线程?IO线程或者是SQL线程。

  1. Retrieved_Gtid_Set: ed7c5ee4-762d-11e6-ab9e-6c92bf24c36a:14-3920163 
  2. Executed_Gtid_Set: 04ffb4f5-762e-11e6-81e4-6c92bf26c5c2:1 

这两个字段在开启GTID后才有意义。分别代表IO线程接收到binlog中的事务对应的GTID和SQL线程执行过的事务对应的GTID。

这里的GTID不会因为复制而发生改变,即主库GTID对应的事务一定是主库执行过之后,通过复制发送过来的。备库GTID对应的事务一定是备库执行的。

  1. Last_Errno/Last_IO_Errno/Last_SQL_Errno 
  2. Laset_Error/Last_IO_Error/Last_SQL_Error 

IO/SQL线程发生错误的相关描述

1.2 查看错误日志

错误日志记录了mysqld发生的错误信息,即复制的错误信息,同时也会记录复制开始和停止的相关信息,记录位置可以通过如下方式查看:

查看错误日志

在error log中,主要关注如下信息。

(1) 开始复制(start slave)

从库启动复制时,error log中会记录复制起始位置,包括IO线程读取主库端binlog的起始位置和SQL线程执行的relay log起始位置。同时,error log还会记录开始复制的具体时间。

  1. 2017-04-17T14:47:19.691088Z 7 [Note] Slave I/O thread for channel '': connected to master  
  2. 'repl@192.168.150.21:30001',replication started in log  
  3. 'binlog001.000002' at position 194 
  4. 2017-04-17T14:47:19.693377Z 8 [Note] Slave SQL thread for channel '' initialized, starting replication in log  
  5. 'binlog001.000002' at position 194, relay log  
  6. './relaylog002.000217' position: 407 

(2) 停止复制(stop slave)

从库停止复制时,error log会记录IO线程停止时读取到的主库binlog的位置,以及停止复制的时间。

  1. 2017-04-18T03:05:52.920750Z 14 [Note] Error reading relay log event for channel '': slave SQL thread was killed2017-04-18T03:05:52.922007Z 13 [Note] Slave I/O thread killed while reading event for channel ''2017-04-18T03:05:52.922041Z 13 [Note] Slave I/O thread exiting for channel '', read up to log 'binlog001.000002', position 443 

(3) 复制错误信息

复制错误信息的描述会在show slave status的last_error中展现,但如果错误信息较长(尤其是在多线程复制的情况下),show slave status并不能完全显示错误的全部信息,需要查看错误日志才能查看到完整的错误信息。比如:

  1. Last_Errno: 1007 
  2. Last_Error: Coordinator stopped because there were error(s) in the worker(s). The most recent failure being: Worker 0 failed executing transaction '0c1b77a7-c113-11e6-9bd6-d4ae52a34783:4' at master log binlog001.000002, end_log_pos 605. See error log and/or performance_schema.replication_applier_status_by_worker table for more details about this failure or others, if any. 
  3. Skip_Counter: 0 

上述错误信息并不是一个完整的错误信息描述,不过可以在error log中看到更完整的信息描述以及发生错误的时间。

  1. 2017-04-18T03:19:00.037806Z 23 [ERROR] Slave SQL for channel '': Worker 0 failed executing transaction '0c1b77a7-c113-11e6-9bd6-d4ae52a34783:4' at master log binlog001.000002, end_log_pos 605; Error 'Can't create database 'mydb3'; database exists' on query. Default database: 'mydb3'. Query: 'create database mydb3', Error_code: 1007 

1.3 查看二进制日志文件

这里的二进制日志文件包括主库的binlog和从库的relay log、binlog。

  • 主库的binlog是指主库执行过事务记录的binlog日志。
  • 从库的relay log是指从库接收到主库的binlog日志。
  • 从库的binlog是指从库SQL线程复现relay log后记录的日志(log-slave-updates开启),以及从库执行过的事务记录的binlog日志。

二进制日志文件中记录的日志是以event为单位进行,比如一个DML语句通常由4-5个event组成,一个DDL语句通常由2个event组成。

二进制日志文件可以通过命令“show binlog events”或者工具MySQLbinlog来将binlog日志转换为可识别的格式。

show binlog events格式如下:

上图显示的是ROW格式binlog中记录的内容,其中包含了一个DML语句和一条DDL语句。DML语句包含了GTID、QUERY、TABLEMAP、WRITEROW、XID五个event,DDL语句包含了GTID、QUERY两个event。

MySQLbinlog工具同样可以解析binlog,提供与show binlog event类似的event信息,以其中一个event为例来说明:

  1. #170417 23:18:37 server id 30001  end_log_pos 412 CRC32 0x818b4058      Write_rows: table id 110 flags: STMT_END_F 
  2.  
  3. BINLOG ' 
  4. zdz0WBMxdQAALQAAAHQBAAAAAG4AAAAAAAEABG15ZGIAAkkxAAEDAAF0sqv/ 
  5. zdz0WB4xdQAAKAAAAJwBAAAAAG4AAAAAAAEAAgAB//4KGgAAWECLgQ== 
  6. '/*!*/; 
  7. ### INSERT INTO `mydb`.`I1` 
  8. ### SET 
  9. ###   @1=6666 
  10. # at 412 

(1) Event的时间

  • 为主库执行事务的时间,不管从库的relay log和binlog,时间均为主库执行事务的时间。

(2) Event的server_id

  • 记录是执行该事务的数据库的server_id,可以用来区分这条事务是主库还是从库执行的。

(3) Event的end log pos

  • 从库relay log中end log pos为对应主库中binlog的该event的真实文件位置。
  • 主库和从库的binlog中,的end log pos为该binlog的文件真实位置。

(4) EVENT的at xxx

  • at xxx代表该event在文件中的真实位置。

对于以上二进制日志文件的内容,我们需要关注的信息包括:

  • Previous_gtids events记录了当前binlog之前执行过的所有的gtid信息,用来定位具体的gtid。
  • GTID event中对应的GTID,与事务是一一对应的,表明该事务是由主库执行还是由从库执行的。
  • 当错误发生时,事务执行的时间,事务的执行和具体语句。
  • 主库执行数据库操作后,将相关日志记录到主库的binlog中。备库的IO线程接收到主库传输的binlog日志后,将这些日志记录到relay log中,如果备库开启了logslaveupdates选项,那么SQL线程在重放relay log过程中,会记录相关binlog日志。这三个二进制文件日志,执行内容上应该是相同的。

1.4 查看其他变量

查看其他复制相关的系统变量或者状态,如:

  • 执行“show variables like‘gtid_mode’”查看gtid是否开启;
  • 执行“show status like ‘Rplsemisyncmasterstatus’”查看半同步复制的状态。

这里不再一一列举。

2. 排查错误

在收集到以上复制信息后,主要通过如下手段排查复制错误:

2.1 查看show slave status

查看是哪个线程(IO线程或者SQL线程)发生错误,查看错误原因。

  • 如果是IO线程发生错误,记录发生错误时接收到的binlog文件名和位置(如果开启了GTID则记录GTID);
  • 如果是SQL线程发生错误,记录发生错误时执行到的relay log文件名和位置(如果开启了GTID则记录GTID)。

2.2 查看错误日志

进一步确认发生错误的原因,部分原因只会记录在错误日志中,不会在show slave status中展示。比如,空间不足导致IO线程出错、网络中断导致IO线程异常等。

查看是不是由于其他用户正常关闭复制或者kill复制相关的线程导致复制不可用。

查看发生错误时,是否为刚刚启动复制、发生错误的语句,是否为***条复制执行的语句。如果为***条语句,则需要考虑是否由于搭建复制错误的原因导致复制异常,是否由于意外宕机等其他因素导致复制相关二进制日志文件不正确。

对比主库和备库的错误日志,查看是否均发生了同样的复制错误,是否主库做了特殊的错误处理。

2.3 对比二进制日志文件

对比备库正在接收的binlog与主库正在执行的binlog是否存在冲突(备库接收的binlog文件和位置要大于主库执行的)。

如果开启了GTID,查看备库是否本身执行了数据库操而产生了GTID,还要查看备库执行过的GTID是否要多于主库,备库是否执行过其他主机的GTID。

根据发生错误时的binlog文件和位置(或者GTID),解析主库和备库的二进制文件,对比相同的文件和位置(或者相同的GTID)时日志中记录的操作是否相同。

查看备库的二进制文件,备库是否执行过与主库冲突的操作。

二、总结

对于处于正常状态的复制,应是以下状态:

  • 查看复制状态应该是正常状态,如show slave status显示IO线程和SQL线程的运行状态均为YES,如半同步复制中show status like “rpl%”显示的半同步复制状态为ON。
  • 主库和备库均没有复制相关的错误信息报出。
  • 主库和备库的二进制日志文件中记录的数据库操作内容应一致,主库和备库中的数据内容应保持一致。 通过对比分析上述信息,查看异常的状态或者日志,可以为我们排查复制相关的错误提供更多的帮助。

三、版本和配置

总体来说,版本和配置不同只是会造成各种信息的显示格式不同,并不会对上述方法造成过多影响。

1. 版本

上述信息收集和分析的举例均是在MySQL-5.7版本上进行的,不同大版本在信息的内容或者信息的存放方式上可能存在一定差异。

MySQL-5.6版本与MySQL-5.7版本在复制相关信息上存在以下差异:

  • 日志:在MySQL-5.6在停止复制时,error log会有错误的信息记录:
    1. 2017-04-18 17:32:46 682 [Note] Error reading relay log event: slave SQL thread was killed 
    2. 2017-04-18 17:32:46 682 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013
    3. 2017-04-18 17:32:46 682 [Note] Slave I/O thread killed while reading event 
    4. 2017-04-18 17:32:46 682 [Note] Slave I/O thread exiting, read up to log 'b5620.000004', position 151 
  • GTID:MySQL-5.6的gtid_executed以global system variables方式展现,MySQL-5.7是以MySQL.gtid_executed表的方式展现。
  • BINLOG:MySQL-5.6版本在使用自增ID时,会使用如下event来记录自增ID
    1. #170419 11:27:12 server id 30061  end_log_pos 494 CRC32 0x7a9f75c6      Intvar 
    2. SET INSERT_ID=1/*!*/; 

2. 配置

主要体现差异的配置包括gtidmode和binlogformat。

(1) gtid_mode

当gtid开启时,gtid作为判断事务由谁执行,是否执行过、事务接收和执行进度的标准。同时,可以通过show slave status直观看出gtid的接收、执行情况。

当gtid关闭时,file和pos作为接收和执行的判断标准,serverid作为事务由谁执行的标准。但是事务对应的所有的serverid并没有完全的展现出来,所以对于我们排查问题,造成一定的困难。

(2) binlog_format

binlog_format影响的是记录到binlog中日志内容的格式,以同一条INSERT语句为例,statement格式记录到binlog中的格式如下(只显示差异部分):

  1. #170418 17:47:06 server id 30001  end_log_pos 730 CRC32 0xdaf9a789      Query   thread_id=154   exec_time=0     error_code=0 
  2. SET TIMESTAMP=1492508826/*!*/; 
  3. insert into mydb.m1 values (13) 
  4. /*!*/; 

row格式记录到binlog中的格式如下:

  1. #170418 17:46:25 server id 30001  end_log_pos 376 CRC32 0xcfdad7cd      Table_map: `mydb`.`m1` mapped to number 114 
  2. # at 376 
  3. #170418 17:46:25 server id 30001  end_log_pos 416 CRC32 0xed08eabe      Write_rows: table id 114 flags: STMT_END_F 
  4.  
  5. BINLOG ' 
  6. ceD1WBMxdQAALQAAAHgBAAAAAHIAAAAAAAEABG15ZGIAAm0xAAEDAAHN19rP 
  7. ceD1WB4xdQAAKAAAAKABAAAAAHIAAAAAAAEAAgAB//4NAAAAvuoI7Q== 
  8. '/*!*/; 
  9. ### INSERT INTO `mydb`.`m1` 
  10. ### SET 
  11. ###   @1=13 
  12. # at 416 

【本文是51CTO专栏机构作者“大U的技术课堂”的原创文章,转载请通过微信公众号(ucloud2012)联系作者】

 戳这里,看该作者更多好文

责任编辑:赵宁宁 来源: 51CTO专栏
相关推荐

2017-06-10 20:47:06

MySQL复制线程

2021-12-26 00:10:39

二分法排查版本

2011-03-28 10:03:46

Btrace

2022-01-26 19:42:05

MySQL乱码排查

2023-03-02 08:53:57

排查问题效率经验

2022-02-08 16:17:41

MySQL主从复制数据库

2018-12-10 10:30:40

阿里Linux命令

2018-11-06 12:12:00

MySQL内存排查

2021-06-28 08:00:00

Python开发编程语言

2017-10-18 15:07:21

MySQL执行死锁

2017-08-18 22:40:33

线上线程备份

2010-05-06 15:29:53

Oracle数据复制

2010-05-14 18:26:39

MySQL 复制设置

2019-01-29 08:41:16

MySQL性能突发事件

2013-03-27 10:32:22

2016-01-04 15:17:50

Linux命令行硬件

2010-03-08 11:21:40

Linux用户操作记录

2022-07-03 07:34:32

Citrix虚拟桌面

2023-04-25 18:54:13

数据数据丢失

2018-11-29 09:00:58

故障定位运维
点赞
收藏

51CTO技术栈公众号