MySQL 5.7最新版本的2个bug

a616652325

　　好久没写博客了，都长草了。新业务上了5.7没遇到什么问题，虽然没遇到什么问题，但不代表没有问题，我有个习惯就是没事就喜欢逛逛percona的Blog，于是看到目前最新GA版本5.7.17的2个bug，于是就搭建环境进行bug复现。目前知道的2个bug如下：
　　1. slave_parallel_workers > 0，也就是开启了多线程复制的时候如果有延时，那么Seconds_Behind_Master一直是0，不会变化，虽然这个参数不准确，但也是一个衡量指标。准确的复制延时判断的请看我前面的文章：主从复制延时判断
　　2. super_read_only开启的时候mysql库中的gtid_executed表会压缩失败，至于这个表是干嘛的请参考文章：MySQL 5.7中新增的表gtid_executed，看看是否解决了你的痛点，原文作者是姜承尧，但原作者的连接打不开了。
　　环境：5.7.17, 1主2从，下面进行第一个bug的复现，其中一个从库是普通复制，也就是没开启多线程复制，另外一个从库开启多线程复制。
　　首先用sysbench写入100w数据，然后在主库进行delete操作，模拟延时，然后查看区别。
　　

sysbench --test=oltp --oltp-table-size=1000000 --oltp-read-only=off --init-rng=on --num-threads=16 --max-requests=0 --oltp-dist-type=uniform --max-time=1800 --mysql-user=root --mysql-socket=/data/mysql/3306/mysqltmp/mysql.sock --mysql-password=123 --db-driver=mysql --mysql-table-engine=innodb --oltp-test-mode=complex prepare 　　

　　普通复制：
　　

mysql> show variables like '%parallel%';　　

+------------------------+----------+　　
| Variable_name          | Value    |
　　
+------------------------+----------+
　　
| slave_parallel_type    | DATABASE |
　　
| slave_parallel_workers | 0        |
　　
+------------------------+----------+
　　
2 rows in set (0.00 sec)
　　

　　
mysql>
　　

　　多线程复制：
　　

mysql> show variables like '%parallel%';　　

+------------------------+---------------+　　
| Variable_name          | Value         |
　　
+------------------------+---------------+
　　
| slave_parallel_type    | LOGICAL_CLOCK |
　　
| slave_parallel_workers | 8             |
　　
+------------------------+---------------+
　　
2 rows in set (0.02 sec)
　　

　　准备查看复制延时脚本：
　　

for i in {1..1000};　　

do　　
(
　　
mysql
-uroot -p123 -h 192.168.0.20 -e "SHOW SLAVE STATUS\G" | grep "Seconds_Behind_Master" | awk '{print "slave_1_not-multi-threaded-repl: " $2}' &　　
sleep 0.1 ;
　　
mysql -uroot -p123 -h 192.168.0.30 -e "SHOW SLAVE STATUS\G" | grep "Seconds_Behind_Master" | awk '{print "slave_2_multi-threaded-repl: " $2}' &
　　
);
　　
sleep 1;
　　
done
　　

　　让这个脚本跑起来，然后在主库删除数据，看复制延时的情况。然后在主库删除数据：
　　

delete from sbtest where>　　

　　运行脚本，查看复制延时情况，输出如下，可以看到开启了多线程复制的Seconds_Behind_Master一直为0，不会变化，而普通复制则显示延时了。
　　

[iyunv@dbserver-yayun-04 ~]# sh a.sh　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_1_not
-multi-threaded-repl: 103　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_2_multi
-threaded-repl: 0　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_1_not
-multi-threaded-repl: 104　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_2_multi
-threaded-repl: 0　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_1_not
-multi-threaded-repl: 105　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_2_multi
-threaded-repl: 0　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
mysql: [Warning] Using a password on the command line interface can be insecure.
　　
slave_1_not
-multi-threaded-repl: 106　　
slave_2_multi
-threaded-repl: 0　　

　　Percona给的解决方法是：
　　

SELECT PROCESSLIST_TIME FROM performance_schema.threads WHERE NAME = 'thread/sql/slave_worker' AND (PROCESSLIST_STATE IS NULL  or PROCESSLIST_STATE != 'Waiting for an event from Coordinator') ORDER BY PROCESSLIST_TIME DESC LIMIT 1;　　

　　下面进行super_read_only开启以后触发bug的复现：
　　1. 其中一个从库设置gtid_executed_compression_period=1，用来控制每执行多少个事务，对此表进行压缩，默认值为1000
　　2. super_read_only开启，超级用户都无法更改从库的数据。
　　3. 关闭log_slave_updates，如果开启，gtid_executed表不会实时变更，也不会压缩。（percona博客中开启了log_slave_updates也触发了bug，我认为是博客中有错误）
　　

mysql> show variables like '%gtid_ex%';　　

+----------------------------------+-------+　　
| Variable_name                    | Value |
　　
+----------------------------------+-------+
　　
| gtid_executed_compression_period | 1     |
　　
+----------------------------------+-------+
　　
1 row in set (0.01 sec)
　　

　　
mysql> show variables like '%log_slave_updates%';
　　
+-------------------+-------+
　　
| Variable_name     | Value |
　　
+-------------------+-------+
　　
| log_slave_updates | OFF   |
　　
+-------------------+-------+
　　
1 row in set (0.00 sec)
　　

　　
mysql> show variables like '%super%';
　　
+-----------------+-------+
　　
| Variable_name   | Value |
　　
+-----------------+-------+
　　
| super_read_only | ON    |
　　
+-----------------+-------+
　　
1 row in set (0.00 sec)
　　

　　
mysql>
　　

　　下面在主库运行sysbench进行压测，产生事务。
　　

sysbench --test=oltp --oltp-table-size=100000 --oltp-read-only=off --init-rng=on --num-threads=16 --max-requests=0 --oltp-dist-type=uniform --max-time=1800 --mysql-user=root --mysql-socket=/data/mysql/3306/mysqltmp/mysql.sock --mysql-password=123 --db-driver=mysql --mysql-table-engine=innodb --oltp-test-mode=complex run　　

　　查看从库：
　　

mysql> select count(*) from gtid_executed;　　

+----------+　　
| count(*) |
　　
+----------+
　　
|       93 |
　　
+----------+
　　
1 row in set (0.44 sec)
　　

　　
mysql> select count(*) from gtid_executed;
　　
+----------+
　　
| count(*) |
　　
+----------+
　　
|      113 |
　　
+----------+
　　
1 row in set (0.66 sec)
　　

　　
mysql>
　　

　　可以发现并没有压缩，一直在增加。
　　执行show engine innodb status可以看到有线程在压缩表的，但是没成功，在回滚
　　

---TRANSACTION 10909611, ACTIVE 2 sec rollback　　
mysql tables in use 1, locked 1

　　
ROLLING BACK 4 lock struct(s), heap>
　　
MySQL thread>　　

　　查看INNODB_TRX表，也能发现有事务在回滚。
　　

mysql> select trx_id,trx_state,trx_operation_state,trx_isolation_level from information_schema.INNODB_TRX;　　

+-----------------+--------------+---------------------+---------------------+　　
| trx_id          | trx_state    | trx_operation_state | trx_isolation_level |
　　
+-----------------+--------------+---------------------+---------------------+
　　
| 10919604        | ROLLING BACK | rollback            | REPEATABLE READ     |
　　
| 421910840085200 | RUNNING      | starting index read | REPEATABLE READ     |
　　
+-----------------+--------------+---------------------+---------------------+
　　
2 rows in set (0.00 sec)
　　

　　看见现在表已经有很多记录了：
　　

mysql> select count(*) from gtid_executed;　　

+----------+　　
| count(*) |
　　
+----------+
　　
|     2448 |
　　
+----------+
　　
1 row in set (0.00 sec)
　　

　　
mysql>
　　

　　关闭super_read_only
　　

mysql> set global super_read_only=0;　　
Query OK,
0 rows affected (0.00 sec)　　

　　
mysql
> select count(*) from gtid_executed;　　

+----------+　　
| count(*) |
　　
+----------+
　　
|        2 |
　　
+----------+
　　
1 row in set (0.07 sec)
　　

　　
mysql> select count(*) from gtid_executed;
　　
+----------+
　　
| count(*) |
　　
+----------+
　　
|        2 |
　　
+----------+
　　
1 row in set (0.00 sec)
　　

　　
mysql>
　　

　　马上恢复正常了。
　　参考文章：
　　https://www.percona.com/blog/2017/02/08/mysql-super_read_only-bugs/
　　https://www.percona.com/blog/2017/01/27/wrong-seconds_behind_master-with-slave_parallel_workers-0/
　　http://keithlan.github.io/2017/02/15/gtid_practice/?utm_source=tuicool&utm_medium=referral