目录
一、简介二、环境准备三、实验过程 3.1 主库创建表 3.2 主库做更新操作 3.3 分析主库的binlog日志 3.4 分析从库的中继日志四、结论一、简介
导致MySQL主从复制延迟的原因有很多，其中一个原因就是大表缺失主键或唯一索引。
今天我们就通过实验的方式来验证这种情况。
二、环境准备主库：IP为192.168.68.168，端口3306，版本为8.0.20
从库：IP为192.168.68.168，端口3306，版本为8.0.20
1[root@docker35 ~]# docker ps 2CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 3ebe3b62a2358 mysql:8.0.20 "docker-entrypoint.s…" 8 days ago Up 8 days 33060/tcp, 0.0.0.0:3319->3306/tcp mysql8020S1 476140b04e2fd mysql:8.0.20 "docker-entrypoint.s…" 8 days ago Up 8 days 33060/tcp, 0.0.0.0:3318->3306/tcp mysql8020M1 5 6 7-- 主库 8MySQL [lhrdb1]> show slave hosts; 9+-----------+------+------+-----------+--------------------------------------+ 10| Server_id | Host | Port | Master_id | Slave_UUID | 11+-----------+------+------+-----------+--------------------------------------+ 12| 80203319 | | 3306 | 80203318 | e12dfcd2-1e40-11eb-b2f0-0242c0a844a9 | 13+-----------+------+------+-----------+--------------------------------------+ 14 15MySQL [lhrdb1]> show variables like '%binlog_format%'; 16+---------------+-------+ 17| Variable_name | Value | 18+---------------+-------+ 19| binlog_format | ROW | 20+---------------+-------+ 211 row in set (0.00 sec) 22 23 24-- 从库 25MySQL [(none)]> show slave status\G; 26*************************** 1. row *************************** 27 Slave_IO_State: Waiting for master to send event 28 Master_Host: 192.168.68.168 29 Master_User: repl 30 Master_Port: 3306 31 Connect_Retry: 60 32 Master_Log_File: mysql8020M1-bin.000007 33 Read_Master_Log_Pos: 19665393 34 Relay_Log_File: mysql8020S1-relay-bin.000008 35 Relay_Log_Pos: 19665620 36 Relay_Master_Log_File: mysql8020M1-bin.000007 37 Slave_IO_Running: Yes 38 Slave_SQL_Running: Yes 39 Replicate_Do_DB: 40 Replicate_Ignore_DB: information_schema,performance_schema,mysql,sys 41 Replicate_Do_Table: 42 Replicate_Ignore_Table: 43 Replicate_Wild_Do_Table: 44 Replicate_Wild_Ignore_Table: 45 Last_Errno: 0 46 Last_Error: 47 Skip_Counter: 0 48 Exec_Master_Log_Pos: 19665393 49 Relay_Log_Space: 19665928 50 Until_Condition: None 51 Until_Log_File: 52 Until_Log_Pos: 0 53 Master_SSL_Allowed: No 54 Master_SSL_CA_File: 55 Master_SSL_CA_Path: 56 Master_SSL_Cert: 57 Master_SSL_Cipher: 58 Master_SSL_Key: 59 Seconds_Behind_Master: 0 60Master_SSL_Verify_Server_Cert: No 61 Last_IO_Errno: 0 62 Last_IO_Error: 63 Last_SQL_Errno: 0 64 Last_SQL_Error: 65 Replicate_Ignore_Server_Ids: 66 Master_Server_Id: 80203318 67 Master_UUID: dcccf122-1e40-11eb-8ca0-0242c0a844a8 68 Master_Info_File: mysql.slave_master_info 69 SQL_Delay: 0 70 SQL_Remaining_Delay: NULL 71 Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates 72 Master_Retry_Count: 86400 73 Master_Bind: 74 Last_IO_Error_Timestamp: 75 Last_SQL_Error_Timestamp: 76 Master_SSL_Crl: 77 Master_SSL_Crlpath: 78 Retrieved_Gtid_Set: dcccf122-1e40-11eb-8ca0-0242c0a844a8:20-160037 79 Executed_Gtid_Set: dcccf122-1e40-11eb-8ca0-0242c0a844a8:1-160037 80 Auto_Position: 1 81 Replicate_Rewrite_DB: 82 Channel_Name: 83 Master_TLS_Version: 84 Master_public_key_path: 85 Get_master_public_key: 0 86 Network_Namespace: 871 row in set (0.00 sec)三、实验过程
3.1 主库创建表
主库先创建一张8万行的大表：
1MySQL [lhrdb1]> DELIMITER $$
2MySQL [lhrdb1]> drop procedure if exists `t_pro`$$
3Query OK, 0 rows affected (0.01 sec)
4
5MySQL [lhrdb1]> create procedure `t_pro`(num int)
6 -> begin
7 -> declare i int unsigned default 1;
8 -> set i=1;
9 -> while i <= num do
10 -> insert into `t` (`id`,`name`)
11 -> values(i,concat('主键测试',i));
12 -> set i=i + 1;
13 -> end while;
14 -> end$$
15Query OK, 0 rows affected (0.01 sec)
16
17MySQL [lhrdb1]> DELIMITER ;
18MySQL [lhrdb1]> call `t_pro`(80000);
19
20--- .... 这里插入8万行数据，比较慢
从库查询延迟：
1D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 2mysql: [Warning] Using a password on the command line interface can be insecure. 3 Seconds_Behind_Master: 11 4 5D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" 6mysql: [Warning] Using a password on the command line interface can be insecure. 7*************************** 1. row *************************** 8 Slave_IO_State: Waiting for master to send event 9 Master_Host: 192.168.68.168 10 Master_User: repl 11 Master_Port: 3306 12 Connect_Retry: 60 13 Master_Log_File: mysql8020M1-bin.000007 14 Read_Master_Log_Pos: 26029948 15 Relay_Log_File: mysql8020S1-relay-bin.000008 16 Relay_Log_Pos: 25067097 17 Relay_Master_Log_File: mysql8020M1-bin.000007 18 Slave_IO_Running: Yes 19 Slave_SQL_Running: Yes 20 Replicate_Do_DB: 21 Replicate_Ignore_DB: information_schema,performance_schema,mysql,sys 22 Replicate_Do_Table: 23 Replicate_Ignore_Table: 24 Replicate_Wild_Do_Table: 25 Replicate_Wild_Ignore_Table: 26 Last_Errno: 0 27 Last_Error: 28 Skip_Counter: 0 29 Exec_Master_Log_Pos: 25066870 30 Relay_Log_Space: 26030483 31 Until_Condition: None 32 Until_Log_File: 33 Until_Log_Pos: 0 34 Master_SSL_Allowed: No 35 Master_SSL_CA_File: 36 Master_SSL_CA_Path: 37 Master_SSL_Cert: 38 Master_SSL_Cipher: 39 Master_SSL_Key: 40 Seconds_Behind_Master: 12 41Master_SSL_Verify_Server_Cert: No 42 Last_IO_Errno: 0 43 Last_IO_Error: 44 Last_SQL_Errno: 0 45 Last_SQL_Error: 46 Replicate_Ignore_Server_Ids: 47 Master_Server_Id: 80203318 48 Master_UUID: dcccf122-1e40-11eb-8ca0-0242c0a844a8 49 Master_Info_File: mysql.slave_master_info 50 SQL_Delay: 0 51 SQL_Remaining_Delay: NULL 52 Slave_SQL_Running_State: waiting for handler commit 53 Master_Retry_Count: 86400 54 Master_Bind: 55 Last_IO_Error_Timestamp: 56 Last_SQL_Error_Timestamp: 57 Master_SSL_Crl: 58 Master_SSL_Crlpath: 59 Retrieved_Gtid_Set: dcccf122-1e40-11eb-8ca0-0242c0a844a8:20-181149 60 Executed_Gtid_Set: dcccf122-1e40-11eb-8ca0-0242c0a844a8:1-177960 61 Auto_Position: 1 62 Replicate_Rewrite_DB: 63 Channel_Name: 64 Master_TLS_Version: 65 Master_public_key_path: 66 Get_master_public_key: 0 67 Network_Namespace: 68 69D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 70mysql: [Warning] Using a password on the command line interface can be insecure. 71 Seconds_Behind_Master: 19 72 73MySQL [(none)]> select count(*) from lhrdb1.t; 74+----------+ 75| count(*) | 76+----------+ 77| 41613 | 78+----------+ 791 row in set (0.01 sec) 80 81MySQL [(none)]> select count(*) from lhrdb1.t; 82+----------+ 83| count(*) | 84+----------+ 85| 41941 | 86+----------+ 871 row in set (0.01 sec) 88
发现，从库延迟越来越高，主要原因是主库正在进行大批量的数据插入操作。
大约5分钟后，主库执行完毕，
1MySQL [lhrdb1]> call `t_pro`(80000); 2Query OK, 1 row affected (5 min 3.37 sec) 3 4MySQL [lhrdb1]> select count(*) from lhrdb1.t; 5+----------+ 6| count(*) | 7+----------+ 8| 80000 | 9+----------+ 101 row in set (0.01 sec)
从库查询，数据已同步完成：
1D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 2mysql: [Warning] Using a password on the command line interface can be insecure. 3 Seconds_Behind_Master: 30 4 5D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 6mysql: [Warning] Using a password on the command line interface can be insecure. 7 Seconds_Behind_Master: 0 8 9MySQL [lhrdb1]> select count(*) from lhrdb1.t; 10+----------+ 11| count(*) | 12+----------+ 13| 80000 | 14+----------+ 151 row in set (0.01 sec) 16
3.2 主库做更新操作
1MySQL [lhrdb1]> flush logs;
2Query OK, 0 rows affected (0.02 sec)
3
4MySQL [lhrdb1]>
5MySQL [lhrdb1]> show master logs;
6+------------------------+-----------+-----------+
7| Log_name | File_size | Encrypted |
8+------------------------+-----------+-----------+
9| mysql8020M1-bin.000001 | 179 | No |
10| mysql8020M1-bin.000002 | 179 | No |
11| mysql8020M1-bin.000003 | 179 | No |
12| mysql8020M1-bin.000004 | 53350509 | No |
13| mysql8020M1-bin.000005 | 1155468 | No |
14| mysql8020M1-bin.000006 | 1345290 | No |
15| mysql8020M1-bin.000007 | 45018719 | No |
16| mysql8020M1-bin.000008 | 196 | No |
17+------------------------+-----------+-----------+
188 rows in set (0.00 sec)
19
20MySQL [lhrdb1]> update t set name=concat('主键测试，结果验证',t.id) where id <=60000;
21Query OK, 40000 rows affected (1.88 sec)
22Rows matched: 60000 Changed: 40000 Warnings: 0
可以看出，主库基本在2s就更新完成，变化的行数为4万行。
从库查询延迟，
1D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 2mysql: [Warning] Using a password on the command line interface can be insecure. 3 Seconds_Behind_Master: 0 4 5D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 6mysql: [Warning] Using a password on the command line interface can be insecure. 7 Seconds_Behind_Master: 0 8 9D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 10mysql: [Warning] Using a password on the command line interface can be insecure. 11 Seconds_Behind_Master: 4 12 13D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 14mysql: [Warning] Using a password on the command line interface can be insecure. 15 Seconds_Behind_Master: 5 16 17D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 18mysql: [Warning] Using a password on the command line interface can be insecure. 19 Seconds_Behind_Master: 7 20 21D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 22mysql: [Warning] Using a password on the command line interface can be insecure. 23 Seconds_Behind_Master: 8 24 25D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 26mysql: [Warning] Using a password on the command line interface can be insecure. 27 Seconds_Behind_Master: 10 28 29D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 30mysql: [Warning] Using a password on the command line interface can be insecure. 31 Seconds_Behind_Master: 11 32 33D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 34mysql: [Warning] Using a password on the command line interface can be insecure. 35 Seconds_Behind_Master: 13 36 37D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 38mysql: [Warning] Using a password on the command line interface can be insecure. 39 Seconds_Behind_Master: 14 40 41D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 42mysql: [Warning] Using a password on the command line interface can be insecure. 43 Seconds_Behind_Master: 16 44 45D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 46mysql: [Warning] Using a password on the command line interface can be insecure. 47 Seconds_Behind_Master: 17 48 49D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 50mysql: [Warning] Using a password on the command line interface can be insecure. 51 Seconds_Behind_Master: 18 52 53D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 54mysql: [Warning] Using a password on the command line interface can be insecure. 55 Seconds_Behind_Master: 19 56 57D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 58mysql: [Warning] Using a password on the command line interface can be insecure. 59 Seconds_Behind_Master: 20 60 61D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 62mysql: [Warning] Using a password on the command line interface can be insecure. 63 Seconds_Behind_Master: 21 64 65D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 66mysql: [Warning] Using a password on the command line interface can be insecure. 67 Seconds_Behind_Master: 0 68 69D:\Program Files\MySQL\mysql-8.0.15-winx64\bin>mysql -uroot -plhr -h192.168.1.35 -P3319 -e "show slave status \G" | grep Seconds_Behind_Master 70mysql: [Warning] Using a password on the command line interface can be insecure. 71 Seconds_Behind_Master: 0 72
可以发现，最长延迟21秒左右。
3.3 分析主库的binlog日志
1root@mysql8020M1:/var/lib/mysql# mysqlbinlog mysql8020M1-bin.000008 --base64-output=decode-row -vv | grep UPDATE | wc -l 240000 3root@mysql8020M1:/var/lib/mysql# mysqlbinlog mysql8020M1-bin.000008 --base64-output=decode-row -vv | more 4/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; 5/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; 6DELIMITER /*!*/; 7# at 4 8#201112 11:25:24 server id 80203318 end_log_pos 125 CRC32 0x11d2d479 Start: binlog v 4, server v 8.0.20 created 201112 11:25:24 9# Warning: this binlog is either in use or was not closed properly. 10# at 125 11#201112 11:25:24 server id 80203318 end_log_pos 196 CRC32 0x443aeae4 Previous-GTIDs 12# dcccf122-1e40-11eb-8ca0-0242c0a844a8:1-240042 13# at 196 14#201112 11:25:33 server id 80203318 end_log_pos 276 CRC32 0xa8eb8112 GTID last_committed=0 sequence_number=1 rbr_only=yes original_committed_timestamp=1605151535412817 immediate_commit_timestamp=1605151535412817 transaction_length=2451018 15/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; 16# original_commit_timestamp=1605151535412817 (2020-11-12 11:25:35.412817 CST) 17# immediate_commit_timestamp=1605151535412817 (2020-11-12 11:25:35.412817 CST) 18/*!80001 SET @@session.original_commit_timestamp=1605151535412817*//*!*/; 19/*!80014 SET @@session.original_server_version=80020*//*!*/; 20/*!80014 SET @@session.immediate_server_version=80020*//*!*/; 21SET @@SESSION.GTID_NEXT= 'dcccf122-1e40-11eb-8ca0-0242c0a844a8:240043'/*!*/; 22# at 276 23#201112 11:25:33 server id 80203318 end_log_pos 362 CRC32 0x0b667ff4 Query thread_id=26 exec_time=0 error_code=0 24SET TIMESTAMP=1605151533/*!*/; 25SET @@session.pseudo_thread_id=26/*!*/; 26SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; 27SET @@session.sql_mode=1168113696/*!*/; 28SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; 29 30-- 省略部分 .................. 31#201112 11:25:33 server id 80203318 end_log_pos 2446999 CRC32 0x6e0e09e8 Update_rows: table id 105 32# at 2446999 33#201112 11:25:33 server id 80203318 end_log_pos 2451183 CRC32 0x30bfc23e Update_rows: table id 105 flags: STMT_END_F 34### UPDATE `lhrdb1`.`t` 35### WHERE 36### @1=20001 /* INT meta=0 nullable=0 is_null=0 */ 37### @2='主键测试20001' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 38### SET 39### @1=20001 /* INT meta=0 nullable=0 is_null=0 */ 40### @2='主键测试，结果验证20001' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 41### UPDATE `lhrdb1`.`t` 42### WHERE 43### @1=20002 /* INT meta=0 nullable=0 is_null=0 */ 44### @2='主键测试20002' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 45### SET 46### @1=20002 /* INT meta=0 nullable=0 is_null=0 */ 47### @2='主键测试，结果验证20002' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 48 49-- 省略部分 .................. 50 51root@mysql8020M1:/var/lib/mysql# mysqlbinlog mysql8020M1-bin.000008 --base64-output=decode-row -vv | tail -n 20 52### @1=59999 /* INT meta=0 nullable=0 is_null=0 */ 53### @2='主键测试59999' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 54### SET 55### @1=59999 /* INT meta=0 nullable=0 is_null=0 */ 56### @2='主键测试，结果验证59999' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 57### UPDATE `lhrdb1`.`t` 58### WHERE 59### @1=60000 /* INT meta=0 nullable=0 is_null=0 */ 60### @2='主键测试60000' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 61### SET 62### @1=60000 /* INT meta=0 nullable=0 is_null=0 */ 63### @2='主键测试，结果验证60000' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */ 64# at 2451183 65#201112 11:25:33 server id 80203318 end_log_pos 2451214 CRC32 0x3d5db696 Xid = 720239 66COMMIT/*!*/; 67SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; 68DELIMITER ; 69# End of log file 70/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; 71/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
可以看出，在ROW模式下，在主库上执行了一条UPDATE语句，更新了4万行记录，但是在binlog中，记录了4万行的UPDATE语句。
3.4 分析从库的中继日志
1root@mysql8020S1:/var/lib/mysql# mysqlbinlog mysql8020S1-relay-bin.000010 --base64-output=decode-row -vv | grep UPDATE | wc -l 240000
可以看出，在从库上也是4万行的UPDATE语句，也是一条一条的进行更新。由于没有主键和索引，所以，就会导致在从库进行4万次的全表扫描，这样也就拖慢了从库APPLY的效率。
四、结论在MySQL的主从复制架构中，若存在大表，那么一定要有主键或唯一索引，否则将导致很大的主从延迟。
本文结束。