原始出處.NET Debugging Demos Lab 1: Hang - Review
Reproduce the problem:
- 瀏覽http://localhost/BuggyBits/FeaturedProducts.aspx
- 顯示這個頁面需要五秒，可以在頁面下看到開始跟執行時間。
- 開啟五個相同的頁面，並且盡量同時重整頁面(reflash)
Get a memory dump:
- 以系統管理員開啟 cmd.exe
- 移至Debugger tool 目錄 cd C:\Program Files (x86)\Windows Kits\8.0\Debuggers\x64
- 先執行所要Dump的腳本
- 開五個ie依序點開http://127.0.0.1/FeaturedProducts.aspx
- 或者使用TinyGet 執行，產生30個Thread及50次迴圈(但我不行用)
- tinyget -srv:localhost -uri:/BuggyBits/FeaturedProducts.aspx -threads:30 -loop:50
- 執行上述過程中在cmd 執行Adplus -hang -pn w3wp.exe -quiet -o D:\dumps
- 因為dump需要很快，所以使用-quiet 避免跳出其他要求的對話框，也許還是會跳出其他的詢問視窗，不過你可以點選yes即可
- Q：在Adplus的hang模式下，甚麼東西是觸發新的memory dump？
- A：這是一個陷阱題。當輸入上述指令時就觸發了新的Memory dump，在hang模式下不需要任何額外的事件(不像crash)，所以不必真的在系統被hanging的時候才能執行Memory dump。
- Q：為了對Process進行Memory dump需要那些權限？
- A：WinDbg/Adplus跟其他的Debugging工具，在權限上沒有甚麼不同。你需要擁有或取得高的使用權限。在hang模式下，dump是採用non-invasive的方式，也就是不須侵入Process。因此在進行Memory dump時，不需跟目標Process是相同winstation 。這在藉由terminal server進行Debugging服務的時候是相當方便的。在Crash模式下，就必須要在相同的winstation 上，也就是說當你用terminal server或遠端進行Debugging時，就必須要藉由log。
- Q：dump在哪產生？提示：觀看WinDbg針對adplus/hang的說明
- A：預設的dump會被放在C:\debuggers\裡，但下指令時包含了-o D:\dumps就是為了將dumps移至特定資料夾。資料夾內回包含下列元件：
- CDBScript：一個內含config檔的檔案，用來告知WinDbg/cdb甚麼指令需執行
- 我的是DebuggerScript.txt
- ADPlus_report.txt：發生資訊，也就是Adplus做了甚麼事
- PID-5656__W3WP.EXE__Date_02-06-2008__Time_11-15-0505.log：運行的紀錄檔，在hang模式下這個記錄檔包含了所有Thread的stack、loaded modules info以及指令!runaway的輸出。如果沒有dumpfile，就可以看這個紀錄檔的內容，找出為什麼。
- 我的是ADPlus_log_0a14_2013-03-07_14-15-59-089.log
- PID-5656__W3WP.EXE__full_1c38_2008-02-06_11-15-08-005_1618.dmp：dump檔
- 我的是FULLDUMP_HangMode_w3wp.exe__0a14_2013-03-07_14-15-59-143_2804.dmp
- Process_List.txt ：顯示所有dump時系統正在值得程序
- 我沒有!!!!
Open the dump in Windbg.exe
- 執行WinDbg
- Open Crush Dump 開啟dump所在位置 D:\dumps
- 設定symbol File Path
- SRV*D:\Symbols*http://msdl.microsoft.com/downloads/symbols
- 勾選reload
- 載入SOS
- 在WinDbg 輸入.load sos
- 必須先從C:\Windows\Microsoft.NET\Framework64\v2.0.50727複製SOS.dll到C:\Program Files (x86)\Windows Kits\8.0\Debuggers\x64
- 在WinDbg 輸入.loadby sos mscorwks
Examine the stacks
- 檢查native callstacks
- 執行~* kb 2000
- 檢視.net callstacks
- 執行~* e !clrstack
- Q：是否有發現任何patterns或認得任何callstacks暗示有Thread這在等待synchronization mechanism
- A：執行後會發現有很多Thread的callstack跟下方的圖很像，原始文章中有提到部分斜體灰色內容是因為WinDbg沒有權限去看.Net底層的東西~但是我的沒有= =
- void GetFeaturedProducts(){
- ...
- lock(...){
- // do something
- }
- ...
- }
Troubleshoot the hang
- 在WinDbg執行 !syncblk 檢視擁有lock的Thread
- Q: What thread owns the lock?
- A
- 最後一個Thread 資訊(我的範例是26)就是擁有lock的Thread，而這個Thread一定又在做部分的GetFeaturedProducts() 或者是hold住了我們想要進去的lock(從dump中可以發現，thread 26正在sleep)
- Q：有多少Thread正在等待Lock?提示：MonitorHeld = 1 代表擁有，=2代表等待
- A：MoniterHeld 為5代表我們有(5-1)/2=2個Thread在等待,，可以藉由輸入下列指令證明計算是否正確。(Monitor.Enter代表lock~但因為我沒有呈現，所以找另一個AwareLock::Enter+)
- .shell -ci "~* e !clrstack" FIND /C "Monitor.Enter"
- .shell -ci "~* kb 2000" find /c "mscorwks!AwareLock::Enter+"
- 取得其中一個Waiter(提示：Waiter的call stack有AwareLock::Enter)並且看一下它如何運作。
- ~24s (移置目標Thread，我的是24)
- kb 2000 (檢視native stack)
- !clrstack (檢視.net stack)
- Q：哪個.Net 程式正在等待lock?
- A：DataLayer.GetFeaturedProducts()
- 看看Owner的運行
- ~24s (移置目標Thread，我的是24)
- kb 2000 (檢視native stack)
- !clrstack (檢視.net stack)
- Q：為什麼blocking?
- A：因為DataLayer.GetFeaturedProducts()呼叫了 ThreadNative::Sleep+0xf9，這也是為什麼會被Block住的原因。(黃色區塊的第一列代表DataLayer.GetFeaturedProducts()，第二列式page_load)
- 根據上述推論，.Net Code應該長得像：
- void GetFeaturedProducts(){
- ...
- lock(syncobj)
- {
- Thread.Sleep(....);
- // do something
- }
- ...
- }
- 可以開啟原始檔確認。
- 如預期，GetFeaturedProducts()具有lock而且sleep 5秒，這當然會產生較長的等待時間，不過會利用sleep是因為它是一個容易重現相同結果的範例。這個結果當然取決於大量的應用程式，不過這包含如何知道這個程式將會運行多久以及發現是否有Thread 比預期的更常被lock。
- 藉由檢視路徑去確認是否有盡量減少lock區塊以降低單一資源的等待時間。
沒有留言:
張貼留言