和我一起作Tess的windbg lab - Lab1, Hang

这几个随笔不是对于Tess的翻译,是我自己做的分析,感兴趣的可以看一下。Tess的分析,在她的网页上有连接地。

一共大概7篇,争取等会都写完。其他的不在首页,可以到这里看:http://juqiang.cnblogs.com

 

原文地址:http://blogs.msdn.com/b/tess/archive/2008/02/04/net-debugging-demos-lab-1-hang.aspx

操作步骤:

1、产生压力:tinyget -srv:localhost -uri:/BuggyBits/FeaturedProducts.aspx -threads:30 -loop:50

2、观察taskmgr的输出:w3wp.exe的CPU为0,内存几乎没有变化

3、模拟手工操作:打开IE,输入地址:http://localhost/buggybits/featuredproducts.aspx,观察最下面的response time,我这里为17秒。

4、抓dump:adplus -hang -pn w3wp.exe -quiet -o c:\dumps

5、分析dump。

  a、加载sos:.loadby sos mscorwks

  b、查看所有托管线程的callstack:~* e!clrstack。输出分为两类:

    //类别1,类似的callstack一共23个,最上面的语句都是Monitor.Enter

    OS Thread Id: 0xee0 (40)
    ESP       EIP    
    05c5f0cc 7c9585ec [GCFrame: 05c5f0cc]
    05c5f208 7c9585ec [HelperMethodFrame: 05c5f208] System.Threading.Monitor.Enter(System.Object)
    05c5f25c 05600df3 DataLayer.GetFeaturedProducts()
    05c5f298 05600c7c FeaturedProducts.Page_Load(System.Object, System.EventArgs)

    //其他代码

    以及:

    //类别2,有一个SleepInternal方法

    OS Thread Id: 0x514 (24)
    ESP       EIP    
    0585ee08 7c9585ec [HelperMethodFrame: 0585ee08] System.Threading.Thread.SleepInternal(Int32)
    0585ee5c 05600dfd DataLayer.GetFeaturedProducts()
    0585ee98 05600c7c FeaturedProducts.Page_Load(System.Object, System.EventArgs)
  c、上面的步骤2和步骤3中,指明了这很可能是一个block的问题,所以,使用命令:!syncblk来查看,是否有阻塞发生。而且上面的步骤b中的类别1,我们看到了Monitor.Enter方法。

  d、!syncblk的输出如下:

    0:000> !syncblk
    Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
       26 000fd17c          
47         1 04c09698   514  24   02a86628 System.Object
    -----------------------------
    Total           31
    CCW             2
    RCW             0
    ComClassFactory 0  
    Free            14
    注意上面的MonitorHeld字段,是47,它意味着有(47-1)/2=23个线程被上面的Thread列(24)所阻塞,24号列正在拿着02a86628这个对象。

  e、分析到这里就比较清楚了,线程24的方法中,通过调用Monitor.Enter正拿着一个对象,然后执行一个比较耗时的动作,这里用Thread.Sleep来模拟。由于只有Monitor.Exit的时候,该对象才可以被其他线程所使用,所以执行同样方法的线程就卡在Monitor.Enter这句话上了。都在等待,没有事情做,CPU就很低。

  f、看上面步骤地5.b,GetFeaturedProducts方法的当前ip是05600dfd ,我们需要得到这个方法的md,执行命令:!ip2md 05600dfd ,结果如下:

    0:024> !ip2md 05600dfd
    MethodDesc: 02429048
    Method Name: DataLayer.GetFeaturedProducts()
    Class: 055b18ac
    MethodTable: 0242905c
    mdToken: 06000008
    Module: 024285cc
    IsJitted: yes
    m_CodeOrIL: 05600dd0

  g、然后我们有三种方法可以看代码:

    根据md来看:!dumpil 02429048 (这个地址是上面步骤f中的输出的第一行MethodDesc的值)

    根据native code来看:!u 05600dd0 (这个地址是上面步骤f中的输出的最后一行的m_CodeOrIL的值)

    根据module来看:!dumpmodule 024285cc (这个地址是上面步骤分钟的输出的倒数第三行的Module的值)

  h、我选择上面第三种模式来看,!dumpmodule之后会得到module所在的assembly的dll的名字,然后用reflector打开

  i、定位到DataLayer.GetFeaturedProducts方法上,代码如下:

     lock (this.syncobj)
     {
            Thread.Sleep(5000);

        // 其他代码

    }

    到这里,问题已经很清楚了。

 

Over


posted @ 2010-06-27 12:14  鞠强  阅读(2520)  评论(3编辑  收藏  举报

hello

world