[[388316]]

那些編程高手除了寫(xiě)代碼很厲害之外，調(diào)試代碼找 bug 更是手到擒來(lái)。

編寫(xiě)代碼只是程序員的工作之一，調(diào)試代碼的時(shí)間甚至?xí)^(guò)編寫(xiě)代碼，之前為大家講解了很多關(guān)于系統(tǒng)、架構(gòu)、編程等方面的內(nèi)容，這篇文章就為大家全方位展示一次涉及到內(nèi)核的 bug 排查過(guò)程。

發(fā)現(xiàn)問(wèn)題

話說(shuō)一天公司服務(wù)器報(bào)警，登錄到機(jī)器后發(fā)現(xiàn)進(jìn)程已被“卡死”，常規(guī) GDB 調(diào)試沒(méi)有反應(yīng)，查找 Log 也沒(méi)有線索，問(wèn)題似乎已經(jīng)無(wú)解。

就在這時(shí)博主的腦海里浮現(xiàn)出了島國(guó)的。。是的，你猜錯(cuò)了，是島國(guó)的一休哥、柯南弟、國(guó)內(nèi)的包青天、狄仁杰、國(guó)外的夏洛克等一眾大佬，瞬間有如神助，一定還有辦法！是的！

分析問(wèn)題

先來(lái)仔細(xì)分析一下，既然進(jìn)程看上去被卡死，那么如果被卡在用戶態(tài)，那么該進(jìn)程 CPU 使用率必然很高（死循環(huán)之類）；如果被卡在內(nèi)核態(tài)，這時(shí)進(jìn)程應(yīng)該正在進(jìn)行 IO 或者網(wǎng)絡(luò)通信等，那么 CPU 使用率應(yīng)該會(huì)很低，現(xiàn)在還能查到進(jìn)程ID，有了進(jìn)程ID運(yùn)行 top 命令看一下：

注意 CPU 那一列，顯示 CPU 占用率為0%，我們發(fā)現(xiàn)此時(shí)該進(jìn)程幾乎沒(méi)有占用CPU，這基本上是在告訴我們?cè)撨M(jìn)程是被卡死在內(nèi)核態(tài)，進(jìn)程要進(jìn)入內(nèi)核態(tài)那么就是因?yàn)檎{(diào)用了某個(gè)阻塞式系統(tǒng)調(diào)用導(dǎo)致被操作系統(tǒng)掛起，那么該怎么知道進(jìn)程調(diào)用了什么系統(tǒng)調(diào)用呢？

跟蹤進(jìn)程系統(tǒng)調(diào)用

strace 命令就用來(lái)告訴你這個(gè)的，運(yùn)行 strace 命令來(lái)查看一下此時(shí)進(jìn)程調(diào)用了什么系統(tǒng)調(diào)用：

Oops！strace 命令也被卡死了，無(wú)奈，再想想還有其它什么辦法。。

跟蹤進(jìn)程用戶態(tài)運(yùn)行時(shí)棧

有了，可以用 pstack 命令，該命令能打印出進(jìn)程運(yùn)行時(shí)棧信息，雖然該命令不能追蹤到內(nèi)核，但是可以看到用戶態(tài)最終調(diào)用了什么函數(shù)，從而推斷出調(diào)用了什么系統(tǒng)調(diào)用，讓我們來(lái)運(yùn)行一下：

和strace一樣，pstack 也被卡死了。

現(xiàn)在我們還能去哪里找線索呢？

古老的ps命令永不過(guò)時(shí)

我們可以利用 ps 命令來(lái)查看進(jìn)程的運(yùn)行狀態(tài)和 WCHAN(waiting channel)。

WCHAN 是什么意思呢？

在 Linux 世界，有問(wèn)題問(wèn)男人（man），這就是萬(wàn)能的 man 命令，我們使用 man 命令來(lái)看一下 ps 展示內(nèi)容的含義： 

$ man ps 

運(yùn)行 man 命令并搜索“WCHAN”，啊哈！最終在“STANDARD FORMAT SPECIFIERS”這一部分中找到了 WCHAN 的含義，是這樣寫(xiě)的：

這里清楚的寫(xiě)著 WCHAN 指的是當(dāng)前進(jìn)程正阻塞在哪個(gè)內(nèi)核函數(shù)上。

OK，我們來(lái)運(yùn)行一下 ps 命令：

這里值得注意的是，因?yàn)?ps 打印的只是運(yùn)行ps命令這一時(shí)刻相應(yīng)進(jìn)程的狀態(tài)，也就是說(shuō)運(yùn)行一次 ps 相當(dāng)于一次采樣，因此你應(yīng)該多運(yùn)行幾次ps，確保運(yùn)行結(jié)果沒(méi)有變化，否則只運(yùn)行一次并且時(shí)間足夠巧那么有可能會(huì)獲得到一個(gè)錯(cuò)誤的線索。

兩種進(jìn)程阻塞狀態(tài)

從ps打印的結(jié)果可以看出，該進(jìn)程運(yùn)行狀態(tài)是D，運(yùn)行狀態(tài)D表示什么意思呢？我們?cè)俅握?qǐng)教man，發(fā)現(xiàn)了這樣的信息：

原來(lái)進(jìn)程運(yùn)行狀態(tài)D表示 uninterruptible sleep，不可被打斷的 sleep，意思是說(shuō)該進(jìn)程正在睡覺(jué)，就算你拍它一巴掌也不會(huì)醒，即該進(jìn)程當(dāng)前不響應(yīng)任何外部信號(hào)，此時(shí)哪怕 kill 命令都?xì)⒉坏粼撨M(jìn)程(除非內(nèi)核允許該進(jìn)程接收 kill 信號(hào))，直觀感受就是該進(jìn)程被“卡死”了。

與不可被打斷的 sleep 相對(duì)于的是可被打斷 sleep，從上圖看狀態(tài)為S，此時(shí)進(jìn)程正在阻塞等待某個(gè)事件(比如網(wǎng)絡(luò)數(shù)據(jù)到來(lái)等等)，處于該狀態(tài)的進(jìn)程可以接收信號(hào)，直觀感受就是該進(jìn)程還有反應(yīng)。

通過(guò)ps命令我們可以看到進(jìn)程狀態(tài)為D，進(jìn)一步驗(yàn)證了進(jìn)程確實(shí)被“卡死”了。

那么進(jìn)程被卡死在了哪里呢？

幸運(yùn)的是 WCHAN 這一列可以告訴你答案。

進(jìn)程阻塞在哪個(gè)內(nèi)核函數(shù)上

上面的ps命令 WCHAN 這一列顯示的是 rpc_wa，嗯。。rpc_wa 什么呢？看上去是被截?cái)嗔耍贿^(guò)沒(méi)關(guān)系，我們可以從源頭上找到 wchan 的完整輸出，實(shí)際上ps等命令也是在這個(gè)源頭上查找信息并展示出來(lái)的，這個(gè)源頭就是 proc 文件系統(tǒng)，proc 文件系統(tǒng)記錄了內(nèi)核以及各個(gè)進(jìn)程的運(yùn)行時(shí)信息，我們可以使用最簡(jiǎn)單的 cat 命令，使用 proc 后跟進(jìn)程ID以及wchan：

啊哈，我們終于找到進(jìn)程此時(shí)到底卡死在哪里了！

看起來(lái)該進(jìn)程正在等待一個(gè) RPC 調(diào)用，RPC 實(shí)際上就是一個(gè)進(jìn)程正在和另一個(gè)進(jìn)程網(wǎng)絡(luò)通信，盡管我們知道了進(jìn)程被卡死在了哪里，但是我們依然不知道為什么會(huì)被卡死在這里。

至此線索似乎中斷了。。。

柳暗花明

讓我們?cè)僮屑?xì)想一想。

既然進(jìn)程被卡死了，那么此時(shí)進(jìn)程必然沒(méi)有位于用戶態(tài)，不是用戶態(tài)就肯定是內(nèi)核態(tài)，那么進(jìn)程怎樣才能進(jìn)入內(nèi)核態(tài)呢？答案很顯然是調(diào)用了某個(gè)系統(tǒng)調(diào)用。

那么我們?cè)撛鯓又滥硞€(gè)進(jìn)程當(dāng)前正在調(diào)用哪個(gè)系統(tǒng)調(diào)用呢？

You are lucky dog，Say hi to /proc/***/syscall，我們同樣可以用簡(jiǎn)單的 cat 命令去 proc 文件系統(tǒng)中查找，使用/proc后跟進(jìn)程ID+syscall即可。

WTF。。。這是一串什么鬼東西！

原來(lái)這一串看起來(lái)不知所云的東西正是系統(tǒng)調(diào)用，第一個(gè)數(shù)字代表系統(tǒng)調(diào)用 ID，后面一堆是參數(shù)，我們可以不用關(guān)心。

從上面的輸出我們可以看到調(diào)用的是第 262 號(hào)系統(tǒng)調(diào)用，只有一個(gè)數(shù)字是沒(méi)什么意義的，這個(gè)數(shù)字到底代表那個(gè)系統(tǒng)調(diào)用呢？

根據(jù)內(nèi)核源碼查系統(tǒng)調(diào)用

要知道這個(gè)數(shù)字的含義，我們就需要參考內(nèi)核代碼了，一般在 Linux 系統(tǒng)中必要的內(nèi)核頭文件位于/usr/include目錄，在博主 64 位 Linux 機(jī)器上，我找到了這個(gè)文件：

Gotyou?。。∥覀兛梢钥吹秸{(diào)用了 newfstatat 系統(tǒng)調(diào)用，這個(gè)系統(tǒng)調(diào)用有什么作用呢？讓我們?cè)僖淮螁?wèn)男人(man命令)： 

$ man newfstatat 

得到了這樣的信息：

啊哈！原來(lái)是fstatat，這是在讀取文件的元信息。

現(xiàn)在我們已經(jīng)知道了調(diào)用什么系統(tǒng)調(diào)用，可是一個(gè)新的問(wèn)題再次出現(xiàn)，那就是我們?yōu)槭裁凑{(diào)用這個(gè)系統(tǒng)調(diào)用后最終會(huì)因?yàn)榈却粋€(gè) rpc 被卡死呢？

顯然我們需要調(diào)用棧信息來(lái)驗(yàn)證。

跟蹤內(nèi)核運(yùn)行時(shí)棧

OOOOKey，是時(shí)候請(qǐng)出重量級(jí)工具了，這就是/proc/PID/stack，通過(guò)簡(jiǎn)單的查看這個(gè)文件我們就能知道相應(yīng)進(jìn)程在內(nèi)核中的調(diào)用棧?。?！就問(wèn)你 Linux 這種設(shè)計(jì)有沒(méi)有很厲害，有沒(méi)有?。?！

這個(gè)內(nèi)核調(diào)用棧最終揭開(kāi)了所有秘密。

真相大白

首先我們來(lái)看調(diào)用棧的棧頂，棧頂正是 ps 命令 WCHAN 那一列打印出來(lái)的，進(jìn)程在內(nèi)核中正是因?yàn)檎{(diào)用這個(gè)函數(shù)被卡死的。

接下來(lái)我們從調(diào)用棧的最底層看，我們發(fā)現(xiàn)了系統(tǒng)調(diào)用，印證了正是進(jìn)程調(diào)用這個(gè)系統(tǒng)調(diào)用而導(dǎo)致卡住的。

那么調(diào)用這個(gè)系統(tǒng)調(diào)用發(fā)生了什么呢？我們接著往上看，注意這幾行：

Finally?。?！從調(diào)用棧中我們看到了一系列 NFS 相關(guān)的函數(shù)，NFS全稱Network File System，也就是網(wǎng)絡(luò)文件系統(tǒng)，我們平時(shí)掛載(mount)一個(gè)遠(yuǎn)程文件系統(tǒng)就是NFS來(lái)實(shí)現(xiàn)的，正是 NFS 進(jìn)行網(wǎng)絡(luò)通信才導(dǎo)致在 rpc 上等待，

從內(nèi)核調(diào)用棧我們知道，進(jìn)程在查詢某個(gè)遠(yuǎn)程主機(jī)上文件的元數(shù)據(jù)時(shí)因網(wǎng)絡(luò)問(wèn)題導(dǎo)致被卡死。

通過(guò)這一線索我們最終鎖定了出現(xiàn)問(wèn)題的代碼。