Using WinDbg to Log Exceptions
September 17th, 2005
Since I discovered that I am currently—and quite inexplicably—the #1 Google Blog Search result for the term “WinDbg,” I decided that I would attempt to actually produce some WinDbg content.
If you are not familiar with WinDbg, check it out with the rest of the Debugging Tools for Windows here.
To get things started, I thought I would post some examples that I’ve found useful lately.
I use this technique quite a bit when I’m doing QA work on an application. I can think of a bunch of other scenarios where it might be useful, but one chore in particular that is well suited for this is finding ASP.NET page compilation exceptions.
There isn’t really a good way to clean up page compilation exceptions in a massive ASP.NET application. Why would you bother? Well, there are a few reasons.
- They encourage you to disable break-on-exceptions in a debugger like VS.NET, since you’ll be inundated with a lot of other people’s exceptions when trying to attach to the worker process. If you do that, you might miss swallowed exceptions or exceptions on background threads that you would have otherwise noticed and fixed.
- They might indicate a problem in the HTML being sent back to the user.
- They cause your application to take longer to start up.
- Some of us are just sticklers for the details, ok?
- So, one good way to trim them down to a bearable amount is to log all of the exceptions that happen when the app starts.
The first thing you need to do is open up a log:
0:003> .logopen c:\temp\exceptions.txt Opened log file 'c:\temp\exceptions.txt'
And if this is managed code you’ll want to load the SOS extension:
We’ll use a breakpoint with a custom command to print out the stack when the exception occurs.
0:003> bp kernel32!RaiseException "!clrstack!clrstack; g"
!clrstack command will print out the stack, and g (go) resumes execution. If the application is unmanaged, you will want to replace
!clrstack with one of the k (display stack) commands. Both managed and unmanaged code will use the same underlying call to the
Once you have this set up, you’ll see a trickle or a flood of stacks, depending on the relative health of your app. They’ll probably be more interesting than this:
(848.d18): CLR exception - code e0434f4d (first chance) Thread 0 ESP EIP 0x0012f648 0x7c81eae1 [FRAME: HelperMethodFrame] 0x0012f674 0x02e000a0 [DEFAULT] Void CsConsoleApp.Program.Main(SZArray String) at [+0x48] [+0xf] c:\src\scratch\csconsoleapp\class2.cs:26 0x0012f8b0 0x791d94bc [FRAME: GCFrame] 0x0012f9b0 0x791d94bc [FRAME: GCFrame] 0x0012fa94 0x791d94bc [FRAME: GCFrame]
But you get the idea.
Adding More Information
Now, notice that in the case of a managed exception, WinDbg didn’t give us much information, other than the fact that it occurred:
(848.d18): CLR exception - code e0434f4d (first chance)
It would be nice to get the exception text, right? You can do that by changing the breakpoint to this:
0:000> bp mscorwks!JIT_Throw "du poi(@ecx+10)+c; !clrstack!clrstack; g"
Homework: explain this command and how I came up with it. I will post the answer soon.
Now we’ll get something more useful:
(848.d18): CLR exception - code e0434f4d (first chance) 00aaab88 "You stink!"
One thing you might want to do in the case of rarer exceptions is create a dump of the process. This is especially useful if your issue only happens in production. The simplest way to do that is very similar to what we just did:
0:003> bp kernel32!RaiseException ".dump /ma /o c:\\temp\\myapp.dmp; g" breakpoint 0 redefined
/ma switch produces a full dump. I set this breakpoint to overwrite a single dump file.
More homework: modify the breakpoint to create a series of dumps. The answer will be posted in the near future.