[Debug]三小时抛出了超过40000个异常,你注意到了没?

原文地址:blogs.msdn.com/tess/archive/2005/11/30/498297.aspx
版权归原文作者所有,转载请注明出处
三小时抛出了超过40000个异常,你注意到了没?
看起来很荒谬,不幸的是,这种情况非常常见.
工 作中,我检查许多内存转储,有时候每天5-20个.在得到足够的信息后,我经常快速检查应用程序抛出了多少异常以及异常的类型,以提醒客户注意.多数时 候,应用抛出的异常数量比开发人员预料的多;或者是预料中的异常但他们并不知道这些异常会导致问题出现,因为这些异常看起来不会对应用程序造成直接的影 响.
那么,为什么上面的做法非常不好? 想想如果一个非常严重的异常在后台被处理掉导致用户看不到异常,会怎样?
我想到的有三个原因:
异常是昂贵的
异常会进入不必要的代码路径
异常一般在出现问题时抛出
异常很昂贵
Chris Brumme 写了一片非常棒的关于异常工作原理的日志,叫做异常模型(The Exception Model ),如果有时间的话应该读一下(绝对值得).
该文列出了一些异常抛出时会发生的事情:
通过翻译编译器生成的元数据抓取堆栈跟踪,来指导如何展开堆栈.
在堆栈向上运行一个handler组成的链,调用每个handler两次
补偿SEH,C++以及托管异常之间的匹配错误.
分配一个托管异常实例并调用其构造器.大多数情况下,这牵涉到到资源中查找错误信息.
可能需要进入操作系统内核.通常是发生了硬件异常.
通知任何已经附加的调试器,探察器,向量异常处理器和其他相关部分.
try{
   Myvar = (myClass) myParameter;
}
catch (Exception ex){
   // do some stuff to handle the exception.
}
如 果myParameter为null,并且没有添加参数检查,这段代码导致应用程序执行上面列出的所有任务,另外有一个特殊的功能,应用程序还抛出一个额 外的1st chance access violation exception(在NullReferenceException中总是触发),所以上面列出的动作实际发生了两次.
在深入讨论之前,上面的代码有一点我不太喜欢:捕获了一个基类异常,没法知道捕获的是否是一个NullReferenceException异常,或许是一个需要用其他方式处理的其他类型异常.不过这样还是比直接吞掉异常什么都不做要好.
异常会导致进入不必要的代码路径
分 享一个很久之前做过的案例.客户的服务器工作比较正常,但客户并不完全满意希望我们帮他们找出潜在的瓶颈.在使用调试器附加上去之后,很快发现有一些异常 用户显然没有注意到.不幸的是,由于其中一个异常最后调用了一个不期望调用的函数.这个函数又调用了一些不同的服务.避免出现这种情况的检查非常简单,把 检查加上去之后,吞吐量增加了不少于20倍…他们对调整后的系统性能非常满意
一个常见的例子是:使用全局异常处理记录异常到事件日志,数据库或者文件时,抛出异常可能会导致阻塞.
别误解我的意思,异常一定要记录,但必须确定对异常的处理没有问题.如果3小时之内抛出了超过40000异常并且将其记录到数据库或事件日志,不仅日志很快被填满,而且会碰到很多争用写的问题.(尤其是事件日志或者文件,因为写操作一般是串行的)
异常一般在出现问题时抛出
如果异常一般在出现问题时抛出,那为什么问题出现的这么频繁 ?在前面的例子中,假设你预料参数为null几率为20%,很可能不是异常而是一个问题.
关于异常,好的思考方式是:异常应该仅在例外的情况下才发生.应该采取措施来避免意料之外的异常.可以考虑使用try/catch而不是用编程控制。
下面是如何知道发生了多少.net 异常以及为什么和在什么地方发生的…
性能监视器中可以监视以下计数器
.NET CLR Exceptions/#Exceps Thrown (异常总数) 以及
.NET CLR Exceptions/#Exceps Thrown / sec
来得知应用程序抛出了多少异常.
可以使用windbg.exe来了解抛出了什么异常,根据当前是生产环境还是压力测试环境,几种方式可供选择,以决定是否允许调试器进入并暂停进程一段时间.
这几种方式是:

发生
未处理异常时附加并中断至调试器
获取内存快照来分析当前异常
让调试器运行并记录异常

发生未处理异常时附加并中断至调试器
出于演示的目的我创建了一个webform,并且简单的在Page_Load中调用 throw new System.Exception(“Test”).
windbg.exe附加到w3wp.exe进程之后运行sxe CLR命令使调试器在.net异常时中断
在检查托管结构之前需要加载sos扩展(.load clr10\sos)然后敲按键开始.
一旦捕捉到第一个异常,在调试窗口汇会看到类似以下的显示:
(15c4.163c): CLR exception – code e0434f4d (first chance)
并且中断至Kernel32!RaiseException,这里是真正抛出CLR异常的native部分
这里我们可以用下面的命令来得知是什么异常以及从什么地方抛出
!cen(CheckExceptionName来打印异常类型以及地址)
0:005> !cen
System.Exception (0x642e134)
以及!clrstack(打印托管栈)
0:005> !clrstack
Thread 5
ESP         EIP     
0x0c1bf6e4  0x77e55dea [FRAME: HelperMethodFrame]
0x0c1bf710  0x0c2e0528 [DEFAULT] [hasThis] Void ExceptionsAndStuff.WebForm1.Page_Load(Object,Class System.EventArgs)
  at [+0x30] [+0x0] c:\inetpub\wwwroot\exceptionsandstuff\webform1.aspx.cs:21
0x0c1bf728  0x0c3192dc [DEFAULT] [hasThis] Void System.Web.UI.Control.OnLoad(Class System.EventArgs)
0x0c1bf738  0x0c319224 [DEFAULT] [hasThis] Void System.Web.UI.Control.LoadRecursive()
0x0c1bf74c  0x0c3184d7 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequestMain()
0x0c1bf790  0x0c317207 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest()
0x0c1bf7cc  0x0c316c73 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest(Class System.Web.HttpContext)
0x0c1bf7d4  0x0c316c4c [DEFAULT] [hasThis] Void System.Web.HttpApplication/CallHandlerExecutionStep.System.Web.HttpApplication+IExecutionStep.Execute()
0x0c1bf7e4  0x0c1d98b8 [DEFAULT] [hasThis] Class System.Exception System.Web.HttpApplication.ExecuteStep(Class IExecutionStep,ByRef Boolean)
0x0c1bf82c  0x0c1d9322 [DEFAULT] [hasThis] Void System.Web.HttpApplication.ResumeSteps(Class System.Exception)
0x0c1bf874  0x0c1d91eb [DEFAULT] [hasThis] Class System.IAsyncResult System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(Class System.Web.HttpContext,Class System.AsyncCallback,Object)
0x0c1bf890  0x01eb6897 [DEFAULT] [hasThis] Void System.Web.HttpRuntime.ProcessRequestInternal(Class System.Web.HttpWorkerRequest)
0x0c1bf8cc  0x01eb6448 [DEFAULT] Void System.Web.HttpRuntime.ProcessRequest(Class System.Web.HttpWorkerRequest)
0x0c1bf8d8  0x01eb2fc5 [DEFAULT] [hasThis] I4 System.Web.Hosting.ISAPIRuntime.ProcessRequest(I,I4)
0x0c1bf9a0  0x79217188 [FRAME: ContextTransitionFrame]
0x0c1bfa80  0x79217188 [FRAME: ComMethodFrame]
输出部分告诉我们ExceptionsAndStuff.WebForm1.Page_Load 抛出了System.Exception异常(在设置web.config中的Debug=true之后我们还可以看到页面名称以及行号)
输入gn(运行至未处理的异常)继续调试
在 初始异常之后如果继续,将得到两个附加的异常,第一个是System.UI.Page.HandleError中的 System.Web.HttpUnhandledException,接着是System.Web.UI.Page.ProcessRequest中的 System.Web.HttpUnhandledException。现在明白为什么看起来简单的异常会导致三次调用异常处理了把.
调试技巧:考虑运行下面的命令使调试更加自动化:
sxe -c "!cen;!clrstack;gn" CLR
这个命令中断到CLR异常,运行!cen,!clrstack然后继续,每一个异常都可以获得其类型以及调用堆栈。
获取一个内存快照查看当前异常
如果希望查看生产系统,要是记录了太多抛出的异常会显著降低应用程序的速度,可以使用adplus获取一个hang模式转储来得到许多信息,命令如下:
adplus -hang –pn <PROCESSNAME.EXE>
加载了转储文件以及sos.dll后,运行!dumpallexceptions(简写为!dae),将显示目当前堆上的所有异常对象,也就是所有还没有被垃圾搜集的异常对象,同时显示异常的类型.!dae给出的是统计信息,独立显示异常使用!dae -v(详细模式)
每次运行!dae你会注意到顶部有4个异常.NotSupportedException、ExecutionEngineException、StackOverflowException和
OutOfMemoryException,这并不意味着抛出了这些异常.绝大多数情况下,可以忽略这些.
往下,可以看到HttpResponse.Redirect/HttpResponse.End中有3个ThreadAbortException以及尝试填充数据集的时候有4个SQLException.
一个redirect总是抛出一个ThreadAbortException,因为此时需要停止执行当前页面,可以将false作为redirect方法的参数来避免这个异常,但这当然会导致当前页面继续执行.
0:000> !dae
Number of exceptions of this type:        1
Exception 0x151ce76c in MT 0x79bf44d4: System.NotSupportedException
_message: Specified method is not supported.
—————–
Number of exceptions of this type:        1
Exception 0x180000bc in MT 0x79b94ee4: System.ExecutionEngineException
—————–
Number of exceptions of this type:        1
Exception 0x1800007c in MT 0x79b94dac: System.StackOverflowException
—————–
Number of exceptions of this type:        1
Exception 0x1800003c in MT 0x79b94c74: System.OutOfMemoryException
—————–
Number of exceptions of this type:        3
Exception 0x28a74114 in MT 0x79bf881c: System.Threading.ThreadAbortException
_message: Thread was being aborted.
_stackTrace:
0x00000000
0x00000000
0x79bb8a00
0x79a29496 [DEFAULT] [hasThis] Void System.Threading.Thread.Abort(Object)
0x0e54eec8
0x79bb8e68
0x030c28fa [DEFAULT] [hasThis] Void System.Web.HttpResponse.End()
0x0e54eecc
0x0200cbe0
0x030c2075 [DEFAULT] [hasThis] Void System.Web.HttpResponse.Redirect(String,Boolean)
0x0e54eee0
0x0200cab0
0x02e2c898 [DEFAULT] [hasThis] Void ExceptionsAndStuff.WebForm1.Page_Load(Object,Class System.EventArgs)
0x0e54eefc
0x02a4af50
—————–
Number of exceptions of this type:        4
Exception 0x077cf420 in MT 0x02b84e9c: System.Data.SQLClient.SqlException
_message: System error.
_stackTrace:
0x02bf9f18 [DEFAULT] [hasThis] Boolean System.Data.SqlClient.SqlDataReader.Read()
0x0dd1ecf4
0x02b85de8
0x02fe432f [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.FillLoadDataRow(Class System.Data.Common.SchemaMapping)
0x0dd1ed60
0x02e43110
0x02e2f9cc [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.FillFromReader(Object,String,Class System.Data.IDataReader,I4,I4,Class System.Data.DataColumn,Object)
0x0dd1ed50
0x02e430f0
0x02e2f849 [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.Fill(Class System.Data.DataSet,String,Class System.Data.IDataReader,I4,I4)
0x0dd1edec
0x02e430c0
0x02e2f688 [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.FillFromCommand(Object,I4,I4,String,Class System.Data.IDbCommand,ValueClass System.Data.CommandBehavior)
0x0dd1edc8
0x02e430b0
0x02e2f4d5 [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.Fill(Class System.Data.DataSet,I4,I4,String,Class System.Data.IDbCommand,ValueClass System.Data.CommandBehavior)
0x0dd1ee60
0x02e43090
0x02fe7e96 [DEFAULT] [hasThis] I4 System.Data.Common.DbDataAdapter.Fill(Class System.Data.DataSet)
0x0dd1ee88
0x02e43060
0x036ed5f4 [DEFAULT] [hasThis] Class System.Data.DataSet ExceptionsAndStuff.DBLib.GetData(I4)
0x0dd1ee94
0x029ff6d8
总共375个异常
SqlException的错误信息为system error,用处不大.SqlException有点特殊因为真实信息保存在异常外部一个错误对象中,所以最好是用!dumpobj命令单独查看对象的地址
0:000> !dumpobj 0x077cf420
Name: System.Data.SqlClient.SqlException
MethodTable 0x02b84e9c
EEClass 0x02af9340
Size 68(0x44) bytes
GC Generation: 2
mdToken: 0x020001c4  (c:\windows\assembly\gac\system.data\1.0.5000.0__b77a5c561934e089\system.data.dll)
FieldDesc*: 0x02b84d98
        MT      Field     Offset                 Type       Attr      Value Name
0x79b947ac 0x4000029     0x34         System.Int32   instance 0 _xptrs
0x79b947ac 0x400002a     0x38         System.Int32   instance -532459699 _xcode
0x02b84e9c 0x4000fb5     0x3c                CLASS   instance 0x077cf464 _errors
—————–
Exception 0x077cf420 in MT 0x02b84e9c: System.Data.SqlClient.SqlException
_message: System error.
_stackTrace:
0x02bf9f18 [DEFAULT] [hasThis] Boolean System.Data.SqlClient.SqlDataReader.Read()
然后把_errors对象dump下来(用下面的地址0x077cf464作为参数)
0:000> !dumpobj 0x077cf464
Name: System.Data.SqlClient.SqlErrorCollection
MethodTable 0x02b8500c
EEClass 0x02af93a4
Size 12(0xc) bytes
GC Generation: 2
mdToken: 0x020001c3  (c:\windows\assembly\gac\system.data\1.0.5000.0__b77a5c561934e089\system.data.dll)
FieldDesc*: 0x02b84f2c
        MT      Field     Offset                 Type       Attr      Value Name
0x02b8500c 0x4000fb4      0x4                CLASS   instance 0x077cf470 errors
0:000> !dumpobj 0x077cf470
Name: System.Collections.ArrayList
MethodTable 0x79ba0d74
EEClass 0x79ba0eb0
Size 24(0x18) bytes
GC Generation: 2
mdToken: 0x020000ff  (c:\windows\microsoft.net\framework\v1.1.4322\mscorlib.dll)
FieldDesc*: 0x79ba0f14
        MT      Field     Offset                 Type       Attr      Value Name
0x79ba0d74 0x400035b      0x4                CLASS   instance 0x077cf488 _items
0x79ba0d74 0x400035c      0xc         System.Int32   instance 1 _size
0x79ba0d74 0x400035d     0x10         System.Int32   instance 1 _version
0x79ba0d74 0x400035e      0x8                CLASS   instance 0x00000000 _syncRoot
0:000> !dumpobj -v 0x077cf488
Name: System.Object[]
MethodTable 0x01a2209c
EEClass 0x01a22018
Size 80(0x50) bytes
GC Generation: 2
Array: Rank 1, Type CLASS
Element Type: System.Object
Content: 16 items
—— Will only dump out valid managed objects —-
   Address            MT    Class Name
0x077cf400    0x02b851a4    System.Data.SqlClient.SqlError
———-
0:000> !do 0x077cf400
Name: System.Data.SqlClient.SqlError
MethodTable 0x02b851a4
EEClass 0x02af9408
Size 32(0x20) bytes
GC Generation: 2
mdToken: 0x020001c2  (c:\windows\assembly\gac\system.data\1.0.5000.0__b77a5c561934e089\system.data.dll)
FieldDesc*: 0x02b85090
        MT      Field     Offset                 Type       Attr      Value Name
0x02b851a4 0x4000fad      0x4                CLASS   instance 0x10015bb0 source
0x02b851a4 0x4000fae     0x10         System.Int32   instance 1205 number
0x02b851a4 0x4000faf     0x18          System.Byte   instance 61 state
0x02b851a4 0x4000fb0     0x19          System.Byte   instance 13 errorClass
0x02b851a4 0x4000fb1      0x8                CLASS   instance 0x077cf28c message
0x02b851a4 0x4000fb2      0xc                CLASS   instance 0x077cf3c8 procedure
0x02b851a4 0x4000fb3     0x14         System.Int32   instance 22 lineNumber
0:000> !do 0x077cf28c
Name: System.String
MethodTable 0x79b925c8
EEClass 0x79b92914
Size 316(0x13c) bytes
GC Generation: 2
mdToken: 0x0200000f  (c:\windows\microsoft.net\framework\v1.1.4322\mscorlib.dll)
String: Transaction (Process ID 104) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
FieldDesc*: 0x79b92978
        MT      Field     Offset                 Type       Attr      Value Name
0x79b925c8 0x4000013      0x4         System.Int32   instance 150 m_arrayLength
0x79b925c8 0x4000014      0x8         System.Int32   instance 149 m_stringLength
0x79b925c8 0x4000015      0xc          System.Char   instance 0x54 m_firstChar
0x79b925c8 0x4000016        0                CLASS     shared   static Empty
    >> Domain:Value 0x000abfc8:0x18000224 0x00163890:0x18000224 <<
0x79b925c8 0x4000017      0x4                CLASS     shared   static WhitespaceChars
    >> Domain:Value 0x000abfc8:0x18000238 0x00163890:0x14005924 <<
可以看到,能搜集到很多信息,比如存储过程名字等.
现在,假设某函数有一个NullReferenceException,但你并不知道真正在函数的哪个地方或者什么可能为null
0:000> !dumpobj 0x3d86c980
Name: System.NullReferenceException
—————–
Exception 0x3d86c980 in MT 0x79c04e64: System.NullReferenceException
_message: Object reference not set to an instance of an object.
_stackTrace:
0x2fa0536b [DEFAULT] [hasThis] Void ExceptionsAndStuff.WebForm1. btnAdd_Click(Object,Class System.EventArgs)
0x0c10f844
0x0f64be20
0x189b51ec [DEFAULT] [hasThis] Void System.Web.UI.WebControls.LinkButton.OnClick(Class System.EventArgs)
0x0c10f854
0x0e124f00
0x189b4f72 [DEFAULT] [hasThis] Void System.Web.UI.WebControls.LinkButton.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(String)
0x0c10f868
0x0e124f60
0x189b4f22 [DEFAULT] [hasThis] Void System.Web.UI.Page.RaisePostBackEvent(Class System.Web.UI.IPostBackEventHandler,String)
0x0c10f878
0x0c2a1308
0x189b4eea [DEFAULT] [hasThis] Void System.Web.UI.Page.RaisePostBackEvent(Class System.Collections.Specialized.NameValueCollection)
0x0c10f880
0x0c2a12f8
0x10920612 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequestMain()
0x0c10f890
0x0c2a14d8
堆栈顶部的地址显示了代码发生异常的准确位置(在这个例子中是btnAdd_Click),可以使用!u来反汇编函数看这个位置到底做了什么.
0:000> !u 0x2fa0536b
Will print '>>> ' at address: 0x2fa0536b
Normal JIT generated code
[DEFAULT] [hasThis] Void ExceptionsAndStuff.WebForm1.btnAdd_Click (Object,Class System.EventArgs)
Begin 0x2fa05358, size 0x9d
2fa05358 57               push    edi
2fa05359 56               push    esi
2fa0535a 8bf1             mov     esi,ecx
2fa0535c 8b8e68010000     mov     ecx,[esi+0x168]
2fa05362 3909             cmp     [ecx],ecx
2fa05364 e8cf4313f7       call    26b39738 (System.Web.UI.HtmlControls.HtmlInputFile.get_PostedFile)
2fa05369 8bc8             mov     ecx,eax
>>> 2fa0536b 3909             cmp     [ecx],ecx
2fa0536d e8464613f7       call    26b399b8 (System.Web.HttpPostedFile.get_ContentLength)
2fa05372 3b053c8b640f     cmp     eax,[0f648b3c]
2fa05378 7e04             jle     2fa0537e
2fa0537a 33c0             xor     eax,eax
2fa0537c eb05             jmp     2fa05383
2fa0537e b801000000       mov     eax,0x1
2fa05383 25ff000000       and     eax,0xff
2fa05388 7448             jz      2fa053d2
2fa0538a 8bbe68010000     mov     edi,[esi+0x168]
2fa05390 8b8e98010000     mov     ecx,[esi+0x198]
2fa05396 8b01             mov     eax,[ecx]
2fa05398 ff90c4010000     call    dword ptr [eax+0x1c4]
2fa0539e 50               push    eax
2fa0539f 6aff             push    0xff
2fa053a1 8bd7             mov     edx,edi
2fa053a3 8bce             mov     ecx,esi
2fa053a5 ff1520c1640f     call    dword ptr [0f64c120]

从这儿,可以看出,调用了HtmlInputFile对象PostedFile属性的get方法,然后从eax移动到ecx(eax通常包含函数的返回值),
然 后将比较对象的引用,接着就抛出了异常.不需要精通汇编指令就可以知道问题的大概并确推断出PostedFile为null并确在尝试访问 ContentLength属性时抛出了异常.如果有源码的话就更容易找到问题了.这里只需要加入PostedFile是否为null的检查就可以放心.

让调试器自己运行并记录异常

下面展示一个让调试器运行并确记录日志的办法,不过有时候web管理员或其他有需要的人用脚本来做更方便.
创建一个叫做TrackCLR.cfg的配置文件,内容如下:
<ADPLUS>
  <SETTINGS>
   <RUNMODE>CRASH</RUNMODE>
  </SETTINGS>
  <PRECOMMANDS>
   <CMD>!load clr10\sos</CMD>
  </PRECOMMANDS>
  <EXCEPTIONS>
   <OPTION>NoDumpOnFirstChance</OPTION>
   <OPTION>NoDumpOnSecondChance</OPTION>
   <CONFIG><!– This is for the CLR exception –>
    <CODE>clr</CODE>
    <ACTIONS1>Log</ACTIONS1>
    <CUSTOMACTIONS1>!cen;!clrstack;gn </CUSTOMACTIONS1>
    <RETURNACTION1>GN</RETURNACTION1>
   </CONFIG>
  </EXCEPTIONS>
</ADPLUS>
然后执行adplus –pn myprocess.exe –c TrackCLR.cfg
这个命令会在调试器目录下产生一个日志文件,记录每个.net异常的托管栈以及异常类型.
或者更进一步,使用下面示例配置文件,在特定的异常发生时创建一个内存转储文件:
<ADPLUS>
  <SETTINGS>
   <RUNMODE>CRASH </RUNMODE>
  </SETTINGS>
  <PRECOMMANDS>
   <CMD>!load clr10\sos </CMD>
  </PRECOMMANDS>
  <EXCEPTIONS>
   <OPTION>NoDumpOnFirstChance </OPTION>
   <OPTION>NoDumpOnSecondChance </OPTION>
   <CONFIG><!– This is for the CLR exception –>
    <CODE>clr </CODE>
    <ACTIONS1>Log </ACTIONS1>
    <CUSTOMACTIONS1>!clr10\sos.cce System.InvalidOperationException 1; j ($t1 = 1) '.dump /ma /u c:\temp_dumps\exceptiondump.dmp;gn' ; 'gn' </CUSTOMACTIONS1>
    <RETURNACTION1>GN </RETURNACTION1>
    <ACTIONS2>Void </ACTIONS2>
    <RETURNACTION2>GN </RETURNACTION2>
   </CONFIG>
  </EXCEPTIONS>
</ADPLUS>
cce命令根据CLR异常是否匹配指定的类型来设置$t1 为1或0.(如果传入的为1,那么用后面的命令作为cce命令的第二个参数,这里可以选择用t1或者t0)
j ($t1 = 1) 是一个if语句,所以要是$t1设置为1就会进行转储,否则直接跳过

赞(0) 打赏
分享到: 更多 (0)

觉得文章有用就打赏一下文章作者

支付宝扫一扫打赏

微信扫一扫打赏