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

我一直在用Windows Live Toolbar中的Live Favorites来同步我的书签信息，但是速度总是很慢，甚至完全死掉。今天闲来无事，刚看到Mark的一篇Bloghttp://blogs.technet.com/markrussinovich/archive/2006/08/31/453100.aspx，对于他不放过任何问题的精神很是钦佩，准备效法一番。正好遇到IE关闭之后停在那边一直不动，怎么点也没有反应，便准备动手调试一下看看问题出在哪里。

启动WinDbg，Attach到IExplore.exe进程上，我依次检查每个Thread的调用栈，发现3号线程的情况最为诡异，其Call Stack如下：

0:003> kb

ChildEBP RetAddrArgs 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 RetAddrArgs 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，毕竟修好问题才是最重要的。