[[384122]]

那些編程高手除了寫代碼很厲害之外，調試代碼找 bug 更是手到擒來。編寫代碼只是程序員的工作之一，調試代碼的時間甚至會超過編寫代碼，之前為大家講解了很多關于系統、架構、編程等方面的內容，這篇文章就為大家全方位展示一次涉及到內核的 bug 排查過程。

發現問題

話說一天公司服務器報警，登錄到機器后發現進程已被“卡死”，常規 GDB 調試沒有反應，查找 Log 也沒有線索，問題似乎已經無解。就在這時博主的腦海里浮現出了島國的。。是的，你猜錯了，是島國的一休哥、柯南弟、國內的包青天、狄仁杰、國外的夏洛克等一眾大佬，瞬間有如神助，一定還有辦法!是的!

分析問題

先來仔細分析一下，既然進程看上去被卡死，那么如果被卡在用戶態，那么該進程 CPU 使用率必然很高(死循環之類);如果被卡在內核態，這時進程應該正在進行 IO 或者網絡通信等，那么 CPU 使用率應該會很低，現在還能查到進程ID，有了進程ID運行 top 命令看一下：

注意 CPU 那一列，顯示 CPU 占用率為0%，我們發現此時該進程幾乎沒有占用CPU，這基本上是在告訴我們該進程是被卡死在內核態，進程要進入內核態那么就是因為調用了某個阻塞式系統調用導致被操作系統掛起，那么該怎么知道進程調用了什么系統調用呢? 

跟蹤進程系統調用

strace 命令就用來告訴你這個的，運行 strace 命令來查看一下此時進程調用了什么系統調用：

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

跟蹤進程用戶態運行時棧

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

和strace一樣，pstack 也被卡死了。現在我們還能去哪里找線索呢? 

古老的ps命令永不過時

我們可以利用 ps 命令來查看進程的運行狀態和 WCHAN(waiting channel)。WCHAN 是什么意思呢?在 Linux 世界，有問題問男人(man)，這就是萬能的 man 命令，我們使用 man 命令來看一下 ps 展示內容的含義：

$ man ps 

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

這里清楚的寫著 WCHAN 指的是當前進程正阻塞在哪個內核函數上。OK，我們來運行一下 ps 命令：

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

兩種進程阻塞狀態

從ps打印的結果可以看出，該進程運行狀態是D，運行狀態D表示什么意思呢?我們再次請教man，發現了這樣的信息：

原來進程運行狀態D表示 uninterruptible sleep，不可被打斷的 sleep，意思是說該進程正在睡覺，就算你拍它一巴掌也不會醒，即該進程當前不響應任何外部信號，此時哪怕 kill 命令都殺不掉該進程(除非內核允許該進程接收 kill 信號)，直觀感受就是該進程被“卡死”了。與不可被打斷的 sleep 相對于的是可被打斷 sleep，從上圖看狀態為S，此時進程正在阻塞等待某個事件(比如網絡數據到來等等)，處于該狀態的進程可以接收信號，直觀感受就是該進程還有反應。通過ps命令我們可以看到進程狀態為D，進一步驗證了進程確實被“卡死”了。那么進程被卡死在了哪里呢?幸運的是 WCHAN 這一列可以告訴你答案。 

進程阻塞在哪個內核函數上

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

啊哈，我們終于找到進程此時到底卡死在哪里了!看起來該進程正在等待一個 RPC 調用，RPC 實際上就是一個進程正在和另一個進程網絡通信，盡管我們知道了進程被卡死在了哪里，但是我們依然不知道為什么會被卡死在這里。至此線索似乎中斷了。。。 

柳暗花明

讓我們再仔細想一想。

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

那么我們該怎樣知道某個進程當前正在調用哪個系統調用呢？

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

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

原來這一串看起來不知所云的東西正是系統調用，第一個數字代表系統調用 ID，后面一堆是參數，我們可以不用關心。從上面的輸出我們可以看到調用的是第 262 號系統調用，只有一個數字是沒什么意義的，這個數字到底代表那個系統調用呢? 

根據內核源碼查系統調用

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

Gotyou!!!我們可以看到調用了 newfstatat 系統調用，這個系統調用有什么作用呢?讓我們再一次問男人(man命令)：

$ man newfstatat 

得到了這樣的信息：

啊哈!原來是fstatat，這是在讀取文件的元信息。現在我們已經知道了調用什么系統調用，可是一個新的問題再次出現，那就是我們為什么調用這個系統調用后最終會因為等待一個 rpc 被卡死呢?顯然我們需要調用棧信息來驗證。 

跟蹤內核運行時棧

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

這個內核調用棧最終揭開了所有秘密。 

真相大白

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

接下來我們從調用棧的最底層看，我們發現了系統調用，印證了正是進程調用這個系統調用而導致卡住的。

那么調用這個系統調用發生了什么呢?我們接著往上看，注意這幾行：

Finally!!!從調用棧中我們看到了一系列 NFS 相關的函數，NFS全稱Network File System，也就是網絡文件系統，我們平時掛載(mount)一個遠程文件系統就是NFS來實現的，正是 NFS 進行網絡通信才導致在 rpc 上等待，從內核調用棧我們知道，進程在查詢某個遠程主機上文件的元數據時因網絡問題導致被卡死。通過這一線索我們最終鎖定了出現問題的代碼。 

總結 

本文為大家完整展示了一次 bug 的定位過程，可以看到 Linux 為我們提供了極為豐富的調試工具，當然這離不開 Linux 系統本身優秀的設計思想，那就是將進程和內核的運行時信息通過文件系統提供出來，這極大的方便了問題的排查與定位。希望本文對大家理解 Linux 系統下問題 debug 有所幫助。

本文轉載自微信公眾號「碼農的荒島求生」，可以通過以下二維碼關注。轉載本文請聯系碼農的荒島求生公眾號。