.Net 调式案例—实验2 崩溃(Crash)复习回顾
现在发布第二个实验,后面会发布一个有关内存的实验。
问题在现
1) 浏览 http://localhost/BuggyBits/Reviews.aspx 这个页面。
2) 点击刷新按钮,这会导致w3wp.exe 进程,iis5 上面是aspnet_wp.exe。
注意:如果你安装了Visual Studio,一个“Just-In-Time”的调试对话框会弹出来(点击“否”),然而,这个消息框会始终在那里并等待用户输入然后结束这个应用程序,你可以禁止JIT调试,方法:把注册表中的下面两个键值删除掉:
·HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\
Windows NT\CurrentVersion\AeDebug\Debugger
·HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\.NETFramework\
DbgManagedDebugger
如果是64位的系统,还应该把下面两个删除:
·HKEY_LOCAL_MACHINE\SOFTWARE\Wow6432Node\Microsoft\
Windows NT\CurrentVersion\AeDebug\Debugger
·HKEY_LOCAL_MACHINE\SOFTWARE\Wow6432Node\Microsoft\.NETFramework\
DbgManagedDebugger
检查事件查看器
1) 打开应用程序和系统的事件查看器,下面的信息会因操作系统合iis版本的不同而有所差别,但大概意思都是一样的
Event Type: Warning
Event Source: W3SVC
Event Category: None
Event ID: 1009
Date: 2008-02-08
Time: 10:12:06
User: N/A
Computer: MYMACHINE
Description:
A process serving application pool 'DefaultAppPool' terminated unexpectedly. The process id was '4592'.
The process exit code was '0xe0434f4d'.
For more information, see Help and Support Center at
http://go.microsoft.com/fwlink/events.asp.
Q:你看到了什么事件?
A:在我的机器上(Win2k3,.net2.0 sp1),我得到了上面的如上面的系统事件日志和如下面的两个应用程序日志,从第一个我们可以看到有某种类型的nullreference 的异常。
Event Type: Error
Event Source: .NET Runtime 2.0 Error Reporting
Event Category: None
Event ID: 5000
Date: 2008-02-11
Time: 11:13:18
User: N/A
Computer: MYMACHINE
Description:
EventType clr20r3, P1 w3wp.exe, P2 6.0.3790.3959,………………
第二个错误完全的给我们讲清楚了是一个空引用的异常,它发生在Review类的
finalizer/destructor中,我们所得到的好处是,我们不需要去再w2k3 中去调试,基于IIS、操作系统和.net框架的帮助,我们就得到了第二个错误。
Event Type: Error
Event Source: ASP.NET 2.0.50727.0
Event Category: None
Event ID: 1334
Date: 2008-02-11
Time: 11:13:15
User: N/A
Computer: PRATHER
Description:
An unhandled exception occurred and the process was terminated.
Application ID: /LM/W3SVC/1/Root/BuggyBits
Process ID: 4944
Exception: System.NullReferenceException
Message: Object reference not set to an instance of an object.
StackTrace: at Review.Finalize()
Q:这个0xe0434f4d 退出码什么意思?
A:这个错误代码是代表 dotnet异常的本地(原生)错误代码,任何dotnet的错误异常都会被转换成0xe0434f4d,无论dotnet 的错误是SQLException, NullReferenceException 还是 FileNotFoundException。
Q:你能说出是什么原因导致了崩溃的发生么?
A:在上面提及的例子中,第二个异常的事件报告说明了原应。进程的崩溃是因为没有被捕获的在finalizer 线程中的一个空引用的异常。
得到一个dump文件
1) 转到浏览器的http://localhost/BuggyBits/Reviews.aspx 这个页面,但不要点击刷新。
2) 打开一个命令行窗口,切换到调试器目录,输入:
adplus -crash -pn w3wp.exe
敲回车。
Q:一个新的windows窗口会出现在工具栏上,它是什么?
A:这是一个调试器,如果你最大化它,你会看见命令窗口,cdb正在运行,cdb是命令行方式下的WinDbg。
Q:调试器在等待什么?提示:查看 Adplus 有关crash的帮助。
A:下面是一个表格,显示了adplus监视器默认的 事件(events)/ 异常(exceptions),和它会做什么,当发生这些事件时。
一些缩写字母的含义:L=Log entry in debuglog, T=Record Time, S=Log stack, M=Mini dump, F=Full dump, E=log in the eventlog。你可以自己编写一个adplus 的配置文件,来改变这些事件被处理的方式。
Code |
Exception/Event |
Explanation/Note |
1st Chance |
2nd Chance |
av |
Access Violation |
An attempt to access to uninitialized memory. |
LTSM |
LTSFE |
ch |
Invalid Handle |
An attempt to access data using an invalid handle. Eg. window, file or other native handle. |
LTSM |
LTSFE |
ii |
Illegal Instruction |
An attempt is made to execute an invalid instruction. |
LTSM |
LTSFE |
dz |
Integer divide |
Integer divide by zero. Even in .net. |
LTSM |
LTSFE |
c000008e |
Floating divide |
Floating point divide by zero. |
LTSM |
LTSFE |
iov |
Integer overflow |
An attempt to store more than 32/64 bits in an integer. |
LTSM |
LTSFE |
lsq |
Invalid Lock Sequence |
An attempt is made to execute an invalid lock sequence. |
LTSM |
LTSFE |
sov |
Stack overflow |
The memory used for the stak (method pointers, parameters, local vars etc.) exceeds the amount allocated for the stack. Typically caused by recursion. |
LTSM |
LTSFE |
eh |
C++ EH exception |
C++ EH Exception |
LTS |
LTSFE |
* |
Unknown exception |
Any exception not specifically defined in this list |
LTS |
LTSFE |
clr |
.NET Exception |
Any .net exception |
- |
LTSFE |
bpe |
Breakpoint |
A break point is hit or the debugger window is shut down. |
LTSME |
- |
wkd |
Wake Debugger |
Wake debugger. |
LTSME |
- |
ld |
Dll Load |
A dll is loaded in the process |
L |
L |
ud |
Dll Unload |
A dll is unloaded from the process |
L |
L |
epr |
Exit Process |
The process exits. |
LTSFE |
- |
aph |
Application Hang |
The Windows OS has determined that the process is no longer responding. |
LTSM |
LTSFE |
cce |
Ctrl+C Console App |
Ctrl+C or Ctrl+Break is passed to a console app. |
LTSM |
LTSFE |
dm |
Data Misaligned |
A unit of data is read from or written to an address that is not a multiple of the data size. |
LTSM |
LTSFE |
gp |
Guard page violation |
An attempt to access data within a guard page. |
LTSM |
LTSFE |
ip |
In Page IO Error |
I/O Error |
LTSM |
LTSFE |
isc |
Invalid System Call |
Invalid System Call |
LTSM |
LTSFE |
sbo |
Stack Buffer overflow |
Stack buffer overflow |
LTSM |
LTSFE |
3) 再现问题,点击那个浏览器的刷新按钮。
Q:在dump目录下什么文件被创建了 ?提示:dump的文件夹在带有crash模式的名字和今天的日期时间的调试器路径下。
A :下面的文件是我的crash模式文件夹
ADPlus_report.txt
<DIR> CDBScripts
PID-4628__W3WP.EXE__Date_02-11-2008__Time_13-14-0808.log
Process_List.txt
PID-4628__W3WP.EXE__1st_chance_AccessViolation__mini_17a4_2008-02-11_13-14-19-358_1214.dmp
PID-4628__W3WP.EXE__1st_chance_Process_Shut_Down__full_17a4_2008-02-11_13-14-31-889_1214.dmp
PID-4628__W3WP.EXE__2nd_chance_NET_CLR__full_17a4_2008-02-11_13-14-20-093_1214.dmp
看看几个重点地地方:我们有一个1st(第一次)的违背正常访问 的mini dump(最小化dump,可能是我们的NullReferenceException)。紧跟在进程关闭(shutdown)dump文件后面,还有2nd(第二次)的CLR 异常(和NullReferenceException 一样,但是现在是2dn,因为它还没有被处理)。你可以通过按照时间排序的顺序来观察它们。
在WinDbg中打开dump文件
1) 打开带有“2nd Chance CLR Exception”这些字样的dump文件,注意到,这个dump文件在1st 的进程被shutdown后创建。注意:如果你有一个异常,你有再try/catch块中处理它们的机会。它第一次被抛出来,就成为1st 异常且不是致命的。如果你不处理它,它会变成2nd 异常,任何2nd的异常会中断进程。
2) 设置符号文件的路径。
在crash dump文件中,活动线程是导致异常的那个线程(因为dump是由一个异常触发)。
Q:哪一个线程是活动的,当你打开dump文件后?提示:看看WinDbg的命令提示符的工具栏
A:活动的线程是#20,我可以用它来和 !thread (输出是Finalizer 的线程)作比较,得到更多信息。
20 2 116c 001ac540 b220 Enabled 02f0d28c:02f0f130 00199400 0 MTA (Finalizer)
System.NullReferenceException (02f0cb3c)
在!thread 的输出中,我们还可以看出该线程抛出了NullReferenceException,这个异常的地址是0x02f0cb3c。
检查调用堆栈和异常
1) 检查本地(原生)和托管堆栈。
kb 2000
!clrstack
Q:线程是什么类型的?
A:从kb的输出中我们看到事实上是finalizer线程,但是!clrstack 并没有给我们完整的更多的有关托管堆栈的信息。看起来,我们是在异常处理代码的内部了。
0:020> kL 2000
ChildEBP RetAddr
02a0f9d8 79f071ac kernel32!RaiseException+0x53
02a0fa38 7a10733d mscorwks!RaiseTheExceptionInternalOnly+0x2a8
02a0fa50 7a1073b1 mscorwks!RaiseTheException+0x4e
02a0fa78 7a1073e2 mscorwks!RealCOMPlusThrowWorker+0x71
02a0faa4 7a1073f0 mscorwks!RealCOMPlusThrow+0x30
02a0fab4 7a14f0d4 mscorwks!RealCOMPlusThrow+0xd
02a0fbe4 7a025a5b mscorwks!Thread::RaiseCrossContextException+0x41f
02a0fc98 79f01747 mscorwks!Thread::DoADCallBack+0x293
02a0fcb8 79f04a71 mscorwks!ManagedThreadBase_DispatchInner+0x47
02a0fcc4 79f04b01 mscorwks!ManagedThreadBase::FinalizerAppDomain+0x25
02a0fd20 79efe5b4 mscorwks!SVR::DoOneFinalization+0x141
02a0fda8 79efe70a mscorwks!SVR::FinalizeAllObjects+0x56
02a0fdc0 79ef3207 mscorwks!SVR::GCHeap::FinalizerThreadWorker+0xe7
02a0fdd4 79ef31a3 mscorwks!ManagedThreadBase_DispatchInner+0x4f
02a0fe68 79ef30c3 mscorwks!ManagedThreadBase_DispatchMiddle+0xb1
02a0fea4 79fb9643 mscorwks!ManagedThreadBase_DispatchOuter+0x6d
02a0fecc 79fb960d mscorwks!ManagedThreadBase_NoADTransition+0x32
02a0fedc 79fd0c91 mscorwks!ManagedThreadBase::FinalizerBase+0xd
02a0ff14 79f95a2e mscorwks!SVR::GCHeap::FinalizerThreadStart+0xbb
02a0ffb8 7d4dfe21 mscorwks!Thread::intermediateThreadProc+0x49
02a0ffec 00000000 kernel32!BaseThreadStart+0x34
0:020> !clrstack
OS Thread Id: 0x116c (20)
ESP EIP
02a0fa8c 7d4e2366 [GCFrame: 02a0fa8c]
02a0faf0 7d4e2366 [GCFrame: 02a0faf0]
02a0fcec 7d4e2366 [GCFrame: 02a0fcec]
Q:线程在干什么?
A:它正在尝试调用对象的finalizer方法,正在做这个的时候,它抛出了一个异常,该异常正在被当作2nd的异常被再次抛出。
2) 检查异常抛出。
!pe 注意:!pe/!PrintException如果没有跟参数会打印出在栈上的当前所有异常。
Q:什么样的异常?
A:一个NullReferenceException 异常
0:020> !pe
Exception object: 02f0cb3c
Exception type: System.NullReferenceException
Message: Object reference not set to an instance of an object.
InnerException:
StackTrace (generated):
StackTraceString:
HResult: 80004003
注意:在一个案例中,比如在这里,异常被再次抛出,原先的栈跟踪可能会不可见,在这种情况下,如果你找到原先的异常你会得到更多的信息。
3)查看栈上的对象,找到原先的异常的地址
!dso
Q:原先异常的地址是什么?提示:看看你刚才的!pe 的输出的再次抛出的异常的对象的地址,把它和对象栈中的地址比较,你可能会有很多异常,一些是再次抛出的异常的地址,但在底部有一个异常,你看,那就是原先的异常(查找地址不同的那个)。
A:唯一的一个地址和前面列出的(0x2f0cb3c)不同的是0x6f1e5e4。
0:020> !dso
OS Thread Id: 0x116c (20)
ESP/REG Object Name
02a0f9f4 02f0cb3c System.NullReferenceException
02a0f9f8 02f0cb3c System.NullReferenceException
02a0fa40 02f0cb3c System.NullReferenceException
02a0fa58 02f0cb3c System.NullReferenceException
02a0faac 02f0cb3c System.NullReferenceException
02a0fabc 02f0cb3c System.NullReferenceException
02a0fb58 06f1e5e4 System.NullReferenceException
02a0fb5c 02f0bd70 System.Byte[]
02a0fb78 02f0cb3c System.NullReferenceException
02a0fb7c 02f0bd70 System.Byte[]
02a0fb8c 02f0bd70 System.Byte[]
02a0fc58 06eb281c System.RuntimeType
02a0fcb0 02efd4b0 Review
4)打印出原先的异常,查看输出的信息。
!pe <original exception address>
0:020> !pe 06f1e5e4
Exception object: 06f1e5e4
Exception type: System.NullReferenceException
Message: Object reference not set to an instance of an object.
InnerException:
StackTrace (generated):
SP IP Function
02A0F950 0FE90F24 App_Code_wbwztx_4!Review.Finalize()+0x14
StackTraceString:
HResult: 80004003
Q:在什么函数中异常被抛出?
A:在Review类中的finalizer/destructor 函数中。
Q:什么对象正在被结束?注意:你可能实际通过二次抛出的异常已经得到了信息,但通过 !pe original address 能得到更清晰的信息。
A:Review对象。
Q:正常情况下,ASP.NET 抛出的异常会被全局(global)的异常处理或由错误页面来显示给用户,但为什么这里会发生呢?为什么会导致崩溃呢?
A:asp.net 的全局异常处理函数仅仅会处理在处理一个请求过程出现的异常。在这个地方,异常发生在finalizer中,意思是:没有用户看到这个异常,因此信息不能发送给任何人。
在1.1 或者在2.0 中使用继承原先的1.1 的方式,在finalizer中的异常不是致命的。它不会导致进程崩溃,而是finalizer的行为会停止,这个是非常危险的,因为它意味着你没有处理的代码来释放本地(原生,非托管)的资源,因而你会以内存泄露的方式来结束一段程序。这个是非常难找到的错误,数据库连接等资源也会泄露。所有在finalizer线程中没有处理的异常都必须认真研究和认真对待。
检查代码,确认情况
1)打开Review.cs ,找到 销毁/终结(destructor/finalizer)的代码:
~Review()
{
if (quote.ToString() != string.Empty)
{
quote = null;
}
}
Q:哪一行的代码或方法导致了异常?
A:在这个例子中代码很简单,也很容易准确的找到问题,quote.ToString()的那个判断如果是if quote = null 则发生异常。