使用WinDbg對Windows Live Toolbar死鎖的簡單分析

ATField發表於2007-08-11
Windows

 

我一直在用Windows Live Toolbar中的Live Favorites來同步我的書籤資訊，但是速度總是很慢，甚至完全死掉。今天閒來無事，剛看到Mark的一篇Blog http://blogs.technet.com/markrussinovich/archive/2006/08/31/453100.aspx，對於他不放過任何問題的精神很是欽佩，準備效法一番。正好遇到IE關閉之後停在那邊一直不動，怎麼點也沒有反應，便準備動手除錯一下看看問題出在哪裡。

啟動WinDbg，Attach到IExplore.exe程式上，我依次檢查每個Thread的呼叫棧，發現3號執行緒的情況最為詭異，其Call Stack如下：

0:003> kb

ChildEBP RetAddr  Args to Child             

01d5f4f4 77a806a0 77a5b18c 000006a8 00000000 ntdll!KiFastSystemCallRet 01d5f4f8 77a5b18c 000006a8 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc [f:/vistartm.obj.x86fre/base/ntdll/daytona/objfre/i386/usrstubs.asm @ 2971]

01d5f55c 77a5b071 00000000 00000000 00000000 ntdll!RtlpWaitOnCriticalSection+0x154 01d5f584 031e5480 040851c4 01d5f5bc 031e55eb ntdll!RtlEnterCriticalSection+0x152 WARNING: Stack unwind information not available. Following frames may be wrong.

01d5f59c 031f08f9 040851c4 00000001 0870611e WLFExt+0x15480

01d5f5d4 031ea967 08706136 03c96650 040851c0 WLFExt+0x208f9

01d5f5fc 031ea9b7 040818f0 01d5f62c 031e9fba WLFExt+0x1a967

01d5f608 031e9fba 00000001 031ec103 031df277 WLFExt+0x1a9b7

01d5f62c 64853ac8 040818f0 00000000 03c968b8 WLFExt+0x19fba

01d5f658 64856164 00000001 80004005 03c96650 msntb!DllUnregisterServer+0xb9a0

01d5f700 7092e468 03c96650 004f4b64 03d44938 msntb!DllUnregisterServer+0xe03c

01d5f720 7093edb2 03c96650 00000000 004ec83c ieframe!Ordinal160+0xb569

01d5f748 70907931 00000001 004ec778 7092e5cc ieframe!Ordinal222+0xd2b1

01d5f77c 7092fc12 004ec850 00000000 00000002 ieframe!Ordinal300+0xc96f

01d5f798 7091dc4a 004eb08c 01d5f7b4 7091dc69 ieframe!SetQueryNetSessionCount+0x1328

01d5f7a4 7091dc69 004e5c4c 00000002 01d5f7cc ieframe!Ordinal224+0xd15a

01d5f7b4 7092fb81 004e5c4c 00000002 00000000 ieframe!Ordinal224+0xd179

01d5f7cc 7090c15c 004eb08c 00060838 00000002 ieframe!SetQueryNetSessionCount+0x1297

01d5f7e8 7090ba6d 004e5c4c 00060838 00000002 ieframe!Ordinal101+0x1ad2

01d5f850 7091ac8a 004e5c4c 00060838 00000002 ieframe!Ordinal101+0x13e3

 

可以看到這個執行緒正在準備Enter一個Critical Section，但是由於該Critical Section已經被別人佔用，並且Spin時間過長，已經呼叫ntdll!ZwWaitForSingleObject進入了核心模式開始等待了。雖說Critical Section並非核心物件，但是Critical Section仍然可以導致執行緒進入等待狀態。假想一下如果一個執行緒一直在Spin，反覆迴圈等待Critical Section被別人釋放，那麼這種方式該有多佔CPU。因此Windows會讓執行緒Spin一段時間之後繼續等待。

那麼這個執行緒到底在做什麼事情呢？可以看到有兩個module非常可疑：wlfext和msntb。

先用lm命令檢視一下wlfext是什麼：

0:003> lmvm wlfext

start    end        module name

031d0000 03225000   WLFExt     (export symbols)       WLFExt.dll

    Loaded symbol image file: WLFExt.dll

    Image path: C:/Program Files/Windows Live Favorites/WLFExt.dll

    Image name: WLFExt.dll

    Timestamp:        Tue Feb 13 07:52:08 2007 (45D0FDA8)

    CheckSum:         00059C4B

    ImageSize:        00055000

    File version:     3.1.0.130

    Product version:  3.1.0.130

    File flags:       0 (Mask 3F)

    File OS:          4 Unknown Win32

    File type:        1.0 App

    File date:        00000000.00000000

    Translations:     0409.04b0

    CompanyName:      Microsoft Corporation

    ProductName:      Windows Live Favorites for Windows Live Toolbar

    InternalName:     WLFExt

    OriginalFilename: WLFExt.dll

    ProductVersion:   03.01.0000.0130

    FileVersion:      03.01.0000.0130

    FileDescription:  Windows Live Favorites for Windows Live Toolbar

    LegalCopyright:   Copyright© Microsoft Corporation 2005-2006.  All rights reserved.

很清楚了，這是Windows Live Favorites！

再看看msntb：

0:003> lmvm msntb

start    end        module name

64830000 648b7000   msntb      (export symbols)       msntb.dll

    Loaded symbol image file: msntb.dll

    Image path: C:/Program Files/Windows Live Toolbar/msntb.dll

    Image name: msntb.dll

    Timestamp:        Tue Feb 13 07:55:00 2007 (45D0FE54)

    CheckSum:         0008650F

    ImageSize:        00087000

    File version:     3.1.0.130

    Product version:  3.1.0.130

    File flags:       0 (Mask 3F)

    File OS:          4 Unknown Win32

    File type:        2.0 Dll

    File date:        00000000.00000000

    Translations:     0409.04b0

    CompanyName:      Microsoft Corporation

    ProductName:      Windows Live Toolbar

    InternalName:     msntb.dll

    OriginalFilename: msntb.dll

    ProductVersion:   03.01.0000.0130

    FileVersion:      03.01.0000.0130

    FileDescription:  Windows Live Toolbar for Internet Explorer

    LegalCopyright:   © Microsoft Corporation.  All rights reserved.

毫不意外，這是Windows Live Toolbar。

根據Call Stack來看，Windows Live Toolbar正在嘗試Unregister自身（DllUnregisterServer），但是這個正確嗎？由於LM命令的顯示我們可以看到對於MSNTB.dll我們並沒有PDB，而是隻有Dll本身的輸出的符號表:

 

0:003> lmvm msntb

start    end        module name

64830000 648b7000   msntb      (export symbols)       msntb.dll

    Loaded symbol image file: msntb.dll

    Image path: C:/Program Files/Windows Live Toolbar/msntb.dll

 

而光看這個是根本不準確的，所以這個Callstack顯示的01d5f658 64856164 00000001 80004005 03c96650 msntb!DllUnregisterServer+0xb9a0這一項不能相信，同時也可以通過0xb9a0這個巨大的偏移量也可以看出確實不正確（哪有一個函式會有那麼長，有超過0xb9a0）。雖然其他的地方可以下到PDB，但是我其實不太關心到底在做什麼，沒有原始碼能做的事情也很有限。

 

再回到之前的Crtical Section。我們可以看一下，這個Critical Section到底是怎麼回事。可以使用!locks命令顯示程式中所有的鎖的狀態：

0:003> !locks

 

CritSec +40851c4 at 040851c4

WaiterWoken        No

LockCount          1

RecursionCount     1

OwningThread       3a0

EntryCount         0

ContentionCount    1

*** Locked

 

Scanned 1413 critical sections

 

 

比較運氣好，這裡只有一個Critical Section 040851c4被Lock住。為了確認這個Critcal Section到底是不是3號Thread正在等待的，我們可以看看CallStack中的資訊：

ChildEBP RetAddr  Args to Child             

01d5f584 031e5480 040851c4 01d5f5bc 031e55eb ntdll!RtlEnterCriticalSection+0x152 01d5f850

這裡可以看到，第一個Arg正好就是040851c4，也就是被Lock住的那一個。

回頭再看一下!locks的輸出，可以看到是Thread 0x3a0在Own這個Critical Section，但是檢查一下，發現根本就沒有這個Thread。

到此事實就比較清楚了，在Windows Live Favorites中有一個Bug導致在退出的時候，WLFEXT.dll中的某個函式線上程A中等待某個Critical Section，而這個Crtical Section已經被某個執行緒B所Own，並且這個執行緒B已經由於某種原因已經被Terminate（可能性比較大的是出錯退出），因此執行緒A死鎖，導致整個IE死鎖。我順便用.dump指令收集了一個Mini Dump，準備星期一給Windows Live那邊Log一個Bug，畢竟修好問題才是最重要的。

 

相關文章