原文地址:http://blogs.msdn.com/b/tess/archive/2008/02/08/net-debugging-demos-lab-2-crash.aspx
操作步骤:
1、打开 http://localhost/BuggyBits/Reviews.aspx,点击5次refresh按钮,然后看到巨大的黑色粗体字:Service Unavailable
2、检察eventlog,点开始-运行,输入:eventvwr,先看Application的,会有如下错误:
Process ID: 1808
Exception: System.NullReferenceException
以及
Process ID: 3544
Exception: System.NullReferenceException
以及
Process ID: 7234
Exception: System.NullReferenceException
以及
Process ID: 2343
Exception: System.NullReferenceException
以及
Process ID: 9087
Exception: System.NullReferenceException
3、上面的错误,我们可以看到,W3WP一共crash了5次,然后看System的日志,可以看到:
事件类型: 错误
事件来源: W3SVC
事件种类: 无
事件 ID: 1002
日期: 2010-6-27
事件: 12:35:28
用户: N/A
计算机: VPC2003
描述:
应用程序池 'LabAppPool' 被自动禁用,原因是为此应用程序池提供服务的进程中出现一系列错误。
有关更多信息,请参阅在 http://go.microsoft.com/fwlink/events.asp 的帮助和支持中心。
4、打开IIS,察看应用程序池,你会发现LabAppPool已经被disable掉了。
5、右键查看该apppool的属性,在快速失败保护中会发现,如果5分钟之内有5次crash,则该apppool会被禁用掉。
6、好了,这是一个典型的crash问题,并导致apppool被disable掉,对客户端显示HTTP503错误。现在开始debug
7、抓一个crash的dump,我们会发现产生了3个dump,分别是1st chance的AV、1st chance的process shutdown和2nd chance的netclr full,先打开第一个av的dump
a、由于是crash的dump,所以windbg会自动切换到导致AV的那个线程,我这里是18号。
b、加载sos,会有如下信息:
0:018> .loadby sos mscorwks
------------------------------------------------------------
sos.dll needs a full memory dump for complete functionality.
You can create one with .dump /ma <filename>
------------------------------------------------------------
因为这是一个mini dump,所以很多信息我们看不到。解决办法之一是在adplus的时候,用参数-FullOnFirst,但是这个参数有副作用,我们后面会看到。
c、查看托管线程,如下:
0:018> !clrstack
PDB symbol for mscorwks.dll not loaded
OS Thread Id: 0x64c (18)
ESP EIP
0221f950 05500efb Review.Finalize()
0221fc1c 79fbcca7 [ContextTransitionFrame: 0221fc1c]
0221fcec 79fbcca7 [GCFrame: 0221fcec]
可以看到,Review.Finalize方法导致了AV错误。
d、运行!threads,输出如下:
0:018> !threads
ThreadCount: 4
UnstartedThread: 0
BackgroundThread: 4
PendingThread: 0
DeadThread: 0
Hosted Runtime: yes
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
16 1 2a4 000dbce8 3808220 Enabled 00000000:00000000 001028a8 1 Ukn (Threadpool Worker)
18 2 64c 000e7de0 b220 Disabled 00000000:00000000 001028a8 0 Ukn (Finalizer)
19 3 538 000ec2c0 1220 Enabled 00000000:00000000 000d8fd8 0 Ukn
20 4 594 000ff408 80a220 Enabled 00000000:00000000 000d8fd8 0 Ukn (Threadpool Completion Port)
可以看到发生AV的18号线程是GC的finalizer线程。那么具体的exception在哪里呢?
e、执行命令,!dso。输出如下:
0:018> !dso
Error requesting details
Unable to determine bounds of gc heap
ooh,我们在一个mini的dump里面,很多东西是看不到的。so,需要抓一个fulldump来看。
f、重新运行adplus,增加参数:-FullOnFirst,重新看dump。
g、看!dso的结果:
0:018> !dso
OS Thread Id: 0x908 (18)
ESP/REG Object Name
esi 029b9158 Review
0221f990 029b9158 Review
0221f9dc 029b9158 Review
0221f9e8 029b9158 Review
0221f9fc 029b9158 Review
0221fa00 029b9158 Review
0221fa10 029b9158 Review
0221fae8 029b9158 Review
0221fcb0 029b9158 Review
没有exception,只有一个Review对象,继续看,执行!do 029b9158
MT Field Offset Type VT Attr Value Name
790fd8c4 4000008 4 System.String 0 instance 00000000 quote
790fd8c4 4000009 8 System.String 0 instance 00000000 source
注意上面的两个string,都是0,这意味着都是null,那么,是否可能是null.SomeMethod导致的呢?
h、看步骤c中的Review.Finalizer方法,代码如下:
~Review()
{
if (quote.ToString() != string.Empty)
{
quote = null;
}
}
嗯,问题找到了,在于上面的quote.ToString造成的,因为某个原因,quote这个字符串变成了null,所以出现AV了。
i、实际上如果查看页面代码,我们能看到一个Clear方法把这个变量变成了null。
Over