一个罕见的MySQL redo死锁问题排查及解决过程(2)

这里我们简单介绍一下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 的有序性,代码说明如下：

在问题一的排查过程中我们确定了 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 没有被任何线程获得.

由问题二的分析过程可知 log_sys->log_flush_order_mutex 没有被任何线程获得,可是为什么 Thread 446 没有被唤醒呢,信号丢失还是程序问题?如果是信号丢失,为什么可以稳定复现?官方的bug list 列表中是没有类似的 Bug的,搜了一下社区,发现可用信息很少,这个时候分析好像陷入了死胡同,心里压力开始无形中变大……好像没有办法,但是任何问题都是有原因的,找到了原因,也就是有解的了……再一次将注意力移到了 Thread 446 的堆栈中,然后查看了函数：

（编辑：ASP站长网）