A .NET Crash: How not to write a global exception handler
I’ve written quite a few posts on memory issues because that is the type of problem we get most frequently in support, but I thought I’d break it up a little bit with a post on a crash scenario.
This is a problem that I have seen a number of times in cases throughout the years and it also turns out to be a pretty nice sample for showing how to debug a stackoverflow crash in .net.
Problem description
From time to time ASP.NET crashes with the following event in the eventlog:
Event Type: Warning
Event Source: W3SVC
Event Category: None
Event ID: 1009
Date: 2006-02-06
Time: 9:45:34
User: N/A
Computer: SUBSPACE1
Description:
A process serving application pool 'AppPool #3' terminated unexpectedly. The
process id was '1956'. The process exit code was '0x800703e9'.
For more information, see Help and Support Center at
https://go.microsoft.com/fwlink/events.asp.
Other than this we don’t really have much information about what caused the web application to crash.
Gathering information
If we take a look at the exit code (0x800703e9) in ErrorLookup that comes with Visual Studio we can see that this means “Recursion too deep; the stack overflowed.”
The best way to proceed is to take a dump in crash mode of the w3wp.exe process since this is IIS6.0 (would have been aspnet_wp.exe on IIS 5.0) to see what really happened. See the back to basics post for how to gather a crash mode dump.
Debugging the problem
If I take a look at the “Crash_Mode__Date_02-06-2006__Time_10-41-5353” folder generated under my debuggers directory for this crash I find the following files:
2006-02-06 10:42 <DIR> .
2006-02-06 10:42 <DIR> ..
2006-02-06 10:41 4 476 ADPlus_report.txt
2006-02-06 10:41 <DIR> CDBScripts
2006-02-06 10:42 5 544 489 PID-4560__W3WP.EXE_-AppPool_#3-__1st_chance_AccessViolation__mini_0C30_2006-02-06_10-42-55-232_11D0.dmp
2006-02-06 10:43 71 806 954 PID-4560__W3WP.EXE_-AppPool_#3-__1st_chance_Process_Shut_Down__full_0C30_2006-02-06_10-42-59-200_11D0.dmp
2006-02-06 10:42 5 494 789 PID-4560__W3WP.EXE_-AppPool_#3-__1st_chance_StackOverflow__mini_0C30_2006-02-06_10-42-50-638_11D0.dmp
2006-02-06 10:43 177 874 PID-4560__W3WP.EXE_-AppPool_#3-__Date_02-06-2006__Time_10-41-5353.log
2006-02-06 10:41 11 603 Process_List.txt
6 File(s) 83 040 185 bytes
3 Dir(s) 11 292 479 488 bytes free
So if we couldn’t figure it out from the eventlog entry we now have evidence in black and white that our shutdown occurred because of a StackOverFlow. (If you want to check out some other reasons a .net process can crash, check out my post on reasons for .net crashses)
Stack overflow exceptions are usually the easiest ones to debug since we pretty much know that we are going to have a stack in the dump with some kind of recursive loop, and it’s just a matter of finding the recursion and why it occurred. And better yet:) they are often the easiest ones to fix too…
As a side note:
If we open a crash mode dump in windbg the debugger will be nice enough to position us on the thread that caused the problem.
If we ever move away from this thread and forgot what thread it was we can run ~ to display all threads, and the “crashing” thread will be marked with a dot (in this case thread #3).
0:003> ~
0 Id: 1054.c30 Suspend: 1 Teb: 7ffde000 Unfrozen
1 Id: 1054.808 Suspend: 1 Teb: 7ffdc000 Unfrozen
2 Id: 1054.113c Suspend: 1 Teb: 7ffdb000 Unfrozen
. 3 Id: 1054.ba0 Suspend: 1 Teb: 7ffdd000 Unfrozen
4 Id: 1054.1544 Suspend: 1 Teb: 7ffd9000 Unfrozen
5 Id: 1054.2f0 Suspend: 1 Teb: 7ffda000 Unfrozen
6 Id: 1054.310 Suspend: 1 Teb: 7ffd8000 Unfrozen
7 Id: 1054.1554 Suspend: 1 Teb: 7ffd7000 Unfrozen
8 Id: 1054.1328 Suspend: 1 Teb: 7ffd6000 Unfrozen
9 Id: 1054.ed0 Suspend: 1 Teb: 7ffd5000 Unfrozen
So that we can move back to the faulting thread with ~3s (set thread 3)
If we look at the dump names above we can see here that it only generated a mini dump for StackOverflow so we will not be able to get to much managed data and call stacks in this dump, but instead we can make use of the Process_Shut_Down full dump to find out what happened.
Usually a process exit dump will only have one live thread (Thread 0) since all the other threads are killed during shutdown, but this is enough for us in the case of a stack overflow since the live thread will be the one that suffered the stackoverflow exception.
A quick note here: Even though the thread ID was 3 in the stackoverflow and 0 in the process shutdown dump it is the same thread. Logical thread ID's can change between dumps as threads are created and killed.
If we take a look what this thread (Thread 0) is doing with kb 2000 we can see that it is mostly doing managed stuff (since most of the function names start with mscorlib_79990000 which is the native image for mscorlib)
0:000> kb 2000
ChildEBP RetAddr Args to Child
01a025e8 7c822034 77e5300a ffffffff 800703e9 ntdll!KiFastSystemCallRet
01a025ec 77e5300a ffffffff 800703e9 00000000 ntdll!NtTerminateProcess+0xc
01a026e0 77e5304d 800703e9 77e8f3b0 ffffffff kernel32!_ExitProcess+0x63
01a026f4 792ba702 800703e9 00000000 01a02ba4 kernel32!ExitProcess+0x14
01a02704 792ba8b8 000dd4a0 00000010 01a02824 mscorsvr!FailFast+0x114
01a02718 7c34246e 01a02740 00000000 01a02740 mscorsvr!ComPlusCoopFrameSEH+0x7e
01a02740 7c82eeb2 01a02824 01a02b94 01a02838 msvcr71!_except_handler3+0x61
01a02764 7c82ee84 01a02824 01a02b94 01a02838 ntdll!ExecuteHandler2+0x26
01a0280c 7c82ecc6 01a01000 01a02838 01a02824 ntdll!ExecuteHandler+0x24
01a0280c 77e55dea 01a01000 01a02838 01a02824 ntdll!KiUserExceptionDispatcher+0xe
01a02b58 792ba88e e0434f4d 00000001 00000000 kernel32!RaiseException+0x53
01a02ba4 792ba929 00000040 01aa11ec 792666c4 mscorsvr!ComPlusCoopFrameSEH+0x54
01a02bb0 792666c4 00000000 00000000 01a03194 mscorsvr!FatalInternalError+0xd
01a02bd4 79214e23 01a02cec 01a03194 01a02d08 mscorsvr!GetPrevSEHRecord+0x6b4
01a02bec 7924daf6 01a02cec 01a03194 01a02d08 mscorsvr!COMPlusFrameHandler+0x3d
01a02c08 7c82eeb2 01a02cec 01a03194 01a02d08 mscorsvr!COMPlusNestedExceptionHandler+0x57
01a02c2c 7c82ee84 01a02cec 01a03194 01a02d08 ntdll!ExecuteHandler2+0x26
01a02cd4 7c82ecc6 01a01000 01a02d08 01a02cec ntdll!ExecuteHandler+0x24
01a02cd4 7924c8b9 01a01000 01a02d08 01a02cec ntdll!KiUserExceptionDispatcher+0xe
01a03030 79aa8b62 0659bc04 00000004 799b4cf9 mscorsvr!JIT_Throw+0x31
WARNING: Stack unwind information not available. Following frames may be wrong.
01a030c0 799b47cd 00000000 0659ba7c 00000000 mscorlib_79990000+0x118b62
01a030e8 799b4720 00001000 00000001 00000002 mscorlib_79990000+0x247cd
01a03108 799b4662 01a03170 0659b944 0239f868 mscorlib_79990000+0x24720
01a0311c 79ab3a43 00000400 0659ba18 00000001 mscorlib_79990000+0x24662
01a03184 799b4720 01a0320c 0c1907e0 01a03230 mscorlib_79990000+0x123a43
01a03220 799b4720 01a032a8 0c1907e0 01a032cc mscorlib_79990000+0x24720
01a032bc 799b4720 01a03344 0c1907e0 01a03368 mscorlib_79990000+0x24720
01a03358 799b4720 01a033e0 0c1907e0 01a03404 mscorlib_79990000+0x24720
01a033f4 799b4720 01a0347c 0c1907e0 01a034a0 mscorlib_79990000+0x24720
01a03490 799b4720 01a03518 0c1907e0 01a0353c mscorlib_79990000+0x24720
01a0352c 799b4720 01a035b4 0c1907e0 01a035d8 mscorlib_79990000+0x24720
01a035c8 799b4720 01a03650 0c1907e0 01a03674 mscorlib_79990000+0x24720
01a03664 799b4720 01a036ec 0c1907e0 01a03710 mscorlib_79990000+0x24720
01a03700 799b4720 01a03788 0c1907e0 01a037ac mscorlib_79990000+0x24720
01a0379c 799b4720 01a03824 0c1907e0 01a03848 mscorlib_79990000+0x24720
01a03838 799b4720 01a038c0 0c1907e0 01a038e4 mscorlib_79990000+0x24720
01a038d4 799b4720 01a0395c 0c1907e0 01a03980 mscorlib_79990000+0x24720
01a03970 799b4720 01a039f8 0c1907e0 01a03a1c mscorlib_79990000+0x24720
01a03a0c 799b4720 01a03a94 0c1907e0 01a03ab8 mscorlib_79990000+0x24720
01a03aa8 799b4720 01a03b30 0c1907e0 01a03b54 mscorlib_79990000+0x24720
01a03b44 799b4720 01a03bcc 0c1907e0 01a03bf0 mscorlib_79990000+0x24720
01a03be0 799b4720 01a03c68 0c1907e0 01a03c8c mscorlib_79990000+0x24720
…
In a stack overflow scenario we disregard the top of the stack and instead we look for a recursive pattern (something that happens over and over) such as the constant calls to mscorlib_79990000+0x24720 in this case.
So let’s take a closer look at the managed stack by running !clrstack on this thread
0:000> !clrstack
Loaded Son of Strike data table version 5 from "C:\WINDOWS\Microsoft.NET\Framework\v1.1.4322\mscorsvr.dll"
Thread 0
ESP EIP
0x01a0300c 0x7c82ed54 [FRAME: HelperMethodFrame]
0x01a03038 0x79aa8b62 [DEFAULT] Void System.IO.__Error.WinIOError(I4,String)
0x01a03044 0x799b4cf9 [DEFAULT] [hasThis] Void System.IO.FileStream..ctor(String,ValueClass System.IO.FileMode,ValueClass System.IO.FileAccess,ValueClass System.IO.FileShare,I4,Boolean,String,Boolean)
0x01a03060 0x799b47cd [FRAME: InlinedCallFrame]
0x01a030e4 0x799b47cd [DEFAULT] [hasThis] Void System.IO.FileStream..ctor(String,ValueClass System.IO.FileMode,ValueClass System.IO.FileAccess,ValueClass System.IO.FileShare,I4)
0x01a03100 0x799b4720 [DEFAULT] Class System.IO.Stream System.IO.StreamWriter.CreateFile(String,Boolean)
0x01a03110 0x799b4662 [DEFAULT] [hasThis] Void System.IO.StreamWriter..ctor(String,Boolean,Class System.Text.Encoding,I4)
0x01a03130 0x79ab3a43 [DEFAULT] [hasThis] Void System.IO.StreamWriter..ctor(String,Boolean)
0x01a03140 0x0c190785 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03178 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03194 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03214 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03230 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a032b0 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a032cc 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a0334c 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03368 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a033e8 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03404 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03484 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a034a0 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03520 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a0353c 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a035bc 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a035d8 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03658 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03674 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a036f4 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a03710 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a03790 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
...
If we disregard the top of the stack for a moment we can see that we are moving between the functions CrashingWebSite.ExceptionHandler.LogException and CrashingWebSite.Utility.WriteToFile, so the LogException function calls WriteToFile and the WriteToFile function calls the LogException function in a seemingly never ending loop.
Well technically it is not “never ending”. It ends when we finally run out of stack space and get a fatal stackoverflow exception that crashes our process. Depending on operative system and application the stack space allotted per thread may differ a little, but 1MB per thread is pretty common.
So let’s take a peak at what happened:
I wrote an exception handling class that has a function LogException
public static void LogException(System.Exception e, String function)
{
Utility.WriteToFile(e.Message + " at " + function, "c:\\errorlog.txt");
}
In the exception handling class I make use of a utility library to write the messages to file.
Since I’ve made it a standard to log all exceptions with the ExceptionHandler routines, of course I do this in the utility library as well:)
public static void WriteToFile(String Message, String Path)
{
try{
using(StreamWriter sw = new StreamWriter(Path, true))
{
sw.WriteLine(Message);
}
}
catch(Exception ex){
ExceptionHandler.LogException(ex, "Utility.WriteToFile");
}
}
So if there is ever an exception in the WriteToFile function we get into a recursive loop like the one above.
This might seem like a silly mistake, but it’s one that easily happens if different people in the project team write the utility libraries and exception handlers.
Specifically what caused the recursion was that we got an UnathorizedAccessException when creating the file (actually a number of them, one per iteration)
0:000> !dso
Thread 0
ESP/REG Object Name
0x01a02c6c 0x0659baa8 System.String c:\errorlog.txt
0x01a02c74 0x0659bd08 System.UnauthorizedAccessException
0x01a02da4 0x0659baa8 System.String c:\errorlog.txt
0x01a02da8 0x0659bd08 System.UnauthorizedAccessException
0x01a02dac 0x0659baa8 System.String c:\errorlog.txt
0x01a02fd4 0x0659bd08 System.UnauthorizedAccessException
0x01a02fdc 0x0659baa8 System.String c:\errorlog.txt
...
If we dump it out we can see that we got an access denied to c:\errorlog.txt
0:000> !do 0x0659bd08
Name: System.UnauthorizedAccessException
MethodTable 0x79bf7fec
EEClass 0x79bf8064
Size 64(0x40) bytes
GC Generation: 0
mdToken: 0x020000d4 (c:\windows\microsoft.net\framework\v1.1.4322\mscorlib.dll)
FieldDesc*: 0x00000000
MT Field Offset Type Attr Value Name
0x79b96824 0x400001d 0x4 CLASS instance 0x00000000 _className
0x79b96824 0x400001e 0x8 CLASS instance 0x00000000 _exceptionMethod
0x79b96824 0x400001f 0xc CLASS instance 0x00000000 _exceptionMethodString
0x79b96824 0x4000020 0x10 CLASS instance 0x0659be2c _message
0x79b96824 0x4000021 0x14 CLASS instance 0x00000000 _innerException
0x79b96824 0x4000022 0x18 CLASS instance 0x00000000 _helpURL
0x79b96824 0x4000023 0x1c CLASS instance 0x00000000 _stackTrace
0x79b96824 0x4000024 0x20 CLASS instance 0x00000000 _stackTraceString
0x79b96824 0x4000025 0x24 CLASS instance 0x00000000 _remoteStackTraceString
0x79b96824 0x4000026 0x2c System.Int32 instance 0 _remoteStackIndex
0x79b96824 0x4000027 0x30 System.Int32 instance -2147024891 _HResult
0x79b96824 0x4000028 0x28 CLASS instance 0x00000000 _source
0x79b96824 0x4000029 0x34 System.Int32 instance 0 _xptrs
0x79b96824 0x400002a 0x38 System.Int32 instance -532459699 _xcode
-----------------
Exception 0659bd08 in MT 79bf7fec: System.UnauthorizedAccessException
_message: Access to the path "c:\errorlog.txt" is denied.
Some times it can be interesting to find out what started the recursive loop. If we look at the bottom of !clrstack in this case we will see...
...
0x01a3f6b8 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a3f6d4 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a3f754 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)
0x01a3f770 0x0c1907e0 [DEFAULT] Void CrashingWebSite.Utility.WriteToFile(String,String)
0x01a3f7f0 0x0c19072c [DEFAULT] Void CrashingWebSite.ExceptionHandler.LogException(Class System.Exception,String)<br>0x01a3f80c 0x0c1906d1 [DEFAULT] [hasThis] Void CrashingWebSite.WebForm1.Button1_Click(Object,Class System.EventArgs)
0x01a3f890 0x0c31bc55 [DEFAULT] [hasThis] Void System.Web.UI.WebControls.Button.OnClick(Class System.EventArgs)
0x01a3f8a4 0x0c31ba32 [DEFAULT] [hasThis] Void System.Web.UI.WebControls.Button.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(String)
0x01a3f8b4 0x0c31b9e3 [DEFAULT] [hasThis] Void System.Web.UI.Page.RaisePostBackEvent(Class System.Web.UI.IPostBackEventHandler,String)
0x01a3f8bc 0x0c31b942 [DEFAULT] [hasThis] Void System.Web.UI.Page.RaisePostBackEvent(Class System.Collections.Specialized.NameValueCollection)
0x01a3f8cc 0x0c1b81d5 [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequestMain()
0x01a3f910 0x0c1b6b3f [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest()
0x01a3f94c 0x0c1b65ab [DEFAULT] [hasThis] Void System.Web.UI.Page.ProcessRequest(Class System.Web.HttpContext)
0x01a3f954 0x0c1b6584 [DEFAULT] [hasThis] Void System.Web.HttpApplication/CallHandlerExecutionStep.System.Web.HttpApplication+IExecutionStep.Execute()
0x01a3f964 0x0c1d9328 [DEFAULT] [hasThis] Class System.Exception System.Web.HttpApplication.ExecuteStep(Class IExecutionStep,ByRef Boolean)
0x01a3f9ac 0x0c1d8d92 [DEFAULT] [hasThis] Void System.Web.HttpApplication.ResumeSteps(Class System.Exception)
0x01a3f9f4 0x0c1d8c5b [DEFAULT] [hasThis] Class System.IAsyncResult System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(Class System.Web.HttpContext,Class System.AsyncCallback,Object)
0x01a3fa10 0x01eb6897 [DEFAULT] [hasThis] Void System.Web.HttpRuntime.ProcessRequestInternal(Class System.Web.HttpWorkerRequest)
0x01a3fa4c 0x01eb6448 [DEFAULT] Void System.Web.HttpRuntime.ProcessRequest(Class System.Web.HttpWorkerRequest)
0x01a3fa58 0x01eb2fc5 [DEFAULT] [hasThis] I4 System.Web.Hosting.ISAPIRuntime.ProcessRequest(I,I4)
0x01a3fb20 0x79217188 [FRAME: ContextTransitionFrame]
0x01a3fc00 0x79217188 [FRAME: ComMethodFrame]
So the first time we call LogException and get into the recursive loop is from Button1_Click in WebForm1 (inventive names huh:))
We can look at the bottom of !dso to find out what the exception was that caused the problem, and then take a look at the code for Button1_Click to see what could have caused this exception.
Searching from the bottom of the stack objects generated by !dumpstackobjects I find that the first exception thrown was...
0x01a3f7d4 0x0239f7f4 System.Exception
0:000> !do 0x0239f7f4
Name: System.Exception
MethodTable 0x79b96824
EEClass 0x79b968c8
Size 64(0x40) bytes
GC Generation: 0
mdToken: 0x02000012 (c:\windows\microsoft.net\framework\v1.1.4322\mscorlib.dll)
FieldDesc*: 0x79b9692c
MT Field Offset Type Attr Value Name
0x79b96824 0x400001d 0x4 CLASS instance 0x00000000 _className
0x79b96824 0x400001e 0x8 CLASS instance 0x00000000 _exceptionMethod
0x79b96824 0x400001f 0xc CLASS instance 0x00000000 _exceptionMethodString
0x79b96824 0x4000020 0x10 CLASS instance 0x0239f780 _message
0x79b96824 0x4000021 0x14 CLASS instance 0x00000000 _innerException
0x79b96824 0x4000022 0x18 CLASS instance 0x00000000 _helpURL
0x79b96824 0x4000023 0x1c CLASS instance 0x0239f834 _stackTrace
0x79b96824 0x4000024 0x20 CLASS instance 0x00000000 _stackTraceString
0x79b96824 0x4000025 0x24 CLASS instance 0x00000000 _remoteStackTraceString
0x79b96824 0x4000026 0x2c System.Int32 instance 0 _remoteStackIndex
0x79b96824 0x4000027 0x30 System.Int32 instance -2146233088 _HResult
0x79b96824 0x4000028 0x28 CLASS instance 0x00000000 _source
0x79b96824 0x4000029 0x34 System.Int32 instance 0 _xptrs
0x79b96824 0x400002a 0x38 System.Int32 instance -532459699 _xcode
-----------------
Exception 0239f7f4 in MT 79b96824: System.Exception
_message: my own exception
_stackTrace:
0c1906b8 [DEFAULT] [hasThis] Void CrashingWebSite.WebForm1.Button1_Click(Object,Class System.EventArgs)
01a3f854
020eb470
...a System.Exception with the message “my own exception” thrown in WebForm1.Button1_Click… that seems to nicely match up with what we are seeing.
Using the instruction pointer from !clrstack
0x01a3f80c 0x0c1906d1 [DEFAULT] [hasThis] Void CrashingWebSite.WebForm1.Button1_Click(Object,Class System.EventArgs)
We can dump out the disassembly/IL (with !u) for Button1_Click and try to figure out why this exception was thrown even though it is a bit of a moot point since our problem with the stack overflow is because of the recursion in the exception handler, not because of this exception as such.
0:000> !u 0x0c1906d1
Will print '>>> ' at address: 0x0c1906d1
Normal JIT generated code
[DEFAULT] [hasThis] Void CrashingWebSite.WebForm1.Button1_Click(Object,Class System.EventArgs)
Begin 0x0c190678, size 0x6a
0c190678 55 push ebp
0c190679 8bec mov ebp,esp
0c19067b 83ec24 sub esp,0x24
0c19067e 57 push edi
0c19067f 56 push esi
0c190680 53 push ebx
0c190681 c745f800000000 mov dword ptr [ebp-0x8],0x0
0c190688 894dec mov [ebp-0x14],ecx
0c19068b 8955e8 mov [ebp-0x18],edx
0c19068e c745e400000000 mov dword ptr [ebp-0x1c],0x0
0c190695 b92468b979 mov ecx,0x79b96824 (MT: System.Exception)
0c19069a e8791996f5 call 01af2018
0c19069f 8945e0 mov [ebp-0x20],eax
0c1906a2 8b15b8a7170a mov edx,[0a17a7b8] ("my own exception")
0c1906a8 8b4de0 mov ecx,[ebp-0x20]
0c1906ab ff158468b979 call dword ptr [mscorlib_79990000+0x206884 (79b96884)] (System.Exception..ctor)
0c1906b1 8b4de0 mov ecx,[ebp-0x20]
0c1906b4 e8cbc10b6d call mscorsvr!JIT_Throw (7924c884)
0c1906b9 8945dc mov [ebp-0x24],eax
0c1906bc 8b45dc mov eax,[ebp-0x24]
0c1906bf 8945e4 mov [ebp-0x1c],eax
0c1906c2 8b15bca7170a mov edx,[0a17a7bc] ("WebForm1.Button1_Click")
0c1906c8 8b4de4 mov ecx,[ebp-0x1c]
0c1906cb ff159cbb0e02 call dword ptr [020ebb9c] (CrashingWebSite.ExceptionHandler.LogException)
>>> 0c1906d1 e8ae16026d call mscorsvr!JIT_EndCatch (791b1d84)
0c1906d6 eb00 jmp 0c1906d8
0c1906d8 90 nop
0c1906d9 5b pop ebx
0c1906da 5e pop esi
0c1906db 5f pop edi
0c1906dc 8be5 mov esp,ebp
0c1906de 5d pop ebp
0c1906df c20400 ret 0x4
and from the disassebly/IL we can deduce that the code for Button1_Click probably looks something like
try{
throw new Exception(“my own exception”);
}
catch{
CrashingWebSite.ExceptionHandler.LogException();
}
...and that we were at the bolded line (based on that that was the last line of code before the >>>).
Now, this was a pretty short and simple method, so matching up the IL (with a little experience) is not that hard. I just want to give you a tip though if you want to look at code for the framework, or some 3rd party dll that you don’t have the code for.
You can use the same instruction pointer (0x035406d3) and run !ip2md (Instruction Pointer to Method Descriptor) to find out which assembly it is implemented in.
0:000> !ip2md 0x0c1906d1
MethodDesc: 0x020eb470
Jitted by normal JIT
Method Name : [DEFAULT] [hasThis] Void CrashingWebSite.WebForm1.Button1_Click(Object,Class System.EventArgs)
MethodTable 0x20eb4a4
Module: 0x1f51be0
mdToken: 0x0600000e (c:\windows\microsoft.net\framework\v1.1.4322\temporary asp.net files\crashingwebsite\adc98ba3\ee722ec7\assembly\dl2\054f53ca\e32aa8c6_f42ac601\crashingwebsite.dll)
Flags : 0x0
Method VA : 0x0c190678
Using reflector from https://www.aisto.com/roeder/dotnet/ we can open up the CrashingWebSite.dll, drill down to CrashingWebSite.WebForm1.Button1_Click and see the code pretty much exactly the way it was written, and find out that the reason for the exception was me explicitly throwing it:)
private void Button1_Click(object sender, EventArgs e)
{
try
{
throw new Exception("my own exception");
}
catch (Exception exception1)
{
ExceptionHandler.LogException(exception1, "WebForm1.Button1_Click");
return;
}
}
How cool is that???
Back to the problem, the moral of the story is to not call the exception handler methods in methods used by the exception handler itself… but hopefully this case study has given you a tool for debugging stackoverflow exceptions whether they are caused by faulty exception handlers or something else:)
Until next time…
Comments
Anonymous
February 06, 2006
How were you able to determine an IOException was a cause of the crash.
I see you generated some type of output of Thread 0 but you don't specify how :)
What command did you run the generate the following output?
Also, how did you know the error occurred on thread0? Would one have to inspect every thread manually or did you run some command to automate this?
Thread 0
ESP/REG Object Name
0x01a02c6c 0x0659baa8 System.String c:errorlog.txt
0x01a02c74 0x0659bd08 System.UnauthorizedAccessException
0x01a02da4 0x0659baa8 System.String c:errorlog.txt
0x01a02da8 0x0659bd08 System.UnauthorizedAccessException
0x01a02dac 0x0659baa8 System.String c:errorlog.txt
0x01a02fd4 0x0659bd08 System.UnauthorizedAccessException
0x01a02fdc 0x0659baa8 System.String c:errorlog.txt
...
Ok, so ESP is the stack pointer?Anonymous
February 06, 2006
Thanks for commenting on this...
There was a typo in the sample. I meant to say UnathorizedAccessException, and the output was generated with !dso. (I will update the post with this)
The reason i picked Thread 0 was that that was the only thread available in the shut down dump and also the thread with the "infinite recursion".
Just to clarify, the thing that cause the crash was not the UnauthorizedAccessException, but rather the stackoverflow caused by the recursion. The UnauthorizedAccessException just caused the recursion. In other words, to fix the problem we need to not call the LogException methods from functions called by the LogException method. Fixing the UnauthorizedAccessException will cause the problem not to happen but it is not a reliable fix as other exceptions may crop up and we will be back in the recursive pattern.
In regards to ESP, yes, you are correct, this is the stack pointer (Extended Stack Pointer)
Some other registers that are handy to know about are
EAX = usually used for storing return values (specifically if they are integers)
EBP = Base Pointer, used to reference locals and parameters. EBP+4 = return address, EBP+8=1st param, EBP+12=2nd param etc. Locals are stored at negative offsets, i.e. EBP-4 is the first local...
ESI=usually the this pointer for instance function calls
EDI=usually used for holding indexes in loops like for loops
EIP=current instruction pointer
Hope this clears things up a little bitAnonymous
February 08, 2006
How about some posts on writing windbg extensions (user)?Anonymous
June 20, 2006
PingBack from http://asharism.wordpress.com/2006/06/20/how-not-to-write-a-global-exception-handler/Anonymous
April 24, 2008
Hi Tess, Thanks for this blog it is just amazing for person like me. I am having stack overflow exception and strange thing is I am not able to capture the dump. Event Type: Warning Event Source: W3SVC Event Category: None Event ID: 1009 Date: 21/04/2008 Time: 15:29:18 User: N/A Computer: LON-WEB-01 Description: A process serving application pool 'SWTNAppPool' terminated unexpectedly. The process id was '14916'. The process exit code was '0x800703e9'. I trued DebugDiag1.1 and it is not capturing the dump but event viewer reports following event. I tried with adplus and cdb but dont have much luck. In order to identify the problem, I think I need to have a dump. Any help on this is greatly appreciated. Uday uday31in@gmail.comAnonymous
April 24, 2008
Hi Uday, Try following this lab, that should get you the dump you are looking for http://blogs.msdn.com/tess/archive/2008/03/05/net-debugging-demos-lab5-crash-review.aspxAnonymous
March 04, 2009
今天有人问如何处理IIS网站出现“ServiceUnavailable”的情况。在网上google了一下，导致这个出错的原因很多，而“ServiceUnavailable”这个出错信息根本就没有...Anonymous
July 01, 2010
Thanks for this, Tess! Just solved my random crashing issue with a 4.5 year old blog entry. how cool is THAT?Anonymous
July 18, 2011
Sorry, i appreciate the accuracy of being able to pinpoint the location of the error this way, but nobody feels like troubleshooting this way! Why is it so hard for microsoft to show the actual "access is denied" error in the event log?? This is ridiculous, nobody understands an error like "0x800703e9".Anonymous
September 16, 2016
Just solved my random crashing issue with a 10 year old blog entry. How cool is THAT????????????????