问题描述
MySQL 8.0.25 在 2023/12/22 10:17:36 左右 出现线程堵塞,正常情况下原本执行很快的sql执行效率陡降(比如:原本执行0.001秒的sql执行7秒仍未结束),导致十几笔交易超时。
问题分析
根据AWR处于非Sleep状态的用户线程,Time由高到低排序,Top1为Command处于Query执行耗时达30秒,是对 performance_schema.data_locks 的查询,该查询需要返回3百多万数据。在查询 performance_schema.data_locks 之后执行的简单DQL&DML都没有按照正常速度完成。
performance_schema.data_locks 在慢日志的记录
# Time: 2023-12-22T10:17:47.968405+08:00
# User@Host: xxx[xxx] @ [127.0.0.1] Id: 10181232
# Query_time: 41.615127 Lock_time: 0.000372 Rows_sent: 7855322 Rows_examined: 7855322
SET timestamp=1703211426;
select engine, engine_lock_id, engine_transaction_id, thread_id, event_id, object_schema, object_name, partition_name, subpartition_name, index_name, object_instance_begin, lock_type, lock_mode, lock_status, lock_data
from performance_schema.data_locks;
疑问1 为什么 performance_schema.data_locks 会有数百万数据?
MySQL 8.0 中,performance_schema.data_locks
包含这些数据:
- InnoDB 事务已申请但未获得的锁。
- InnoDB 事务正在持有的锁。
可能有事务,有大量 正在持有锁 或者 已申请但未获得锁。
疑问2 什么操作持有百万数据量的行锁?
根据异常期间AWR与慢日志,发现问题sql UPDATE xxx_dtl xxx order by t.priority desc 执行过程累计扫描200多万数据 且 在一个未提交事务累计持有 400 多万 row locks,也就是造成performance_schema.data_locks 有百万数据量的原因。
AWR截图
慢日志截图
疑问3 为什么 MySQL整个实例的SQL执行会变慢?
SQL执行缓慢猜测有3种原因:1、SQL执行效率低 2、资源异常/瓶颈 3、无效等待
1、SQL执行效率低 (排除),没有表锁的情况下,简单 select & insert 执行很快。
2、资源异常/瓶颈(排除),查看监控没有硬件报错与没有资源使用率跑高。
3、无效等待(复现),根据AWR抓取的现场信息,模拟后能100%复现。
问题复现
session1 | session2 | session3 | |
t1 | mysql> use dbtest; mysql> begin; Query OK, 0 rows affected (0.00 sec) mysql> update sbtest1 set c='d'; Query OK, 0 rows affected (13.13 sec) Rows matched: 3000000 Changed: 0 Warnings: 0 | ||
t2 | mysql> insert into t1 values(1113,1113); Query OK, 1 row affected (0.01 sec) | ||
t3 | mysql> select count(*) from performance_schema.data_locks;+----------+*| count(*) |+----------+| 3000001 |+----------+1 row in set (27.34 sec) | mysql> insert into t1 values(1114,1114); Query OK, 1 row affected (18.58 sec) | |
t4 | mysql> insert into t1 values(1115,1115); Query OK, 1 row affected (0.02 sec) | ||
t5 | commit | ||
t6 | mysql> select count(*) from performance_schema.data_locks;+----------+*| count(*) |+----------+| 0 |+----------+1 row in set (0.01 sec) | mysql> insert into t1 values(1116,1116);Query OK, 1 row affected (0.02 sec) |
用vscode查看mysqld的函数调用情况
正常执行dml语句的堆栈,可见执行iterator,代表dml操作正常执行
查询data_locks后,再执行的dml语句堆栈变更为条件等待,等待locksys::latches的释放
测试结论:performance_schema.data_locks有大量数据时,查询performance_schema.data_locks会严重影响其他并发SQL的执行效率,执行其他SQL需要等待查询 performance_schema.data_locks 持有的locksys::latches的释放,才能往下执行
问题总结
MySQL 8.x当performance_schema.data_locks有大量数据时,查询performance_schema.data_locks会严重影响其他并发SQL的执行效率,执行其他SQL需要等待查询 performance_schema.data_locks 持有的locksys::latches释放后,才能往下执行,可能会造成MySQL大量阻塞。
优化建议
1、业务问题sql UPDATE xxx_dtl xxx order by t.priority desc ,去掉order by t.priority desc 减少数据扫描量缩短锁占用时间提升执行效率
2、避免大事务,避免长时间未提交事务
3、禁止出现访问 performance_schema.data_locks/sys.innodb_lock_waits 的"慢查询",最好不要查询performance_schema.data_locks/sys.innodb_lock_waits
4、MySQL 8.X sys.innodb_lock_waits视图依赖performance_schema.data_locks,特殊场景下也会产生阻塞问题。MySQL 8.X 中,如果只想要获取锁的阻塞情况,可以查询 performance_schema.data_lock_waits。而MySQL 5.7 查询information_schema.INNODB_LOCKS不会造成阻塞。