【DB宝34】测试MySQL主从复制中主库表缺失主键会导致主从延迟的情况

一、简介
二、环境准备
三、实验过程  
3.1 主库创建表  
3.2 主库做更新操作  
3.3 分析主库的binlog日志 
3.4 分析从库的中继日志
四、结论

 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)

 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

 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

 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

 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

 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*/;

1root@mysql8020S1:/var/lib/mysql# mysqlbinlog mysql8020S1-relay-bin.000010 --base64-output=decode-row -vv | grep UPDATE | wc -l
240000