使用WinDbg对Windows Live Toolbar死锁的简单分析

 

我一直在用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，毕竟修好问题才是最重要的。

 

Trackback: http://tb.blog.csdn.net/TrackBack.aspx?PostId=1737651