一个典型kernel bug的追踪之（一）：出错现场分析

昨天偶尔在跑测试的时候发现uksmd的一个极其罕见出现的bug（在一个很难进入的路径上，很久很久没有碰到类似的问题了），本质上属于一个soft lockup的bug。所谓，soft lockup就是说，这个bug没有让系统彻底死机，但是若干个进程（或者kernel thread）被锁死在了某个状态（一般在内核区域）。很多情况下这个是由于内核锁的使用的问题。本系列新手教程帖子，教大家如何查看内核出错信息。

而本帖主要是教大家如何分析错误现场（当然了，你要结合代码）

我们先来看一下这次错误的dmesg输出：





我们可以看到内核提示“task uksmd:81 blocked for more than 120 seconds.”，这告诉我们，uksmd这个进程停止在某处很久了。然后内核打印了这个进程的栈和Call Trace（也就是函数调用嵌套情况），我们重点关注的是Call Trace:。

每个Call Trace的格式是由两部分组成：[<压入栈的地址>] 所在函数名称
其中这个地址是当前函数调用的ret地址，或者换句话说，是这个call指令的下一条（这里看不懂的回去好好复习复习C调用规范和汇编http://cache.soso.com/img/img/e144.gifbug的追踪之（一）【转】" />），而函数名之前可能有 “？”这样一个符号，这个符号告诉我们，这个不是严格的调用框架上的节点，而是栈里面残存的（没有被后来调用的栈框架洗刷掉）一些调用轨迹。这个往往是说明到目前位置，曾经调用过的一些函数路径。

好，我们看一下着重关注的uksmd的情况



从上面的轨迹，我们不难看到，这次锁死是出现在一个page lock上，想象一下，这样的情形可能的情况：

•     有一个进程已经获得了这个page lock，而和uksmd互相dead lock在另一个锁上
  

•     有进程忘记释放page lock了，很有可能是错误的进程自己，这里罪魁祸首最大可能性就是uksmd自己
  

为了进一步缩小范围，我们接下来分析日志其它部分：
我们发现同时锁死的有khugepaged， 和 zeusmp_base.amd，后面这个进程是我们benchmark进程，在用户层，所以一般是无辜的。而khugepaged同样是一个页表操纵进程（将碎页合并成大页面），所以首先怀疑是它们两者的dead lock，我们接着看khugepaged的call trace:

很明显，锁在一个信号量(semaphore)上，那么这个具体是哪个呢？其实也很明显：mmap_sem是最大的可能性。因为在合并大页面之前，mmap_sem是要加锁，这个很容易想象（其实具体在collapse_huge_page函数里面），而uksmd显然在合并页面的时候也加了这个锁，所以，不难看出khugepaged其实锁在 uksmd正在工作的mmap_sem上。这个根本原因还是uksmd死锁导致的，而不是它们之间的互相 dead lock。

接下来看zeusmp_base.amd被锁死的场景，也是同一个：mmap_sem，所以不难的出这个现场的基本猜测：
uksmd自己有某个页面没有释放锁，而下一次扫描的时候，堵在了自己加的page lock上，而由于它被锁死，没有释放mmap_sem，所以khugepaged在扫描zeusmp_base.amd内存区域的时候被锁死了，而接着zeusmp_base.amd由于page fault同样要mmap_sem加读锁，被堵在khugepaged的写锁操作上。

现场分析到此结束，看明白了嘛？

下回分析，如何定位具体哪里错了！
有想法的同学可以先行查看一下uksmd的代码（目前补丁还没有合并到git head上），回帖分析。
回头我揭晓。http://cache.soso.com/img/img/e113.gifbug的追踪之（一）【转】" />

（啊，忘了说明一下了，这个错误是在 0.1.0的补丁中的（在下载区有补丁下载），
目前在 2.6.38头上的其实是为 0.1.1做准备，最近在和内核的 stable 各个branch做融合，
这个错误，在0.1.1中已经不经意的被修正了，呵呵。）