官方在 8.0.37 中修复了这个 bug,可升级到 8.0.37 解决。

作者:胡呈清,爱可生 DBA 团队成员,擅长故障分析、性能优化,个人博客:[简书 | 轻松的鱼],欢迎讨论。

爱可生开源社区出品,原创内容未经授权不得随意使用,转载请联系小编并注明来源。

本文约 1500 字,预计阅读需要 8 分钟。

问题描述

MySQL 版本:8.0.26

跑批执行到 insert into t1 select * from t2 时,有一个定时任务运行 MySQL 巡检脚本,巡检脚本执行到 select * from performance_schema.data_locks、select * from performance_schema.data_lock_waits 会导致 MySQL hang,一开始只是某些 SQL 执行无响应,最终 MySQL 无法登录。

分析过程

1. 开始 hang 时的线程状态

下图标记的两个线程中:

  • 第一个线程完整的 SQL 是 insert into t1 select * from t2
  • 第二个线程完整的 SQL 是 select * from performance_schema.data_lock_waits,这是巡检脚本里的 SQL,上一句是 select * from performance_schema.data_locks
  • 其余线程全部都卡住了

2. 分析堆栈

分析等锁和互斥量的线程持有和正在等待的锁情况如下:

  • Thread 285 持有 LOCK_status,被 Thread 21 持有的 srv_innodb_monitor_mutex 阻塞
  • Thread 21 持有 srv_innodb_monitor_mutex,被未知线程持有的 trx_sys_mutex_enter()trx_sys->mutex 阻塞
  • 大量线程被 Thread 285 持有的 LOCK_status 阻塞
  • 大量线程(包括 insert into..select 和查询 ps.data_lock_wait)阻塞在 trx_sys_mutex_enter()

现在的问题是没有找到哪个线程持有了 trx_sys->mutex 互斥量。

<蓝1,绿2>

3. 本地复现

调用存储过程,当执行到 insert into ... select... 时,另外一个 session 执行 select * from performance_schema.data_locks

反复测试了很多次,后面找到了复现的必要条件:

执行 select * from performance_schema.data_locks 报错内存分配异常:ERROR 3044 (HY000): Memory allocation error: while scanning data_locks table in function rnd_next.

然后才能观察到 insert into ... select 卡住,堆栈显示这个线程在等 trx_sys->mutex

复现截图:

insert into ... select 线程堆栈如下,不过分析所有线程堆栈后仍然找不到谁持有了 trx_sys->mutex

4. 代码分析 trx_sys->mutex 结构

由于堆栈信息里找不到 trx_sys->mutex 互斥锁的持有者,想到的另外一个方法是用 gdb 打印出 trx_sys->mutex 结构,看其中是否有线程 ID 信息。

发现只有 debug 模式下才有 线程 ID 信息,普通模式下没有,因此需要编译一个 debug 版本进行复现,然后用 gdb 打印出 trx_sys->mutex 互斥锁的持有者。

5. debug版本复现

当查询 ps.data_locks 触发内存分配报错后,通过 gdb 打印 insert into 线程的堆栈,卡在了 mutex_enter_inline

然后打印查询 ps.data_locks 的线程堆栈,堆栈是正常的,但是打印 trx_sys->mutex 时发现持有者竟是它自己:

_M_thread 的值转换为 16 进制,就可以用来核对 gdb info thread 输出的的线程号:

gdb) p/x 140316922181376
$2 = 0x7f9e144d7700

6. 合理推测&找证据

经过 debug 版本上复现,发现查询 ps.data_locks 时触发内存分配错误,但是没有释放 trx_sys->mutex 互斥量。

于是合理推测:存在 bug,查询 ps.data_locks 时触发内存分配错误后,不会释放 trx_sys->mutex,导致内部死锁。

找到了这个 bug:https://github.com/mysql/mysql-server/commit/d6be2f8d23b1fe41f10c7147957faf68b117abb2

7. bug 解释

performance_schame.data_locks 的实现中,使用了 C++ try-catch 机制来处理读取 data_locks 记录时内存分配失败的异常情况。

table_data_locks.cc 文件的 table_data_locks::rnd_next 函数中:

代码解释:
catch (const std::bad_alloc &) 用来捕获 std::bad_alloc 类型的异常,当 try 块中抛出 std::bad_alloc 异常时,调用 my_error 打印错误信息,并返回 ER_STD_BAD_ALLOC_ERROR,结束执行。

try 模块中的 iterator_done = it->scan(&m_container, true); 是实际执行的业务逻辑代码,it->scan 进行某种迭代扫描操作,结果存储在 iterator_done 变量中。catch 模块捕获的异常就是由这里抛出的。

it->scan 的定义在 p_s.cc 源码文件的 Innodb_data_lock_iterator::scan 函数中,执行逻辑很清晰:

  1. trx_sys_mutex_enter() 先加 trx_sys->mutex 互斥锁
  2. 调用 scan_trx_list 扫码 rw_trx_listmysql_trx_list 两个事务列表
  3. trx_sys_mutex_exit() 释放 trx_sys->mutex 互斥锁

很显然,调用 scan_trx_list 扫描时如果发生 std::bad_alloc 内存异常,会直接被 catch 模块获取,抛出异常结束执行,无法执行到 trx_sys_mutex_exit() 释放互斥锁,导致了 trx_sys->mutex 互斥锁的残留。

这一点可以在 debug 版本复现时打印的 trx_sys->mutex 信息中得到证实:是在 p_s.cc 文件的第 592 行加上的。

复现步骤

简化的复现步骤如下:

  1. 准备一个小内存的虚拟机,比如 2-4G,方便触发内存分配异常
  2. 造一张 500 万行的表 t1
  3. 执行 begin;select * from t1 for update;
  4. 执行 select * from performance_schema.data_locks; 触发报错 ERROR 3044 (HY000): Memory allocation error: while scanning data_locks table in function rnd_next.
  5. 继续查询 performance_schema.data_lock_waits 会被阻塞。

结论

该故障成因如下:

  1. 跑批中 INSERT INTO t1 SELECT * FROM t2; 会对 t2 表所有行加 S Lock(原因:RR 隔离级别,并且无法走索引)。t2 表很大,有几亿行,会导致 performance_schema.data_locks 中有几亿个锁记录;
  2. 查询 ps.data_locks 时,由于记录数太多,消耗大量内存,触发内存分配异常。在 ps.data_locks 的实现中,内存分配异常是由 C++ try-catch 机制处理的,但是这个异常处理发生在 mutex lock 和 mutex unlock 之间,导致 mutex 不释放。本次故障就是执行 trx_sys_mutex_enter() 后迭代扫描锁记录时发生了内存分配异常,trx_sys_mutex_exit() 释放互斥锁的操作未执行,残留了下来;
  3. 由于 trx_sys->mutex 互斥锁在 InnoDB 中被大量使用,接下来巡检脚本查询 data_lock_waits 被阻塞,后台 purge 线程、innodb monitor 线程、元数据刷新进程、用户线程执行的业务 SQL 都被阻塞,最终会导致死锁。

解决方案

  1. 官方在 8.0.37 中修复了这个 bug,可升级到 8.0.37 解决

    修复方式是在 ps.data_locksdata_lock_waits 的实现中去掉了 try-catch 这段代码,防止发生在 mutex lock 和 mutex unlock 之间处理异常,导致 mutex unlock 无法执行残留 mutex。

  2. 不要在行锁很多的情况下查询 ps.data_locks

爱可生开源社区
426 声望209 粉丝

成立于 2017 年,以开源高质量的运维工具、日常分享技术干货内容、持续的全国性的社区活动为社区己任;目前开源的产品有:SQL审核工具 SQLE,分布式中间件 DBLE、数据传输组件DTLE。