故障分析 | MySQL 升级到 8.0 变慢问题分析
作者：操盛春
技术专家，任职于爱可生，专注研究 MySQL、OceanBase 源码。
本文来源：原创投稿
1. 背景介绍
升级完成之后，放业务请求进来，没到一分钟就开始出现慢查询，然后，慢查询越来越多，业务 SQL 出现堆积。
整个过程持续了大概一个小时，直到给某条业务 SQL 对应的表加上索引，问题才得到解决。
有一个比较奇怪的现象是：问题持续的过程中，服务器的系统负载、CPU 使用率、磁盘 IO、网络都处于低峰时期的水平，也就是说，问题很可能不是因为硬件资源不够用导致的。
那么，根本原因到底是什么？让我们一起来揭晓答案~
2. 原因分析
客户线上环境有一个监控脚本，每分钟执行一次，这个脚本执行的 SQL 如下：
select ... from sys.innodb_lock_waits w
inner join information_schema.innodb_trx b
on b.trx_id = w.blocking_trx_id
inner join information_schema.innodb_trx r
on r.trx_id = w.waiting_trx_id;
对几个监控脚本的日志、SAR 日志、MySQL 的慢查询日志 & 错误日志，以及死锁的源码，进行了全方位无死角的分析，发现了可疑之处。
经过测试验证，最终确认罪魁祸首是 sys.innodb_lock_waits 视图引用的某个基表。
这个基表的名字和 MySQL 5.7 中不一样了，它的行为也发生了变化，就是这个行为的变化在某些场景下阻塞了业务 SQL，导致大量业务 SQL 执行变慢。
揭露这个罪恶的基表之前，我们先来看一下 sys.innodb_lock_waits 视图的定义：
-
MySQL 5.7 中简化的视图定义
CREATE VIEW sys.innodb_lock_waits AS
SELECT ... FROM information_schema.innodb_lock_waits w
JOIN information_schema.innodb_trx b
ON b.trx_id = w.blocking_trx_id
JOIN information_schema.innodb_trx r
ON r.trx_id = w.requesting_trx_id
JOIN information_schema.innodb_locks bl
ON bl.lock_id = w.blocking_lock_id
JOIN information_schema.innodb_locks rl
ON rl.lock_id = w.requested_lock_id
ORDER BY r.trx_wait_started
-
MySQL 8.0 中简化的视图定义
CREATE VIEW sys.innodb_lock_waits (...) AS
SELECT ... FROM performance_schema.data_lock_waits w
JOIN information_schema.INNODB_TRX b
ON b.trx_id = w.BLOCKING_ENGINE_TRANSACTION_ID
JOIN information_schema.INNODB_TRX r
ON r.trx_id = w.REQUESTING_ENGINE_TRANSACTION_ID
JOIN performance_schema.data_locks bl
ON bl.ENGINE_LOCK_ID = w.BLOCKING_ENGINE_LOCK_ID
JOIN performance_schema.data_locks rl
ON rl.ENGINE_LOCK_ID = w.REQUESTING_ENGINE_LOCK_ID
ORDER BY r.trx_wait_started
5.7 中 sys.innodb_lock_waits 涉及 3 个基表：
-
information_schema.innodb_lock_waits -
information_schema.innodb_locks -
information_schema.innodb_trx
8.0 中 sys.innodb_lock_waits 也涉及 3 个基表：
-
performance_schema.data_lock_waits -
performance_schema.data_locks -
information_schema.INNODB_TRX
揭晓答案：引发问题的罪魁祸首就是 8.0 中的 performance_schema.data_locks 表。
从两个版本的视图定义对比可以看到，performance_schema.data_locks 的前身是 information_schema.innodb_locks。
我们再来看看这两个表的行为有什么不一样？
MySQL 5.7 中，information_schema.innodb_locks 包含这些数据：
-
InnoDB 事务已申请但未获得的锁。 -
InnoDB 事务已持有并且阻塞了其它事务的锁。
官方文档描述如下：
The INNODB_LOCKS table provides information
about each lock that an InnoDB transaction
has requested but not yet acquired,
and each lock that a transaction holds
that is blocking another transaction.
MySQL 8.0 中，performance_schema.data_locks 包含这些数据：
-
InnoDB 事务已申请但未获得的锁。 -
InnoDB 事务正在持有的锁。
官方文档描述如下：
The data_locks table
shows data locks held and requested
从官方文档的描述可以看到两个表的不同之处：
-
5.7 的 innodb_locks记录 InnoDB 事务已持有并且阻塞了其它事务的锁。 -
8.0 的 data_locks记录 InnoDB 事务正在持有的锁。
正是因为这个不同之处，导致 8.0 的 data_locks 表的数据量可能会非常大。
我们再深挖一层，看看 data_locks 表的数据量大是怎么导致其它业务 SQL 阻塞的。
MySQL 线程读取 data_locks 表时，会持有全局事务对象互斥量（trx_sys->mutex），直到读完表中的所有数据，才会释放这个互斥量。
实际上，
直到读完表中的所有数据，才会释放 trx_sys->mutex 互斥量的说法不准确。
为了避免展开介绍读取 data_locks 表实现逻辑，我们暂且使用这个说法。
data_locks 表的数据量越大，从表里读取数据花费的时间就越长，读取这个表的线程持有 trx_sys->mutex 互斥量的时间也就越长。
从 data_locks 表里读取数据的线程长时间持有 trx_sys->mutex 互斥量会有什么问题？
这个问题就大了，因为 trx_sys->mutex 互斥量非常吃香。
涉及 InnoDB 的所有 SQL 都在事务中运行，每个事务启动成功之后，都需要加入全局事务链表，而全局事务链表需要 trx_sys->mutex 互斥量的保护。
也就是说，InnoDB 中每个事务加入全局事务链表之前，都需要持有 trx_sys->mutex 互斥量。
从 data_locks 表里读取数据的线程长时间持有 trx_sys->mutex 互斥量，就会长时间阻塞其它 SQL 执行，导致其它 SQL 排队等待，出现堆积，表现出来的状态就是 MySQL 整体都变慢了。
介绍清楚逻辑之后，我们回归现实，来看看客户线上的问题。
1. 背景介绍小节中提到的那条业务 SQL 在执行过程中会对 300 万条记录加锁。
这条 SQL 只要执行一次，事务结束之前，data_locks 表中会有 300 万条加锁记录。
从 data_locks 表中读取记录之前，需要持有 trx_sys->mutex 互斥量，再读取 300 万条记录，最后释放互斥量。互斥量释放之前，其它业务 SQL 就得排队等着这个互斥量。
监控脚本执行一次的过程中，一堆业务 SQL 只能排队等待 trx_sys->mutex 互斥量，然后到了周期执行时间，监控脚本又执行了一次，也在等待 trx_sys->mutex 互斥量，不幸的是，又来了一堆业务 SQL。
就这样，监控脚本和业务 SQL 相互影响，恶性循环，SQL 执行越来越慢...，直到 DBA 在 1. 背景介绍小节中提到的那条业务 SQL 对应的表上创建了一个索引。
在那个表上创建索引之后，那条业务 SQL 执行过程中就不需要对 300 万条记录加锁了，而是只会对少量记录加锁，data_locks 表中的数据量也就变的很少了，不需要长时间持有 trx_sys->mutex 互斥量，消除了堵点，MySQL 整体就变的通畅了。
3. 测试验证
在 MySQL 5.7 和 8.0 的 test 库中都创建 t1 表，事务隔离级别为：READ-COMMITTED。
表结构如下：
CREATE TABLE `t4` (
`id` int unsigned NOT NULL AUTO_INCREMENT,
`e1` enum('长春', '沈阳', '福州', '成都', '杭州', '南昌', '苏州', '德清', '北京') NOT NULL DEFAULT '北京',
`i1` int unsigned NOT NULL DEFAULT '0',
`c1` char(11) DEFAULT '',
`d1` decimal(10,2) DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3
数据如下：
3.1 MySQL 5.7 测试
第 1 步，在 session 1 中执行一条 SQL，锁住全表记录：
mysql> begin;
Query OK, 0 rows affected (0.00 sec)
mysql> select * from test.t1
-> for update;
+----+--------+-------+---------------+------------+
| id | e1 | i1 | c1 | d1 |
+----+--------+-------+---------------+------------+
| 1 | 长春 | 99999 | 1 测试char | 1760407.11 |
| 2 | 沈阳 | 2 | 2 测试char | 3514530.95 |
| 3 | 福州 | 3 | 3 测试char | 2997310.90 |
| 4 | 成都 | 4 | 4 测试char | 8731919.55 |
| 5 | 杭州 | 5 | 5 测试char | 2073324.31 |
| 6 | 南昌 | 6 | 6 测试char | 3258837.89 |
| 7 | 苏州 | 7 | 7 测试char | 2735011.35 |
| 8 | 德清 | 8 | 8 测试char | 145889.60 |
| 9 | 杭州 | 9 | 9 测试char | 2028916.63 |
| 10 | 北京 | 10 | 10 测试char | 3222960.80 |
+----+--------+-------+---------------+------------+
10 rows in set (0.00 sec)
第 2 步，在 session 2 中，执行另一条 SQL：
mysql> select * from test.t1
-> where id >= 5
-> for update;
第 3 步，session 2 的 SQL 等待获取锁的过程中，在 session 3 中查询锁的情况：
mysql> select * from information_schema.innodb_lock_waits;
+-------------------+-------------------+-----------------+------------------+
| requesting_trx_id | requested_lock_id | blocking_trx_id | blocking_lock_id |
+-------------------+-------------------+-----------------+------------------+
| 263231 | 263231:473:3:6 | 263229 | 263229:473:3:6 |
+-------------------+-------------------+-----------------+------------------+
1 row in set, 1 warning (0.04 sec)
mysql> select
-> lock_id, lock_trx_id, lock_table, lock_data
-> from information_schema.innodb_locks;
+----------------+-------------+-------------+-----------+
| lock_id | lock_trx_id | lock_table | lock_data |
+----------------+-------------+-------------+-----------+
| 263231:473:3:6 | 263231 | `test`.`t1` | 5 |
| 263229:473:3:6 | 263229 | `test`.`t1` | 5 |
+----------------+-------------+-------------+-----------+
2 rows in set, 1 warning (0.01 sec)
从 innodb_lock_waits 的查询结果可以看到，事务 263231 申请持有锁被事务 263229 阻塞了。
innodb_locks 表中有 2 条记录：
-
lock_trx_id = 263231, lock_data = 5 的记录表示事务 263231 正在申请对 id = 5 的记录加锁。
-
lock_trx_id = 263229，lock_data = 5 的记录表示事务 263229 正在持有 id = 5 的记录上的锁，阻塞了事务 263231 对 id = 5 的记录加锁。
这和官方文档对 innodb_locks 表的行为的描述一致（前面已介绍过）。
3.2 MySQL 8.0 测试
第 1 步，在 session 1 中执行一条 SQL，锁住全表记录：
mysql> begin;
Query OK, 0 rows affected (0.00 sec)
mysql> select * from test.t1
-> for update;
+----+--------+-------+---------------+------------+
| id | e1 | i1 | c1 | d1 |
+----+--------+-------+---------------+------------+
| 1 | 长春 | 99999 | 1 测试char | 1760407.11 |
| 2 | 沈阳 | 2 | 2 测试char | 3514530.95 |
| 3 | 福州 | 3 | 3 测试char | 2997310.90 |
| 4 | 成都 | 4 | 4 测试char | 8731919.55 |
| 5 | 杭州 | 5 | 5 测试char | 2073324.31 |
| 6 | 南昌 | 6 | 6 测试char | 3258837.89 |
| 7 | 苏州 | 7 | 7 测试char | 2735011.35 |
| 8 | 德清 | 8 | 8 测试char | 145889.60 |
| 9 | 杭州 | 9 | 9 测试char | 2028916.63 |
| 10 | 北京 | 10 | 10 测试char | 3222960.80 |
+----+--------+-------+---------------+------------+
10 rows in set (0.00 sec)
第 2 步，在 session 2 中，执行另一条 SQL：
mysql> select * from test.t1
-> where id >= 5
-> for update;
第 3 步，session 2 的 SQL 等待获取锁的过程中，在 session 3 中查询锁的情况：
mysql> select
-> engine_transaction_id as trx_id,
-> lock_status, lock_data
-> from performance_schema.data_locks
-> where lock_type = 'RECORD';
+--------+-------------+-----------+
| trx_id | lock_status | lock_data |
+--------+-------------+-----------+
| 19540 | WAITING | 5 |
| 19522 | GRANTED | 1 |
| 19522 | GRANTED | 2 |
| 19522 | GRANTED | 3 |
| 19522 | GRANTED | 4 |
| 19522 | GRANTED | 5 |
| 19522 | GRANTED | 6 |
| 19522 | GRANTED | 7 |
| 19522 | GRANTED | 8 |
| 19522 | GRANTED | 9 |
| 19522 | GRANTED | 10 |
+--------+-------------+-----------+
11 rows in set (0.00 sec)
从以上查询结果可以看到，data_locks 表里包含事务 19522 正在持有的 10 把锁（对应 10 条锁记录），以及事务 19540 已申请但未获得的 id = 5 的记录上的锁，这个行为也和官方文档的描述一致（前面介绍过）。
4. 总结
performance_schema.data_locks 表会记录所有事务正在持有的锁，如果某些 SQL 写的有问题，锁定记录非常多，这个表里的锁记录数量就会非常多。
data_locks 表里的锁记录数量非常多，读取这个表的线程就会长时间持有 trx_sys->mutex 互斥量，这会阻塞其它 SQL 执行。
如果只想要获取锁的阻塞情况，可以查询 performance_schema.data_lock_waits。
文章推荐：
爱可生开源社区的 SQLE 是一款面向数据库使用者和管理者，支持多场景审核，支持标准化上线流程，原生支持 MySQL 审核且数据库类型可扩展的 SQL 审核工具。
| 类型 | 地址 |
|---|---|
| 版本库 | https://github.com/actiontech/sqle |
| 文档 | https://actiontech.github.io/sqle-docs-cn/ |
| 发布信息 | https://github.com/actiontech/sqle/releases |
| 数据审核插件开发文档 | https://actiontech.github.io/sqle-docs-cn/3.modules/3.7_auditplugin/auditplugin_development.html |
更多关于 SQLE 的信息和交流，请加入官方QQ交流群：637150065...
本文分享自微信公众号 - 爱可生开源社区（ActiontechOSS）。
如有侵权，请联系 support@oschina.cn 删除。
本文参与“OSC源创计划”，欢迎正在阅读的你也加入，一起分享。
