使用 lldb 來診斷 .NET Core 應用程式

有原始碼就拿原始碼來偵錯,除非真的沒招了才拿大絕招來用R。

最近做到一個關於 ASP.NET Core 的 hands-on lab 覺得還蠻有趣的,它是要讓做 lab 的人可以體驗一下:如何使用 LLDB 這個工具來 debug 跑在 Linux 環境上的 ASP.NET Core 應用程式。

也許你跟我一樣,看到 lab 的第一個想法就是:「都有了 Visual Studio 或 Visual Studio Code (搭配 C# 擴充套件) 了,為什麼不用這些工具來 debug 呢?」後來帶 lab 的講師說明情境,大致上就是在維運的場景中,也許你只拿得到部署用的 binary package 或 container image,結果網站出錯了,如何在第一時間協助偵錯甚至除錯。

假設網站上有個動作(如:Post action)執行了一段時間後 timeout,不知道發生了什麼原因,那要怎麼開始偵錯呢?假設這個 ASP.NET Core 的應用程式是執行在 Linux 的環境(或是 docker container 中),連上該台部署應用程式的伺服器,先準備好工具(以 Ubuntu 16.04 為例):

(假設是 Ubuntu Linux)
$ sudo apt install -y lldb-3.6 gdb
...
...
(安裝 process dump)
$ wget https://packages.microsoft.com/repos/microsoft-ubuntu-trusty-prod/pool/main/p/procdump/procdump_1.0_amd64.deb
...
$ sudo dpkg -i procdump_1.0_amd64.deb
...

接著執行 ps -x | grep dotnet 指令找出這個 ASP.NET 應用程式的 process id

注意要找的 process id 是執行網站 .dll 的那一個(上圖中就是 23014),接著執行sudo lldb(因為要 attach process 需要管理者權限)進行偵錯,使用 process attach -p <process id> 來針對這個應用程式偵錯:

接上 process 後,這時 process 是在暫停的狀態,先執行 (lldb) process continue 恢復執行,然後再去瀏覽器上執行網站中有問題的動作,再返回 lldb 中執行 (lldb) process interrupt 中斷目前回應過久的狀態,這時就可以開始偵錯了。

首先我們載入 .NET Core 附的 SOS 除錯外掛模組(很可愛的名字)來協助 lldb 認得 .NET Core 相關的除錯工具,這個模組你可以在 .NET Core 的 runtime 目錄中找到,通常是在 /usr/share/dotnet/shared/Microsoft.NETCore.App/2.0.5/libsosplugin.so 這樣的路徑下,你可以根據版本來修改。在 lldb 中可以使用 (lldb) plugin load /usr/share/dotnet/shared/Microsoft.NETCore.App/2.0.5/libsosplugin.so 命令來載入。

接下來,使用 (lldb) clrthreads -live 來觀看目前這個 ASP.NET Core 應用程式 process 中所有的執行緒,找出有問題的那一個。

列出這個 ASP.NET Core 應用程式所有的執行緒後,你會發現到其中一個出現了 Exception!啊哈,看起來可能可以從這條路追下去找找看為什麼會產生 exception,所以再使用 (lldb) thread select 20 (看第一個 column)進入這個執行緒,接著使用 (lldb) clrstack 把這個執行緒的記憶體倒出來看看:

當然你會看到滿滿的 exception stack,不過大概已經猜出問題出在 System.Net.WebClient 此時再執行 (lldb) pe 來仔細審視這個例外:

原來是 WebClient 建立連線失敗造成的 exception,接著再執行 (lldb) dso 來找出 WebClient 的物件記憶體位址,看看能不能找出為什麼它會連線錯誤產生 exception 呢

只要在茫茫物件海中找到 System.Net.WebClient 就好了,接著就能使用 (lldb) dumpobj <記憶體位址> 來把物件內容 dump 出來好好看看(用第二個 column 的數值)

用 dumpobj 會把物件下所有的欄位名稱、類別以及記憶體位址都展開,由於是連線失敗,所以我們合理懷疑 _webRequest 應該有點問題,所以再次 dumpobj 它的內容來看(記憶體位址要使用 Value 那一欄的值,所以是 (lldb) dumpobj 00007f025cfb25d8):

然後再 deep dive 下去看 _requestUri 的值是不是連到奇怪的伺服器才連不上的((lldb) dumpobj 00007f025cf58d10):

終於快追到最後一層了,看看 _string 就可以找出 URL 的真相了!((lldb) dumpobj 00007f035c01df30):

啊哈,原來是這個值被填入了 http://localhost:8888 的值啊,難怪連不上發生問題,這樣一來找到問題、回報 bug 後就可以打完收工了。