mysql8.0的坑 - data_locks导致的全库变慢问题

讲一个关于mysql8.0的故事：

在mysql5.7时代，若想获取行锁信息，要用到 information_schema.innodb_locks 表，到了mysql8.0，它已不复存在，取而代之的是 performance_schema.data_locks 表。两者的区别如下：
innodb_locks 包含这些数据：

• InnoDB 事务已申请但未获得的锁
• InnoDB 事务已持有并且阻塞了其它事务的锁

data_locks 包含这些数据：

• InnoDB 事务已申请但未获得的锁
• InnoDB 事务正在持有的锁

说到这儿，并没什么不妥，反而 data_locks 为DBA分析事务加锁情况，提供了极大的便利，可故事往往不是一帆风顺……

某天，DBA要归档一张表的数据，其中有一件必做的事情：从表中删除50W记录。
由于要归档的数据，业务基本不会访问，故决定用一条SQL：delete from tb where create_time < ‘2022-07-27’ 直接删除。

开始表演：

-- 下面所有操作在 session1 中进行：
-- 创建测试表
 CREATE TABLE `lock_test` (
  `id` int NOT NULL AUTO_INCREMENT,
  `create_time` datetime,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB;

-- 插入100万数据
mysql> insert into lock_test (create_time)
    -> select '2022-07-27' from information_schema.columns a, information_schema.columns b limit 500000;
Query OK, 500000 rows affected (12 min 14.17 sec)
Records: 500000  Duplicates: 0  Warnings: 0

mysql> insert into lock_test (create_time) select '2023-07-27' from lock_test limit 500000;
Query OK, 500000 rows affected (4 min 32.77 sec)
Records: 500000  Duplicates: 0  Warnings: 0

-- 删除50万数据
mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> delete from lock_test where create_time <= '2022-07-27';
Query OK, 500000 rows affected (5 min 38.12 sec)

故事说到这儿，暂停一下，看看这波操作可能引起的问题：

• 删除的50W数据加X行锁（RC隔离级别），会阻塞这些行后续的delete、update语句
• 如果数据不在buffer pool中，会产生一定的物理IO

好像没什么大问题，此时，重点来了，有一条监控SQL每5秒运行一次：select count(*) from performance_schema.data_locks;

继续表演：

-- 下面所有SQL逐个顺序执行：
-- 在 session2 中执行 (1个表IX锁 + 500000个X行锁)
mysql> select count(*) from performance_schema.data_locks;
+----------+
| count(*) |
+----------+
|   500001 |
+----------+
1 row in set (21.70 sec)

-- 在 session3 中执行 (只要是事务，就要等待trx_sys->mutex)
mysql> begin; select * from t;
Query OK, 0 rows affected (0.00 sec)

+----+------+------+
| id | b    | c    |
+----+------+------+
|  7 |    7 |    0 |
|  8 |    8 |    0 |
|  9 |    9 |    0 |
+----+------+------+
3 rows in set (20.11 sec)

-- 在 session4 中执行（没有显示声明事务，也可能被阻塞）
mysql> select * from t;
+----+------+------+
| id | b    | c    |
+----+------+------+
|  7 |    7 |    0 |
|  8 |    8 |    0 |
|  9 |    9 |    0 |
+----+------+------+
3 rows in set (19.30 sec)

-- 在 session5 中执行（查看SQL运行状态，虽然被阻塞，但仍是executing状态）
mysql> show processlist;
+-----+-----------------+-----------------------+--------------------+------------------+--------+-----------------------------------------------------------------+----------------------------------------------------+
| Id  | User            | Host                  | db                 | Command          | Time   | State                                                           | Info                                               |
+-----+-----------------+-----------------------+--------------------+------------------+--------+-----------------------------------------------------------------+----------------------------------------------------+
|   5 | event_scheduler | localhost             | NULL               | Daemon           | 121022 | Waiting on empty queue                                          | NULL                                               |
|  27 | repl            | 192.168.199.131:43949 | NULL               | Binlog Dump GTID |  80117 | Source has sent all binlog to replica; waiting for more updates | NULL                                               |
|  36 | root            | 192.168.199.1:59031   | information_schema | Sleep            |  18498 |                                                                 | NULL                                               |
|  64 | root            | 192.168.199.1:63255   | NULL               | Sleep            |  18498 |                                                                 | NULL                                               |
|  75 | root            | 192.168.199.1:51130   | NULL               | Sleep            |  24392 |                                                                 | NULL                                               |
| 108 | root            | 192.168.199.130:49062 | modb               | Sleep            |    415 |                                                                 | NULL                                               |
| 110 | root            | 192.168.199.130:49064 | modb               | Query            |     18 | executing                                                       | select count(*) from performance_schema.data_locks |
| 115 | root            | 192.168.199.130:49069 | modb               | Query            |     17 | executing                                                       | select * from t                                    |
| 116 | root            | 192.168.199.130:49070 | modb               | Query            |     17 | executing                                                       | select * from t                                    |
| 118 | root            | 192.168.199.130:49072 | modb               | Query            |      0 | init                                                            | show processlist                                   |
+-----+-----------------+-----------------------+--------------------+------------------+--------+-----------------------------------------------------------------+----------------------------------------------------+
10 rows in set (0.02 sec)

可以看出，后续的SQL语句都被阻塞了。分析如下：

1. 由于 data_locks 中有大量的行锁记录，导致扫描一次很慢。
2. 扫描 data_locks 时，SQL线程会持有全局事务对象互斥量（trx_sys->mutex），直到扫描结束才释放。
3. InnoDB 中每个事务加入全局事务链表之前，都需要持有 trx_sys->mutex 互斥量，按SQL分类如下：
   • insert,delete,update：一定要等待 trx_sys->mutex 互斥量，直到持有。
   • 显示开启事务的select：一定要等待 trx_sys->mutex 互斥量，直到持有。
   • 未显示开启事务的select：实测发现，也会出现等待，但有时也不会。
4. 由于 trx_sys->mutex 释放较慢，业务SQL出现堆积。

最终，删除50W记录耗时5分钟38.12秒，在这个过程中，data_locks记录越来越多，data_locks每5秒扫描1次，整个mysql的SQL查询出现等待堆积，且CPU、IO没有明显异常，内存使用量上涨（如果内存不足，实测mysql会自动释放后，再次上涨）。

那该如何解决呢？

• 关掉 performance_schema，这个动作有点儿大，DBA肯定不答应。
• 保证不出现大事务、不产生大量行锁，这个也无法100%保证。
• 去掉 data_locks 的监控，这个貌似代价最小，但假如出现类似问题，如何预防？
• 思来想去，可用下面SQL做近似监控：select sum(trx_rows_locked) from information_schema.innodb_trx;

故事完。