和我一起作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