zoukankan      html  css  js  c++  java
  • 用Windbg调试Silverlight应用死锁

    测试一个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              ret

    0: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              ret

    0: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才返回。

    于是,获知死锁的原因:

    1. UI线程请求一把锁,该锁被工作线程锁持有。UI线程等待工作线程释放锁。
    2. 工作线程同步调用UI线程,等待UI线程完成任务。
    3. 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)的程序。它们虽然看上去很酷,但是往往有一些明显的缺点。

    1. 可测试性差。我无法直接测试匿名委托,这导致测试粒度的增大与测试复杂性的提高。
    2. 可理解性差。由于是“匿名”的,我无法使用“命名”这一强大的工具来展示程序的意图。
    3. 增加耦合性。匿名委托往往导致不同目标、不同抽象级别的代码混杂在一个函数中。

    这次死锁的根本原因是不正确的加锁范围,诱因是匿名委托导致的耦合。函数LoadLoggingProperties完成了两件任务:(1) 调用WCF,获得服务端数据;(2) 利用服务端数据,更新客户端数据(loggingProperties)。只有任务(2)是需要加锁保护的。不幸的是,两个任务被匿名委托耦合为一个语句。程序员没有经过深思熟虑,就对整个语句加锁,导致执行任务(1)时引发死锁。

    根据以上分析,不难获得解除死锁的方法:缩小加锁范围,将lock语句移入异步WCF调用的回调函数,从而只对任务(2)加锁。

    对于这次调试过程,做一个小结:

    1. 不使用调试器,很可能会漏掉一些难以复现的缺陷。
    2. !SyncBlk可以查看所有的同步块,是调试死锁的好帮手。
    3. 了解应用的线程模型对于调试死锁有帮助。例如,UI线程是STA线程,Threading.Dispatcher.Invoke是同步调用等。
    4. 加锁范围要尽可能的小。这是一条基本原则,但是常常被程序员遗忘。
    5. 尽量避免对第三方代码加锁,因为你往往不知道它会执行什么操作。
  • 相关阅读:
    稳扎稳打Silverlight(13) 2.0交互之鼠标事件和键盘事件
    稳扎稳打Silverlight(17) 2.0数据之详解DataGrid, 绑定数据到ListBox
    再接再厉VS 2008 sp1 + .NET 3.5 sp1(2) Entity Framework(实体框架)之详解 Linq To Entities 之一
    稳扎稳打Silverlight(8) 2.0图形之基类System.Windows.Shapes.Shape
    稳扎稳打Silverlight(11) 2.0动画之ColorAnimation, DoubleAnimation, PointAnimation, 内插关键帧动画
    稳扎稳打Silverlight(21) 2.0通信之WebRequest和WebResponse, 对指定的URI发出请求以及接收响应
    稳扎稳打Silverlight(16) 2.0数据之独立存储(Isolated Storage)
    稳扎稳打Silverlight(9) 2.0画笔之SolidColorBrush, ImageBrush, VideoBrush, LinearGradientBrush, RadialGradientBrush
    稳扎稳打Silverlight(23) 2.0通信之调用WCF的双向通信(Duplex Service)
    游戏人生Silverlight(1) 七彩俄罗斯方块[Silverlight 2.0(c#)]
  • 原文地址:https://www.cnblogs.com/liangshi/p/1805857.html
Copyright © 2011-2022 走看看