MySQL 遇到的死锁问_一个罕见的MySQL redo死锁问题排查及解决过程
原标题:一个罕见的MySQL redo死锁问题排查及解决过程
作者:张青林,腾讯云布道师、MySQL架构师,隶属腾讯TEG-基础架构部-CDB内核开发团队,专注于MySQL内核研发&相关架构工作,有着服务多个10W级QPS客户的数据库优化及稳定性维护经验。
腾讯云数据库团队:继承腾讯数据库团队十多年海量存储的内部数据库运营和运维经验,推出一系列高性能关系型、分布式、文档型和缓存类数据库产品,并提供高可用性、自动化运维和易维护的云数据库综合解决方案。
问题背景
周一上班,首先向同事了解了一下上周的测试情况,被告知在多实例场景下 MySQL Server hang 住,无法测试下去,原生版本不存在这个问题,而新版本上出现了这个问题,不禁心头一颤,心中不禁感到奇怪,还好现场环境还在,为排查问题提供了一个好的环境,随即便投入到紧张的问题排查过程当中。问题实例表现如下:
并发量为 384 的时候出现的问题;
MySQL服务器无法执行事务相关的语句,即使简单的 select 语句也无法执行;
所有线程处于等待状态,无法 KILL。
现场环境的收集
首先,通过 pstack 工具获取当前问题实例的堆栈信息以便后面具体线程的查找 & 问题线程的定位:
使用 pt-pmp 工具统计 hang.info 中的进程信息,如下:
问题分析
从堆栈上可以看出,有这样几类线程:
等待进入 INNODB engine 层的用户线程,测试环境中 innodb_thread_concurrency=16, 当 INNODB 层中的活跃线程数目大于此值时则需要排队,所以会有大量的排队线程,这个参数的影响&作用本身就是一篇很不错的文章,由于篇幅有限,在此不做扩展,感兴趣者可以参考官方文档:https://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_thread_concurrency;
操作过程中需要写 redo log 的后台线程,主要包括 page cleaner 线程、异步 io threads等;
正在读取Page页面的 purge 线程 & 操作 change buffer 的 master thread;
大量的需要写 redo log 的用户线程。
从以上的分类不难看出,所有需要写 redo log 的线程都在等待 log_sys->mutex,那么这个保护 redo log buffer 的 mutex 被究竟被哪个线程获取了呢,因此,我们可以顺着这个线索进行问题排查,需要解决以下问题:
问题一:哪个线程获取了 log_sys->mutex ?
问题二:获取 log_sys->mutex 的线程为什么没有继续执行下去,是在等其它锁还是其它原因?
问题三:如果不是硬件问题,整个资源竟争的过程是如何的?
1
问题一:由表及里
在查找 log_sys->mutex 所属线程情况时,有两点可以帮助我们快速的定位到这个线程:
由于 log_sys->mutex 同时只能被同一个线程获得,所以在 pt-pmp 的信息输出中就可以排除线程数目大于1的线程;
此线程既然已经获取了 log_sys->mutex, 那就应该还是在写日志的过程中,因此重点可以查看写日志的逻辑,即包括:mtr_log_reserve_and_write 或 log_write_up_to 的堆栈。
顺着上面的思路很快的从 pstack 中找到了以下线程:
这里我们简单介绍一下MySQL写 redo log 的过程(省略undo & buffer pool 部分),当对数据进行修改时,MySQL 会首先对针对操作类型记录不同的 redo 日志,主要过程是:
记录操作前的数据,根据不同的类型生成不同的 redo 日志,redo 的类型可以参考文件:src/storage/innobase/include/mtr0mtr.h
记录操作之后的数据,对于不同的类型会包含不同的内容,具体可以参考函数:recv_parse_or_apply_log_rec_body();
写日志到 redo buffer,并将此次涉及到脏页的数据加入到 buffer_pool 的 flush list 链表中;
根据 innodb_flush_log_at_trx_commit 的值来判断在commit 的时候是否进行 sync 操作。
上面的堆栈则是写Redo后将脏页加到 flush list 过程中时 hang 住了,即此线程在获取了 log_sys->mutex 后,在获取 log_sys->log_flush_order_mutex 的过程中 hang 住了,而此时有大量的线程在等待该线程释放log_sys->mutex锁,问题一 已经有了答案,那么log_sys->log_flush_order_mutex 是个什么东东,它又被哪个占用了呢?
说明:
MySQL 的 buffer pool 维护了一个有序的脏页链表 (flush list according LSN order),这样在做 checkpoint & log_free_check 的过程中可以很快的定位到 redo log 需要推进的位置,在将脏页加入;
flush list过程中需要对其上锁以保证 flush list 中 LSN 的有序性, 但是如果使用 log_sys->mutex,在并发量大的时候则会造成 log_sys->mutex 的 contention,进而引起性能问题,因此添加了另外一个 mutex 来保护脏页按 LSN 的有序性,代码说明如下:
2
问题二:弹尽粮绝
在问题一的排查过程中我们确定了 log_sys->mutex 的所属线程, 这个线程在获得 log_sys->log_flush_order_mutex 的过程中 hang 住了,因此线程堆栈可以分以为下几类:
Thread 446, 获得 log_sys->mutex, 等待获取 log_sys->log_flush_order_mutex 以把脏页加入到 buffer_pool 的 flush list中;
需要获得 log_sys->mutex 以写日志或者读取日志信息的线程;
未知线程获得 log_sys->log_flush_order_mutex,在做其它事情的时候被 hang 住。
因此,问题的关键是找到哪个线程获取了 log_sys->log_flush_order_mutex。
为了找到相关的线程做了以下操作:
查找获取 log_sys->log_flush_order_mutex 的地方;
结合现有 pstack 中的线程信息,仔细查看上述查找结果中的相关代码,发现基本没有线程获得 log_sys->log_flush_order_mutex;
gdb进入 MySQL Server, 将 log_sys->log_flush_order_mutex 打印出来,发现 {waiters=1; lock_word= 0}!!!,即 Thread 446 在等待一个空闲的 mutex,而这个Mutex也确实被等待,由于我们的版本为 Release 版本,所以很多有用的信息没有办法得到,而若用 debug 版本跑则很难重现问题,log_flush_order_mutex 的定义如下:
由以上的分析可以得出 问题二 的答案:
只有两个线程和log_sys->log_flush_order_mutex有关,其中一个是 Thread 446 线程, 另外一个则是最近一次调用 log_flush_order_mutex_exit() 的线程;
现有线程中某个线程在释放log_sys->log_flush_order_mutex的过程中没有唤醒 Thread 446,导致Thread 446 hang 并造成其它线程不能获得 log_sys->mutex,进而造成实例不可用;
log_sys->log_flush_order_mutex没有被任何线程获得。
3
问题三:绝处逢生
由问题二的分析过程可知 log_sys->log_flush_order_mutex 没有被任何线程获得,可是为什么 Thread 446 没有被唤醒呢,信号丢失还是程序问题?如果是信号丢失,为什么可以稳定复现?官方的bug list 列表中是没有类似的 Bug的,搜了一下社区,发现可用信息很少,这个时候分析好像陷入了死胡同,心里压力开始无形中变大……好像没有办法,但是任何问题都是有原因的,找到了原因,也就是有解的了……再一次将注意力移到了 Thread 446 的堆栈中,然后查看了函数:
由问题二的分析过程可以得出某线程在 log_flush_order_mutex_exit 的退出过程没有将 Thread 446 唤醒,那么就顺着这个函数找,看它如何唤醒其它本程的,在没有办法的时候也只有这样一步一步的分析代码,希望有些收获,随着函数调用的不断深入,将目光定在了 mutex_exit_func 上, 函数中的注释引起了我的注意:
从上面的注释中可以得到两点信息:
由于 memory barrier 的存在,mutex_get_waiters & mutex_reset_lock_word 的调用顺序可能与执行顺序相反,这种情况下会引起 hang 问题;
专门写了一个函数 sync_arr_wake_threads_if_sema_free() 来解决上述问题。
由上面的注释可以看到,并不是信号丢失,而是多线程 memory barrier 的存在可能会造成指令执行的顺序的异常,这种问题确定存在,但既然有sync_arr_wake_threads_if_sema_free() 规避这个问题,为什么还会存在 hang 呢?有了这个线索,瞬间感觉有了些盼头……经过查找 sync_arr_wake_threads_if_sema_free 只在 srv_error_monitor_thread 有调用,这个线程是专门对 MySQL 内部异常情况进行监控并打印出 error 信息的线程,臭名昭著的 600S 自杀案也是它的杰作, 那么问题来了:
机器周末都在 hang 着,为什么没有检测到异常并 abort 呢?
既然 sync_arr_wake_threads_if_sema_free 可以唤醒,为什么没有唤醒呢?
顺着这个思路,查看了pstack 中 srv_error_monitor_thread 的堆栈,可以发现此线程在获取 log_sys->mutex 的时候hang 住了,因此无法执行sync_arr_wake_threads_if_sema_free() & 常归的异常检查,正好回答了上面的问题,详细堆栈如下:
经过上面的分析问题越来越明朗了,过程可以简单的归结为:
Thread 446获得 log_sys->mutex, 但是在等待 log_sys->log_flush_order_mutex 的过程中没有被唤醒;
Thread XXX在释放 log_sys->log_flush_order_mutex 的过程中出现了 memory barrier 问题,没有唤醒 Thread 446;
Thread 470获得 log_sys->mutex 时被 hang 住,导致无法执行 sync_arr_wake_threads_if_sema_free(), 导致了整个实例的 hang 住;
Thread 470需要获得 Thread 446 的 log_sys->mutex, 而 Thread 446 需要被 Thread 470 唤醒才会释放 log_sys->mutex;
结合 log_sys->log_flush_order_mutex 的状态信息,实例 hang 住的整个过程如下:
关于 Memory barrier 的介绍可以参考 :https://en.wikipedia.org/wiki/Memory_barrier
http://name5566.com/4535.html
问题解决
既然知道了问题产生的原因,那么问题也就可以顺利解决了,有两种方法:
直接移除 log_get_lsn 在此处的判断,本身就是开发人员加的一些判断信息,为了定位 LSN 的异常而写的,用到的时候也Crash了,用处不大;
保留判断,将 log_get_lsn 修改为 log_peek_lsn, 后者会首先进行 try_lock,当发现上锁失败的时候会直接返回,而不进行判断,这种方法较优雅些;
经过修改之后的版本在测试过程中没有没有再复现此问题。
问题扩展
虽然问题解决了,但官方版本中肯定存在着这个问题,为什么 buglist 没有找到相关信息呢,于是在查看了最新代码,发现这个问题已经修复,修复方法为上面列的第二种方法,详细的 commit message 信息如下:
bug影响范围:MySQL 5.6.28 及之前的版本都有此问题。
相关专题:
精选专题(官网:dbaplus.cn)
◆近期热文 ◆
◆专家专栏 ◆
丨丨丨丨丨
丨丨丨丨丨丨
◆近期活动 ◆
Gdevops全球敏捷运维峰会上海站
峰会官网:www.gdevops.com
责任编辑:
MySQL 遇到的死锁问_一个罕见的MySQL redo死锁问题排查及解决过程相关推荐
- linux mysql 死锁进程_一个罕见的MySQL redo死锁问题排查及解决过程
作者:张青林,腾讯云布道师.MySQL架构师,隶属腾讯TEG-基础架构部-CDB内核开发团队,专注于MySQL内核研发&相关架构工作,有着服务多个10W级QPS客户的数据库优化及稳定性维护经验 ...
- mysql面向用户是什么意思_原来大厂的MySQL面试会问这些问题!
1. 写出下面 2 个 PHP 操作 Mysql 函数的作用和区别(新浪网技术部) mysql_num_rows() mysql_affected_rows() 这两个函数都作用于 mysql_que ...
- mysql建立数据浏览器_一个简单的MySQL数据浏览器
一个简单的MySQL数据浏览器 2021-01-21 16:17:28679 这个程序可以用来浏览MySQL中的数据,您可以稍做修改就可以做出很不错的MySQL浏览器. */ /* ?cmd=db ? ...
- MySQL 读写分离 部分_一个完整的mysql读写分离环境包括以下几个部分
一个完整的mysql读写分离环境包括以下几个部分: ?应用程序client ?database proxy ?database集群 在本次实战中,应用程序client基于c3p0连接后端的databa ...
- mysql浏览器_一个简单的MySQL数据浏览器
一个简单的MySQL数据浏览器 更新时间:2006年10月09日 00:00:00 作者: 这个程序可以用来浏览MySQL中的数据,您可以稍做修改就可以做出很不错的MySQL浏览器. */ /* ...
- mysql建立数据浏览器_一个简单的MySQL数据浏览器_php
这个程序可以用来浏览mysql中的数据,您可以稍做修改就可以做出很不错的MySQL浏览器. */ /* ?cmd=db ?cmd=table&db={} http://www.gaodaima ...
- mysql基于binlog增量更新_一个应用它提取MySQL binlog,解析binlog并将增量更新数据推送到不同的接收器...
DolphinBeat Other languages: 中文 This is a high available server that pulls MySQL binlog, parses binl ...
- mysql避免回环复制_【20181204】 MySQL 双主复制是如何避免回环复制的
想要了解这个问题的原因在于有一次面试的时候,面试官问我一个问题,就是MySQL的双主复制的时候是如何避免回环复制这个问题的,说老实话在基于GTID复制的时候我还是比较了解的,因为GTID复制是MySQ ...
- mysql安装check requirements出错_精心整理的mysql主从监控脚本,值得收藏
概述 分享下最近整理的一个mysql主从监控脚本,仅供参考. 一.邮件配置 1.安装邮件服务 yum -y install sendmail mailx 2.修改配置 # vi /etc/mail.r ...
最新文章
- 【每日DP】day7P1064 金明的预算方案 (分组背包,我又悟了)难度⭐⭐★
- 【CURL】模拟登录网站并获取用户信息
- jQuery 属性选择器
- ejb运行程序_在哪里可以运行EJB?
- [Big Data - Kafka] Kafka设计解析(四):Kafka Consumer解析
- 20个MySQL运维案例,请查收!
- python max函数key_Python标准库:内置函数max(iterable, *[, key, default]) | 学步园
- 机器学习基础(三十六)—— 非规整数据(值缺失、异常值)的处理
- XP系统下如何把FAT32转换成NTFS格式的?
- xcode经验汇总(持续更新中)
- 《凤凰项目:一个IT运维的传奇故事》的读后感
- 安装emmet时pyv8下载失败
- Postgresql13之FETCH FIRST ROWS … WITH TIES展示打结的行
- 习题 3.6 请编程序将China译成密码,密码规律是:用原来的字母后面第4个字母代替原来的字母。
- matlab dx dy dt,y/(y^2+1)dy=dx/(x^2-1)
- kvm介绍、kvm存储池、kvm快照和克隆、kvm虚拟机基本管理和网络管理
- Linux磁盘监控工具说明
- VS2012序列号,激活码,【旗舰版】
- python3小项目——爬取招聘信息(智联招聘)
- 岁月的剪影【八月硝烟四起】