MySQL增加索引导致主从同步延时更大的重现与分析
生产上有一套MySQL库，一主二从，使用MHA做高可用。在主库大进行大量删除操作之后，从库应用缓慢，主从延时很大。经查，进行大量删除的表既无主键、也无其他索引。在删除语句的筛选字段上增加索引之后，发现从库应用缓慢的现象并没有消失，反而更加严重。最后在表上增加主键，问题才得以解决。本文将该生产问题复现到测试环境，通过无索引批量删除、有索引批量删除以及有主键批量删除三次测试，分析出表中有无主键是影响从库同步性能的关键因素。
问题
业务对MySQL数据库中的一张表进行大量删除操作，造成从库同步的延时过大。之后业务对表中删除操作相关字段进行增加索引的操作，但是并没有效果。下面在测试环境复现场景并且分析。
配置信息
1.主机信息
IP 主机名 CPU 内存
xxx.xxx.32.127 k8s-node1 8C 16G
xxx.xxx.32.141 k8s-node2 8C 16G
xxx.xxx.32.144 k8s-node3 8C 16G
# CPU信息
vendor_id : GenuineIntel
cpu family : 6
model : 94
model name : Intel Core Processor (Skylake, IBRS)
stepping : 3
microcode : 0x1
cpu MHz : 2194.842
cache size : 16384 KB
2.MySQL配置信息
port = 3307
transaction_isolation = READ-COMMITTED
innodb_buffer_pool_size=100M
innodb_log_file_size = 50M
innodb_log_files_in_group = 7
innodb_undo_tablespaces = 3
binlog_format = ROW
sync_binlog = 1
long_query_log = 0.1
xxx.xxx.32.127 为主库
xxx.xxx.32.141 为从库1
xxx.xxx.32.144 为从库2
主库配置
+-------------------------------------------+------------+
| Variable_name | Value |
+-------------------------------------------+------------+
| rpl_semi_sync_master_enabled | ON |
| rpl_semi_sync_master_wait_for_slave_count | 1 |
| rpl_semi_sync_master_wait_no_slave | ON |
| rpl_semi_sync_master_wait_point | AFTER_SYNC |
| rpl_semi_sync_slave_enabled | ON |
+-------------------------------------------+------------+
从库配置
+-------------------------------------------+------------+
| Variable_name | Value |
+-------------------------------------------+------------+
| rpl_semi_sync_master_enabled | OFF |
+-------------------------------------------+------------+
测试准备
1.创建数据库
mysql> create database bossdb;
2.创建用户
mysql> grant all privileges on bossdb.* to 'boss'@'localhost' identified by 'bosscloud';
3.创建表
mysql> use bossdb;
mysql> create table `t1` (
`tcol01` varchar(10) NOT NULL,
`tcol02` varchar(10) NOT NULL,
`tcol03` datetime NOT NULL,
`tcol04` varchar(20) DEFAULT NULL,
`tcol05` char(1) DEFAULT NULL,
`tcol06` varchar(20) DEFAULT NULL,
`tcol` varchar(20) NOT NULL,
`tcol07` int(11) DEFAULT '0',
`tcol08` varchar(20) DEFAULT NULL,
`tcol09` varchar(100) DEFAULT NULL,
`tcol10` varchar(255) DEFAULT NULL,
`tcol11` varchar(255) DEFAULT NULL,
`tcol12` int(10) DEFAULT NULL,
`tcol13` int(10) DEFAULT '0',
`tcol21` date DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 ROW_FORMAT=DYNAMIC;
重点：无主键、无索引
[mysqlcat@k8s-node1 ~]$ ./mysql_random_data_load bossdb t1 200000 -hxxx.xxx.32.127 -P3307 -uboss -pbosscloud
INFO[2020-04-20T16:02:56+08:00] Starting
1m7s [====================================================================] 100%
INFO[2020-04-20T16:04:05+08:00] 100000 rows inserted
十万行数据用了1m7s，因为数据库的buffer_pool_size和onlinelog都配置的比较小，这个效果还是可以的。
这句命令执行了两遍，总共插入了20万条数据。
考虑到t1表中的tcol是记录的日期，格式如下‘20200421’，这也是后文的关键字段，mysql_random_data_load随机生成的varchar并不符合要求。我们使用update语句将datetime字段的年月日赋值给该字段。避免不必要的主从同步，在update的时候关闭了sql_log_bin参数。
xxx.xxx.32.127
mysql> set sql_log_bin=0;
mysql> update bossdb.t1 set tcol=date_format(tcol03,'%Y%m%d');
mysql> set sql_log_bin=1;
xxx.xxx.32.141/144
mysql> set sql_log_bin=0;
mysql> set global super_read_only=0;
mysql> update bossdb.t1 set tcol=date_format(tcol03,'%Y%m%d');
mysql> set global super_read_only=1;
mysql> set sql_log_bin=1;
xxx.xxx.32.127
mysql> select count(*) from bossdb.t1 where tcol<'20200401';
+----------+
| count(*) |
+----------+
| 189158 |
+----------+
1 row in set (1.18 sec)
mysql> explain delete from bossdb.t1 where tcol<'20200401';
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| 1 | DELETE | t1 | NULL | ALL | NULL | NULL | NULL | NULL | 197242 | 100.00 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
下面这句话是接下来的重点，此处执行计划为全表扫描。
delete from bossdb.t1 where tcol<'20200401';
5.撰写脚本
在/tmp/在，写两个脚本，如下。master status以及slave status的数据
5.1 gather_master_status.sh
放在xxx.xxx.32.127，用来记录主库的master status数据
!/bin/bash
while [ true ]; do
/bin/sleep 1
/bin/date >>/tmp/gather_master_status.txt
/mysql/app/bin/mysql -s -e "show master status\G;" >>/tmp/gather_master_status.txt
echo ''>>/tmp/gather_master_status.txt
echo ''>>/tmp/gather_master_status.txt
done
5.2 gather_slave_status.sh
放在xxx.xxx.32.141/144上，用来记录从库的slave status数据
!/bin/bash
while [ true ]; do
/bin/sleep 1
/bin/date >>/tmp/gather_slave_status.txt
/mysql/app/bin/mysql -s -e "show slave status\G;" >>/tmp/gather_slave_status.txt
echo ''>>/tmp/gather_slave_status.txt
echo ''>>/tmp/gather_slave_status.txt
done
5.3 显示Second Behind Master脚本
在xxx.xxx.32.141/144的命令行执行，显示何时降为0.
[mysqlcat@k8s-node1 ~]$ while [ true ]; do sleep 2;date;a=`mysql -e "show slave status\G;"|grep "Seconds_Behind_Master"`;echo $a;b=`echo $a|awk -F ': ' '{print $2}'`;if [ $b == 0 ];then echo 'Finished';break;else echo 'Not yet';fi;done;
6.备份数据
[mysqlcat@k8s-node1 ~]$ mysqldump --set-gtid-purged=OFF --databases bossdb |gzip>/mysqlcat/backup/bossdb.sql.gz
测试1 无索引下批量删除
1.执行脚本
xxx.xxx.32.127/141/144
[mysqlcat@k8s-node1 ~]$ nohup sh /tmp/gather*status.sh 2>&1 >/dev/null &
xxx.xxx.32.141/144
[mysqlcat@k8s-node1 ~]$ while [ true ]; do sleep 2;date;a=`mysql -e "show slave status\G;"|grep "Seconds_Behind_Master"`;echo $a;b=`echo $a|awk -F ': ' '{print $2}'`;if [ $b == 0 ];then echo 'Finished';break;else echo 'Not yet';fi;done;
2.删除
mysql> delete from bossdb.t1 where tcol<'20200401';
3.查看慢日志
# Time: 2020-04-20T17:07:32.885274+08:00
# User@Host: root[root] @ localhost [] Id: 5586
# Query_time: 4.996057 Lock_time: 0.000140 Rows_sent: 0 Rows_examined: 200000
SET timestamp=1587373652;
delete from bossdb.t1 where tcol<'20200401';
4.等待Seconds_Behind_Master归零
xxx.xxx.32.141
Mon Apr 20 17:07:32 CST 2020
Second Behind Master 5
Not yet
Mon Apr 20 17:14:27 CST 2020
Second Behind Master 0
Finished
耗时415s
xxx.xxx.32.144
Mon Apr 20 17:07:32 CST 2020
Second Behind Master 5
Not yet
Mon Apr 20 17:14:09 CST 2020
Second Behind Master 0
Finished
耗时397s
5.停止脚本的执行
xxx.xxx.32.127/141/144
[mysqlcat@k8s-node1 ~]$ ps -ef|grep gather_*_status|grep -v grep|awk -F ' ' '{print $2}'|xargs kill
6.使用mysqlbinlog分析binlog
[mysqlcat@k8s-node1 ~]$mysqlbinlog --start-datetime='2020-04-20 17:07:27' --stop-datetime='2020-04-20 17:07:31' -vv
binlog 部分如下
# at 353150914
#200420 17:07:27 server id 127 end_log_pos 353150981 CRC32 0x9eabf598 Rows_query
# delete from bossdb.t1 where tcol<'20200401'
# at 353150981
#200420 17:07:27 server id 127 end_log_pos 353151064 CRC32 0x747fcc33 Table_map: `bossdb`.`t1` mapped to number 118
# at 353151064
#200420 17:07:27 server id 127 end_log_pos 353159207 CRC32 0xc7c827e6 Delete_rows: table id 118
748833 ### DELETE FROM `bossdb`.`t1`
748834 ### WHERE
748835 ### @1='Ann' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
748836 ### @2='Gerald' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
748837 ### @3='2019-11-01 19:07:41' /* DATETIME(0) meta=0 nullable=0 is_null=0 */
748838 ### @4='Jesse Lewis' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
748839 ### @5='G' /* STRING(4) meta=65028 nullable=1 is_null=0 */
748840 ### @6='Timothy Little' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
748841 ### @7='20191101' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */
748842 ### @8=2038042080 /* INT meta=0 nullable=1 is_null=0 */
748843 ### @9='Marie Welch' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
748844 ### @10='fuga qui omnis molestiae veritatis ut optio recusandae.' /* VARSTRING(400) meta=400 nullable=1 is_null=0 */
748845 ### @11='expedita in quia reiciendis facilis qui.' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */
748846 ### @12='laboriosam et aut modi qui non.' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */
748847 ### @13=627801321 /* INT meta=0 nullable=1 is_null=0 */
748848 ### @14=51425520 /* INT meta=0 nullable=1 is_null=0 */
748849 ### @15='2020:04:20' /* DATE meta=0 nullable=1 is_null=0 */
3964502 ### DELETE FROM `bossdb`.`t1`
3964503 ### WHERE
3964504 ### @1='Pamela' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
3964505 ### @2='Harry' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
3964506 ### @3='2019-09-03 08:08:56' /* DATETIME(0) meta=0 nullable=0 is_null=0 */
3964507 ### @4='Jeremy Fisher' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
3964508 ### @5='C' /* STRING(4) meta=65028 nullable=1 is_null=0 */
3964509 ### @6='Mr. Dr. Matthew Fost' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
3964510 ### @7='20190903' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */
3964511 ### @8=666660140 /* INT meta=0 nullable=1 is_null=0 */
3964512 ### @9='Mrs. Ms. Miss Kelly ' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
3964513 ### @10='nostrum temporibus atque.' /* VARSTRING(400) meta=400 nullable=1 is_null=0 */
3964514 ### @11='voluptatem ut voluptas sint quo autem aliquid iure.' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */
3964515 ### @12='in commodi dolor doloremque rerum nobis.' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */
3964516 ### @13=156647923 /* INT meta=0 nullable=1 is_null=0 */
3964517 ### @14=764931703 /* INT meta=0 nullable=1 is_null=0 */
3964518 ### @15='2020:04:20' /* DATE meta=0 nullable=1 is_null=0 */
3964519 # at 395096777
可以看到，虽然主库只是执行了一句delete操作，但是因为我们设定的是基于行的binlog格式，所以binlog中，会记下匹配到的189158条delete操作，再将这些delete操作传输给从库，显然是非常惊人的。
7.时间线
17:07:28 开始执行 delete from bossdb.t1 where tcol<'20200401';
17:07:31 binlog写完
17:07:32 主库执行完成
17:07:32 从库开始有second behind master不为0
17:14:09 从库2的second_behind_master 0
17:14:27 从库1的second_behind_master 0
主库执行5秒钟，主从同步用了500s左右。
测试2 增加索引 批量删除
1.恢复数据
xxx.xxx.32.127
[mysqlcat@k8s-node1 ~]$ mysql</mysqlcat/backup/bossdb.sql
2.给tcol字段增加索引
xxx.xxx.32.127
mysql> alter table t1 add index idx_tcol(`tcol`);
mysql> show create table t1;
| t1 | CREATE TABLE `t1` (
`tcol01` varchar(10) NOT NULL,
`tcol02` varchar(10) NOT NULL,
`tcol03` datetime NOT NULL,
`tcol04` varchar(20) DEFAULT NULL,
`tcol05` char(1) DEFAULT NULL,
`tcol06` varchar(20) DEFAULT NULL,
`tcol` varchar(20) NOT NULL,
`tcol07` int(11) DEFAULT '0',
`tcol08` varchar(20) DEFAULT NULL,
`tcol09` varchar(100) DEFAULT NULL,
`tcol10` varchar(255) DEFAULT NULL,
`tcol11` varchar(255) DEFAULT NULL,
`tcol12` int(10) DEFAULT NULL,
`tcol13` int(10) DEFAULT '0',
`tcol21` date DEFAULT NULL,
KEY `idx_tcol` (`tcol`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 ROW_FORMAT=DYNAMIC |
(重复操作不再赘述，见测试1)
3.删除
mysql> explain delete from bossdb.t1 where tcol<'20200401';
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| 1 | DELETE | t1 | NULL | ALL | idx_tcol | NULL | NULL | NULL | 187534 | 100.00 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
mysql> delete from bossdb.t1 where tcol<'20200401';
Query OK, 189158 rows affected (6.74 sec)
4.时间线
11:24:10 开始执行 delete from bossdb.t1 where tcol<'20200401';
11:24:17 binlog写完
11:24:17 主库执行完成
11:24:17 从库开始有second behind master不为0
12:28:13 从库2的second_behind_master 0
12:37:23 从库1的second_behind_master 0
主库执行6.7秒钟，主从同步用了3600s左右。
期中分析
问题：为什么t1表加了索引，但是效果为什么比原来没有还要差很多呢？
不知道大家有没有关注到测试2中的delete执行计划，possible_keys中有idx_tcol，但是key中没有，也就是说delete操作根本就没有走索引，在进行了比较之后，MySQL仍然认为走全表扫描是cost更小的方式。
但是有了索引，也就是多了一次比较。而且索引也是需要空间的，增加索引也增加了数据库的大小。主库执行满了1s多，可以理解。但是从库的同步时间几乎被慢了10倍，这是为什么呢？
因为从库的执行时一行行执行的，类似这种
DELETE FROM `bossdb`.`t1`
WHERE
@1='Ann' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
@2='Gerald' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
@3='2019-11-01 19:07:41' /* DATETIME(0) meta=0 nullable=0 is_null=0 */
@4='Jesse Lewis' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
@5='G' /* STRING(4) meta=65028 nullable=1 is_null=0 */
@6='Timothy Little' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
@7='20191101' /* VARSTRING(80) meta=80 nullable=0 is_null=0 */
@8=2038042080 /* INT meta=0 nullable=1 is_null=0 */
@9='Marie Welch' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
@10='fuga qui omnis molestiae veritatis ut optio recusandae.' /* VARSTRING(400) llable=1 is_null=0 */
@11='expedita in quia reiciendis facilis qui.' /* VARSTRING(1020) meta=1020 is_null=0 */
@12='laboriosam et aut modi qui non.' /* VARSTRING(1020) meta=1020 nullable=1 /
@13=627801321 /* INT meta=0 nullable=1 is_null=0 */
@14=51425520 /* INT meta=0 nullable=1 is_null=0 */
@15='2020:04:20' /* DATE meta=0 nullable=1 is_null=0 */
我们改写了一下，并且看他的执行计划
mysql> explain DELETE FROM `bossdb`.`t1`
WHERE
tcol01='Ann' and
tcol02='Gerald' and
tcol03='2019-11-01 19:07:41' and
tcol04='Jesse Lewis' and
tcol05='G' and
tcol06='Timothy Little' and
tcol ='20191101' and
tcol07=2038042080 and
tcol08='Marie Welch' and
tcol09=='fuga qui omnis molestiae veritatis ut optio recusandae.' and
tcol10=='expedita in quia reiciendis facilis qui.' and
tcol11=='laboriosam et aut modi qui non.' and
tcol12==627801321 and
tcol13==51425520 and
tcol21=='2020:04:20';
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| 1 | DELETE | t1 | NULL | range | idx_tcol | idx_tcol | 82 | const | 1 | 100.00 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
MySQL其实选择走了索引，这很可能就是执行非常慢的原因。而且大量的删除操作，还会带来索引维护的开销增大，十分不可取。
最后，我们试试增加主键。
测试3 增加主键 批量删除
1.删除表
xxx.xxx.32.127
mysql> truncate bossdb.t1;
2.增加主键
mysql> alter table bossdb.t1 add (id int);
mysql> alter table bossdb.t1 add constraint pk primary key(id);
3.重新造数据
xxx.xxx.32.127
[mysqlcat@k8s-node1 ~]$ ./mysql_random_data_load bossdb t1 200000
INFO[2020-04-21T22:35:50+08:00] Starting
3m5s [====================================================================] 100%
INFO[2020-04-21T22:38:57+08:00] 200000 rows inserted
4.更新tcol字段
详细见测试1和2
5.删除
mysql> select count(*) from bossdb.t1 where tcol<'20200401';
+----------+
| count(*) |
+----------+
| 188535 |
+----------+
1 row in set (2.52 sec)
mysql> explain delete from bossdb.t1 where tcol<'20200401';
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
| 1 | DELETE | t1 | NULL | ALL | NULL | NULL | NULL | NULL | 199988 | 100.00 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+------+--------+----------+-------------+
1 row in set (0.00 sec)
mysql> delete from bossdb.t1 where tcol<'20200401';
6.查看慢日志以及等待Second_Behinds_Master归零
# Time: 2020-04-21T22:42:04.524712+08:00
# User@Host: root[root] @ localhost [] Id: 9795
# Query_time: 13.810188 Lock_time: 0.000130 Rows_sent: 0 Rows_examined: 200000
SET timestamp=1587480124;
delete from bossdb.t1 where tcol<'20200401';
Tue Apr 21 22:42:16 CST 2020
Seconds_Behind_Master: 26
False
Tue Apr 21 22:42:18 CST 2020
Seconds_Behind_Master: 28
False
Tue Apr 21 22:42:20 CST 2020
Seconds_Behind_Master: 30
False
Tue Apr 21 22:42:22 CST 2020
Seconds_Behind_Master: 0
True
7.时间线
22:41:51 开始执行 delete from bossdb.t1 where tcol<'20200401';
22:42:04 binlog写完
22:42:04 主库执行完成
22:42:04 从库开始有second behind master不为0
22:42:22 从库2的second_behind_master 0
22:42:22 从库1的second_behind_master 0
主库执行13秒钟，主从同步用了18s左右。
期末分析
有主键的表主从同步快的十分明显，证明删除操作走主键是最有效的。主库执行时间长因为是因为维护主键的开销，可以忽略。
还有个好方法可以增加主键，不需要迁移数据，直接加自增非空列。
mysql> alter table bossdb.t1 add column `id` int not null auto_increment primary key first;
因此得出结论，MySQL在基于行复制的主从同步模式下，建议所有表有主键。对于批量的删除操作，特别有效。