测试一个Silverlight应用时，突然整个IE窗口失去响应（Not Responding）。这时，IE和内嵌的Silverlight应用不响应任何Windows事件，似乎只有杀死IE进程，才能进一步测试。但是，简单地杀死进程，很可能导致问题无法复现（repro）。于是，我将Windbg附加（attach）到IE进程上，做现场调试（live debugging）。
调试.NET程序，需要在Windbg中加载调试扩展项sos.dll。Silverlight的运行时（runtime）是CoreCLR，因此必须加载CoreCLR对应的sos.dll（不能使用.NET Framework自带的sos.dll）。获得正确sos.dll的方法是安装Silverlight Tools for Visual Studio（3.0, 4.0）。如果安装了正确的sos.dll，在Windbg中可用如下命令将其加载。
0:023> .loadby sos coreclr
对于任何一个Windows窗口程序，只有UI线程绘制用户界面。IE窗口失去响应，这暗示UI线程停止工作。于是用!threads命令查看所有线程。
0:023> !threads
ThreadCount: 9
UnstartedThread: 0
BackgroundThread: 7
PendingThread: 0
DeadThread: 2
Hosted Runtime: yes
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
4 1 608 0a7098b8 2000220 Enabled 1bf9090c:1bf915dc 109e7fb8 1 STA
33 2 14e0 0a67fc78 b220 Enabled 00000000:00000000 0a567760 0 MTA (Finalizer)
34 3 504 0a680b68 1220 Enabled 00000000:00000000 0a567760 0 Ukn
35 4 46c 0e8b7798 1000220 Enabled 00000000:00000000 0a567760 0 Ukn (Threadpool Worker)
39 5 2350 0a41bf60 3001220 Enabled 1bf5fe18:1bf615dc 109e7fb8 1 Ukn (Threadpool Worker)
XXXX a 0a41c970 1011820 Enabled 00000000:00000000 0a567760 0 Ukn (Threadpool Worker)
XXXX 9 0a41a638 1011820 Enabled 00000000:00000000 0a567760 0 Ukn (Threadpool Worker)
47 6 1618 0a41ce78 3001220 Enabled 1bf91700:1bf935dc 109e7fb8 0 Ukn (Threadpool Worker)
42 8 2754 0a41c468 3001220 Enabled 1bf93710:1bf955dc 109e7fb8 0 Ukn (Threadpool Worker)
由于UI线程是STA线程，所以可以断定4号线程是UI线程。于是切换到4号线程，用!CLRStack命令检查其托管栈。
0:023> ~4s
eax=0000539e ebx=0244c8b8 ecx=0c4a19f4 edx=00000005 esi=00000001 edi=00000000
eip=776464f4 esp=0244c868 ebp=0244c904 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00200246
ntdll!KiFastSystemCallRet:
776464f4 c3 ret0:004> !CLRStack
OS Thread Id: 0x608 (4)
Child SP IP Call Site
0244cac4 776464f4 [GCFrame: 0244cac4]
0244cbdc 776464f4 [HelperMethodFrame_1OBJ: 0244cbdc] System.Threading.Monitor.Enter(System.Object)
0244cc24 024b117f MyApp.Common.Logger.Log(MyApp.GeneralServiceReference.Level, System.String,
MyApp.GeneralServiceReference.ClientLoggingAttributes)
0244cc84 024b0d82 MyApp.Common.UsersUsageTracer.Log(MyApp.Common.UsageCategoryType,
MyApp.Common.Event, MyApp.Common.TraceLevel, MyApp.Common.UsageParametes[])
0244cd18 067ddc3b MyApp.BookInfo.BookInfoPresenter.set_Book(MyApp.BookServiceReference.BookInfo)
...
由托管栈可知，UI线程正在调用函数Monitor.Enter，以请求一把排他锁。由于UI线程始终无法获得这把锁，于是UI线程停止工作。申请锁的函数是Logger.Log。这是可以理解的：大多数日志类（Logger）都会在记录日志时，申请排它锁，以确保日志内容的多线程安全。那么这把挂起UI线程的锁是被谁持有呢？
CLR会为每一个被加锁的对象分配一个同步块（sync block），以记录必要的同步信息。用调试器命令!SyncBlk可以查看进程的所有同步块。
0:004> !SyncBlk
Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock ...
1364 1ae8c1a4 3 1 0a41bf60 2350 39 0c4a19f4 ...
很幸运，进程只有一个同步块，它应该是挂起UI线程的“元凶”。现在，它被线程2350（操作系统线程号）所持有。于是切换到这个工作线程，用!CLRStack命令检查其托管栈。
0:004> ~~[2350]s
eax=00000001 ebx=15c4eb00 ecx=00000001 edx=00000000 esi=00000001 edi=00000000
eip=776464f4 esp=15c4eab0 ebp=15c4eb4c iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000202
ntdll!KiFastSystemCallRet:
776464f4 c3 ret0:039> !CLRStack
Child SP IP Call Site
15c4ed10 776464f4 [HelperMethodFrame_1OBJ: 15c4ed10] System.Threading.WaitHandle.WaitOneNative
(System.Runtime.InteropServices.SafeHandle, UInt32, Boolean, Boolean)
15c4ed84 0e279584 System.Threading.WaitHandle.InternalWaitOne
(System.Runtime.InteropServices.SafeHandle, Int64, Boolean, Boolean)
15c4eda0 0e279552 System.Threading.WaitHandle.WaitOne(Int64, Boolean)
15c4edb4 0e279440 System.Threading.WaitHandle.WaitOne(Int32, Boolean)
15c4edc8 0e2794d0 System.Threading.WaitHandle.WaitOne()
15c4edd0 5e59223d System.Windows.Threading.Dispatcher.Invoke
(System.Windows.Threading.DispatcherPriority, System.Delegate, System.Object[])
15c4edf0 5e5ed437 System.Windows.Threading.DispatcherSynchronizationContext.Send
(System.Threading.SendOrPostCallback, System.Object)
15c4ee04 5e638404 System.Net.Browser.AsyncHelper.BeginOnUI(System.Threading.SendOrPostCallback,
System.Object)
15c4ee18 5e6395a9 System.Net.Browser.BrowserHttpWebRequestCreator.Create(System.Uri)
15c4ee4c 0406764c System.ServiceModel.Channels.HttpChannelFactory.GetWebRequest
(System.ServiceModel.EndpointAddress, System.Uri, System.TimeSpan)
...
15c4f204 067dd666 MyApp.Services.GeneralServiceHandler.CallToServer(ServiceCallDelegate)
15c4f258 067dd50c MyApp.Services.GeneralServiceHandler.RetrieveLoggingProperties
(System.EventHandler`1<MyApp.GeneralServiceReference
.RetrieveLoggingPropertiesCompletedEventArgs>)
15c4f270 067dd42b MyApp.Common.Logger.LoadLoggingProperties()
...
该工作线程调用函数Logger.LoadLoggingProperties。从函数名推断，该函数是加载日志的属性。从调用栈分析，它使用WCF（调用了名空间System.ServiceModel的类）以获得服务端数据。令人惊讶的是，WCF竟然调用函数Browser.AysncHelper.BeignOnUI，从而将计算任务分配给UI线程。而BeginOnUI调用函数Threading.Dispatcher.Invoke，这是一个对UI线程的同步调用：只有UI线程完成了对System.Delegate对象的调用，函数Invoke才返回。
于是，获知死锁的原因：
- UI线程请求一把锁，该锁被工作线程锁持有。UI线程等待工作线程释放锁。
- 工作线程同步调用UI线程，等待UI线程完成任务。
- UI线程与工作线程相互等待，形成死锁。
到目前为止，我不清楚为什么Silverlight中的WCF会同步调用UI线程。事实上，程序员只能用异步函数调用UI线程，为什么框架本身要同步函数调用UI线程？也许，这是Silverlight团队的一个特殊设计，用于解决更底层的问题。那么，如何解决当前的死锁问题？由于死锁是由函数LoadLoggingProperties引发的，于是检查其实现。
private static void LoadLoggingProperties()
{
lock (loggingMsgs)
{
GeneralServiceHandler.RetrieveLoggingProperties(
delegate(object sender, RetrieveLoggingPropertiesCompletedEventArgs e)
{
loggingProperties = e.Error == null
? e.Result
: new LoggingProperties
{
LevelThreshold = Level.Warning,
SendClientLogsToServer = true,
SendClientUsageLogsToServer = false
};
HandleLogMsgs(null);
});
}
}
坦白地说，我不喜欢使用匿名委托（anonymous delegate）的程序。它们虽然看上去很酷，但是往往有一些明显的缺点。
- 可测试性差。我无法直接测试匿名委托，这导致测试粒度的增大与测试复杂性的提高。
- 可理解性差。由于是“匿名”的，我无法使用“命名”这一强大的工具来展示程序的意图。
- 增加耦合性。匿名委托往往导致不同目标、不同抽象级别的代码混杂在一个函数中。
这次死锁的根本原因是不正确的加锁范围，诱因是匿名委托导致的耦合。函数LoadLoggingProperties完成了两件任务：(1) 调用WCF，获得服务端数据；(2) 利用服务端数据，更新客户端数据（loggingProperties）。只有任务(2)是需要加锁保护的。不幸的是，两个任务被匿名委托耦合为一个语句。程序员没有经过深思熟虑，就对整个语句加锁，导致执行任务(1)时引发死锁。
根据以上分析，不难获得解除死锁的方法：缩小加锁范围，将lock语句移入异步WCF调用的回调函数，从而只对任务(2)加锁。
对于这次调试过程，做一个小结：
- 不使用调试器，很可能会漏掉一些难以复现的缺陷。
- ！SyncBlk可以查看所有的同步块，是调试死锁的好帮手。
- 了解应用的线程模型对于调试死锁有帮助。例如，UI线程是STA线程，Threading.Dispatcher.Invoke是同步调用等。
- 加锁范围要尽可能的小。这是一条基本原则，但是常常被程序员遗忘。
- 尽量避免对第三方代码加锁，因为你往往不知道它会执行什么操作。
