[[388316]]

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

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

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

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

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

分析問題

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

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

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

strace 命令就用來告訴你這個的，運行 strace 命令來查看一下此時進程調(diào)用了什么系統(tǒng)調(diào)用：

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

跟蹤進程用戶態(tài)運行時棧

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

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

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

古老的ps命令永不過時

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

WCHAN 是什么意思呢？

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

$ man ps 

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

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

OK，我們來運行一下 ps 命令：

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

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

從ps打印的結(jié)果可以看出，該進程運行狀態(tài)是D，運行狀態(tài)D表示什么意思呢？我們再次請教man，發(fā)現(xiàn)了這樣的信息：

原來進程運行狀態(tài)D表示 uninterruptible sleep，不可被打斷的 sleep，意思是說該進程正在睡覺，就算你拍它一巴掌也不會醒，即該進程當前不響應(yīng)任何外部信號，此時哪怕 kill 命令都殺不掉該進程(除非內(nèi)核允許該進程接收 kill 信號)，直觀感受就是該進程被“卡死”了。

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

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

那么進程被卡死在了哪里呢？

幸運的是 WCHAN 這一列可以告訴你答案。

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

上面的ps命令 WCHAN 這一列顯示的是 rpc_wa，嗯。。rpc_wa 什么呢？看上去是被截斷了，不過沒關(guān)系，我們可以從源頭上找到 wchan 的完整輸出，實際上ps等命令也是在這個源頭上查找信息并展示出來的，這個源頭就是 proc 文件系統(tǒng)，proc 文件系統(tǒng)記錄了內(nèi)核以及各個進程的運行時信息，我們可以使用最簡單的 cat 命令，使用 proc 后跟進程ID以及wchan：

啊哈，我們終于找到進程此時到底卡死在哪里了！

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

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

柳暗花明

讓我們再仔細想一想。

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

那么我們該怎樣知道某個進程當前正在調(diào)用哪個系統(tǒng)調(diào)用呢？

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

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

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

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

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

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

Gotyou！！！我們可以看到調(diào)用了 newfstatat 系統(tǒng)調(diào)用，這個系統(tǒng)調(diào)用有什么作用呢？讓我們再一次問男人(man命令)： 

$ man newfstatat 

得到了這樣的信息：

啊哈！原來是fstatat，這是在讀取文件的元信息。

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

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

跟蹤內(nèi)核運行時棧

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

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

真相大白

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

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

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

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

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

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