内核futex的BUG导致程序hang死问题排查
https://mp.weixin.qq.com/s/sGS-Kw18sDnGEMfQrbPbVw
内核futex的BUG导致程序hang死问题排查
近日,Hadoop的同学反映,新上的几台机器上的java程序出现hang死的现象,查看系统的message记录,发现一些内存方面的错误输出,怀疑是内存不足导致java程序hang死在gc的过程中。经排查发现即使是在内存充足的情况下也会出现程序hang死的现象。
我们又发现只有这批新上的机器才出现hang死的问题,之前老机器上一直很正常。排查后发现在老机器上有一个监控脚本,每隔一段时间就会用jstack查看一下java程序的状态。关了监控脚本后,老机器也出现了hang死的问题。最后我们发现使用jstack、pstack都可以将原来hang死的程序刷活。
后来DBA的同学也反映,他们的xtrabackup程序也出现了hang死的问题,最后我们使用GDB对这个备份程序分析后发现,问题的原因出现在内核的一个BUG上。
结论
出现问题的机器上的Linux内核都是linux 2.6.32-504版本,这个版本存在一个futex的BUG。
参见:
https://github.com/torvalds/linux/commit/76835b0ebf8a7fe85beb03c75121419a7dec52f0
这个BUG会导致非共享锁的程序体会陷入无人唤醒的等待状态,造成程序hang死。
触发这个BUG需要具备以下几个条件:
• 内核是2.6.32-504.23.4以下的版本
• 程序体需要使用非共享锁的锁竞争
• CPU需要有多核,且需要有CPU缓存
满足以上条件就有概率触发这个程序hang死的BUG。
解决方案就是升级到 2.6.32-504.23.4或更高版本来修复此BUG。
下面我们来看一下,是如何断定问题是由这个BUG引起的。
原理分析
1. 首先要拿到进程ID
我们要分析的xtrabackup程序的PID是715765
2. 看一下内核调用栈
cat /proc/715765/*/task/stack
发现大多数线程在停在 futex_wait_queue_me 这个内核函数中。
这个函数使当前线程主动释放CPU进入等待状态,若没有被唤醒,就一直停在这个函数中。
也就是说,现在大多数线程都在等其他资源释放锁,下面我们就需要到用户态下分析,他们到底在等待什么锁。
3. 分析用户态代码
gdb attach 715765
对于这种程序hang死的问题,最好的工具还是gdb,附加到程序上,来获取的实时状态信息。
3.1 查看线程信息
首先先看一下在用户态中线程的状态。
可以看到线程大体有两类等待, pthread_cond_wait 和 __lll_lock_wait。
pthread_cond_wait是线程在等待一个条件成立,这个条件一般由另一个线程设置;
__lll_lock_wait是线程在等另一个线程释放锁,一般是抢占锁失败,在等其他线程释放这个锁。
3.2 查看每个线程信息
看到大体有三类线程:
• 拷贝线程:data_copy_thread_func
• 压缩线程:compress_wokrer_thread_func
• IO线程:io_handler_thread
为了弄明白这些线程的作用,我们可以先了解下xtrabackup的工作原理。
3.3 工作原理说明
mysql数据库备份中的一个工作就是将数据库文件拷贝,为节省空间,可以通过参数来设置开启压缩。
在做实际分析前,我们先梳理一遍启用压缩后,拷贝线程的业务逻辑:
• 拷贝线程会把文件分成多个小块,喂给压缩线程
• 在喂之前,需要通过一个控制锁来获取这个压缩线程的控制权
• 喂完后,会发送一个条件信号来通知压缩线程干活
• 然后就依次等每个压缩线程将活干完
• 每等到一个压缩线程干完活,就将数据写到文件中,然后释放这个压缩线程控制锁
下面我们看一个具体的拷贝线程,我们从第1个拷贝线程开始,也就是2#线程。
3.4 拷贝线程2# 锁分析
拷贝线程2# hang死的位置 是 在给第1个压缩线程发送数据前,加ctrl_mutex锁的地方
它在等其owner 715800 释放,而715800 对应的是7#线程
3.5 拷贝线程 7# 锁分析
我们看到7# 线程hang死的位置与2号线程是相同,不同的是 它是卡在第3个压缩线程上,且其ctrl_mutex的owner为空。也就是说没有与其竞争的线程,它自己就一直在这等。
虽然这个现象很奇怪,但可以确定这不是死锁问题导致的。一般来讲只能是内核在释放锁时出现问题才会出现这种空等的情况。
为了更完整的还原出当时的场景,我们需要分析一下到底都有谁有可能释放压缩线程的控制锁。
3.6 拷贝线程控制锁怎么释放
ctrl_mutex对应的是压缩线程一个控制锁,拥有这个锁才能对压缩线程做相应的操作
在xtrabackup中,大体有四个地方释放这个锁:
1. 创建压缩线程时,会初始化这个锁,并通过这个锁启动线程进入主循环
2. 压缩线程在运行时, 会使用这个锁设置启动状态(与上面的创建线程对应)
3. 拷贝线程会在往压缩线程放原始数据时,把持这个锁,在从压缩线程拿完数据后,释放对应锁
4. 销毁压缩线程后,会释放上面相关的锁
查看日志我们看到,日志是停在一个压缩文件的过程中,且上面完成了多次文件的压缩操作;
所以,可以排除上面的1、2、4这三种情况;
那么我们可以再做出下面的假设:
前面有一个拷贝线程,取完了几个压缩线程的压缩结果,释放了这几个压缩线程;
这时,7#拷贝线程正好拿到了1、2两个压缩线程的控制锁,往里放完数据后,开始要拿第3个压缩线程的控制锁;
这时前一个拷贝线程并没有释放,于是7#只好在加锁处等待;
但当前一个拷贝线程释放第3个压缩线程锁的时候,内核并没有通知到7#线程,造成其一直在等待。
而7#线程等待的过程中,也不会释放其他已把持的压缩线程的锁,造成其他拷贝线程一直等待其释放,最后导致整个进程夯死。
到此我们大概还原了程序hang死的场景,目前来讲嫌疑最大的就是内核出现了问题,而当前内核版本正好有一个futex的BUG,我们来具体看一下这个BUG是否是导致程序hang死的元凶。
4. 内核的futex的BUG分析
先看一下内核futex中的这个BUG,其实很简单,就是少加了两行代码;严格点说是在非共享锁分支上少加了一个mb。
mb又是什么呢?mb的作用将上下两部分代码做一个严格的分离,一般叫屏障,主要有两种屏障:
• 优化屏障:当gcc编译器从O2级别的优化开始就会对指令进行重排,而mb会在其宏上加一个volatile关键字来告诉编译器禁止与其他指令重排。
• 内存屏障:现在CPU通常是并行的执行若干条指令,具可能重新安排内存访问的次序,这种重排或乱序可以极大地加速程序运行,但也会导致一些需要数据同步的场景导致读到脏数据。而mb会使用mfence汇编指令告诉CPU,必须要把前面的指令执行完,才能执行其下面的指令,保证操作同步。
那不加这个mb 会造成什么实际影响呢?我们来看futex_wake函数的代码:
futex_wake函数中会查看hb变量里有没有需要被唤醒的锁,如果没有就不做唤醒操作。
若没加 mb,将导致其获取的数据不一致,有机率将实际有锁在等待而误当成没锁在等待,造成该唤醒的锁,错失唯一一次被唤醒的机会,导致其一直处在等待状态,最终导致程序夯死!
下面我们要确定一件事情就是,当前程序是否命中了这个BUG,也就是说当前锁是否是非共享锁。我们查看pthread的代码,可以看到__kind的值决定了其传给内核的锁是共享还是非共享的。
通过gdb可以看到,__kind的值为0,一定是非共享锁;
通过上面的分析,我们基本可以得出是内核BUG导致xtracbackup程序的hang死。
最后我们将内核升到了2.6.32-504.23.4,发现xtrabackup程序能正常运行,然后我们对hadoop服务器内核也做了升级,发现hang死问题也解决了。
结语
通过上面的分析过程,我们可以发现gdb对这种需要实时分析的问题场景特别契合,但一般用来调度用户态的代码,内核态的相关信息可能用systemtap等工具更方便一些。
此外,还有一个问题令人困惑,就是为什么使用pstack、jstack、gdb或SIGSTP+SIGCON信号能唤醒hang死的程序?
这里要说明的一点就是jstack、gdb、pstack的原理都是通过内核的SIGTRAP等一系列调试信号来,抓取信息或调试程序的;
所以,这个问题的本质是为什么信号能唤醒程序?
我们看到出现这种夯死现象的程序,大多线程都会停在 内核的 futex_wait_queue_me 这个函数处;而这个函数,使用 TASK_INTERRUPTIBLE 来设置自己的状态,表示自己主动想放弃CPU,但可以被中断、信号或其他程序唤醒;并在下面调用 schedule 内核调度方法,主动通知内核放弃自己的CPU。
所以,我们从外界最简单的就是通过向其发送信号,来唤醒那些可能永远等待的线程,让程序跑起来。