今天成功的利用 WinDbg 分析與解決程式 Hang 住的狀況

我們之前有一支 Console Program 程式是用來收取 POP3 伺服器中的郵件，並在解析郵件內容後進行分析與後續處理，不過三不五時程式都會 Hang 住不動，導致分析作業無法進行下去。又因為我們在開發環境一直都很正常的執行，程式是到正式主機才 Hang 住的，所以一直很苦惱到底要怎麼解決。

我們之前的解決方法就是在程式中寫了大量的 Log 訊息，讓程式在正式主機執行的時候多紀錄一些執行的動作，最後是查出抓取某一封郵件的時候 Hang 住的，由於我們是採用從 CodeProject 下載回來的 .NET POP3 MIME Client 元件，元件本身包的還不錯用，只是寫的有點複雜，我們在追蹤錯誤的時候很難標出可能發生錯誤的地方，曾經研究了 6 個小時找不到 Hang 住的地方，這樣一直猜程式到底 Hang 在哪裡真的很累人。

今天我就利用之前去「ASP.NET 應用程式偵錯實戰專班」 上課所學的知識進行程式的傾印(dump)與分析(analysis)，還真的給我找到問題點了，不出 30 分鐘問題就解決，真的太棒了！不過說實在的，這課雖然是5月6~7日才剛上過的，到了今天還真的忘了一大半，主要是 WinDbg 的指令太難記了，不常用真的會忘記，我今天就大致分享一下除錯的過程與心得。

我主要會分成兩大塊來講，第一個是「將程式執行中的狀態留下來」（又稱 dump 或 Userdump），接下來是透過 WinDbg 程式分析 dump 檔。

首先，你必須先去下載 Debug Diagnostic Tool v1.1 工具（抓 dump 的工具），以及到 Debugging Tools for Windows 網站下載 WinDbg 程式（目前的最新版是6.9.3.113），並安裝完成。

第一步，將程式執行中的狀態留下來

開啟 Debug Diagnostic Tool 後，可以直接進入 Processes 頁籤，選取你 Hang 住的程式，按滑鼠右鍵選【Create Full Userdump】（如下圖）

Debug Diagnostic Tool 預設手動產生的 Dump 檔會放在 C:\Program Files\DebugDiag\Logs\Misc 目錄下：

這 時你就會取得一個完整的程式執行狀態了，其中綠色圖示的 ConsoleProgram1.exe__PID__5276__Date__05_18_2008__Time_03_36_54PM__659__Manual Dump.dmp 檔案就是一個完整的 Dump File。

第二步：透過 WinDbg 程式分析 *.dmp 檔案

你開啟 WinDbg 程式後，第一步是先設定 Symbol 位址，開啟 File -> Symbol File Path。

接著輸入以下位址就設定完成了，預設動態下載的 Symbol 檔會儲存在底下這個設定的 c:\websymbols 目錄，你可以自己修改成其他目錄：

SRV*c:\websymbols*http://msdl.microsoft.com/download/symbols

在來就直接載入剛剛的 ConsoleProgram1.exe__PID__5276__Date__05_18_2008__Time_03_36_54PM__659__Manual Dump.dmp 檔案。

選完檔案後會出現一個小視窗：

接下來就是打指令的時間啦，只要輸入 3 個指令就可以完成分析作業：

1. 在畫面最下面 0:000> 的輸入框輸入 kbn 顯示目前程式的 Call stack 與前三個參數、Frame number，如果你有看到 mscorwks 字樣的話（如下圖框紅色的地方），就代表這支程式是 .NET 寫的應用程式。

2. 接著載入 .NET 的 SOS 組件，輸入 .loadby sos mscorwks 指令。

3. 接著輸入 !clrstack 指令，輸出目前 .NET 程式的 Call stack，這你就應該很熟悉了。

0:000> !clrstack OS Thread Id: 0x140c (0) ESP EIP 0012f190 7c9585ec [HelperMethodFrame_1OBJ: 0012f190] System.Threading.WaitHandle.WaitOneNative(Microsoft.Win32.SafeHandles.SafeWaitHandle, UInt32, Boolean, Boolean) 0012f23c 793b03fe System.Threading.WaitHandle.WaitOne(Int64, Boolean) 0012f254 793b0c1b System.Threading.WaitHandle.WaitOne(Int32, Boolean) 0012f264 793b044e System.Threading.WaitHandle.WaitOne() 0012f268 00e92204 Net.Mail.Pop3Command`1[[System.__Canon, mscorlib]].GetResponse() 0012f2a4 00e9207d Net.Mail.Pop3Command`1[[System.__Canon, mscorlib]].Execute(Net.Mail.Pop3State) 0012f2cc 00e92d36 Net.Mail.Pop3Client.ExecuteCommand[[System.__Canon, mscorlib],[System.__Canon, mscorlib]](System.__Canon) 0012f2f0 00e94301 Net.Mail.Pop3Client.RetrMimeEntity(Net.Mail.Pop3ListItem) 0012f334 00e941c3 Net.Mail.Pop3Client.RetrMailMessageEx(Net.Mail.Pop3ListItem) 0012f348 00e9059c Pop3.Program.Main(System.String[]) 0012f69c 79e7c74b [GCFrame: 0012f69c]

由這個 .NET 的 Call stack 訊息得知我的程式一直停在 System.Threading.WaitHandle.WaitOne() 這個方法，且透過 Call stack 也很容易找到這一行到底在哪裡。

找到後原本的程式是這樣：

_manualResetEvent.WaitOne();

最後我改成有 timeout 的版本，不樣讓程式一直癡癡的等：

_manualResetEvent.WaitOne(20 * 1000, false);

就這樣解決了一個惱人的問題。