When !PrintException Isn’t Quite Enough

Wherein we’ll discuss a handy technique to get a little bit more information out of !PrintException.  Sometimes it’s all that’s needed to turn a seemingly impossible issue into a trivial one!

Another customer reporting crashes, this time we’ve got the logs and a crash dump to work from.  Here’s the last thing we logged before dying:

 

Everything is pretty straightforward so far.  Digging a little deeper into the logs from the crashed service instance we see a stack trace to help us pinpoint the source of the issue:

 

We’d like to verify that the log we’re seeing lines up with the crash dump, so we’ll load it up in WindDbg to do a quick sanity check.  Inspecting the active threads in the crash dump shows a thread with an IOException on it.  This lines up with the output from the log.  Let’s switch over to thread 21 and continue investigating.

 

Out of curiosity, let’s dump the stack trace and see where the thread was when this dump file was created:

 

Unfortunately the stack trace doesn’t contain much information about where the error occurred.  That’s because things have progressed past that point.  The service is crashing because there was an unhandled exception on one of the worker threads, but in our AppDomain we’ve got an unhandled exception handler for just this eventuality.  It gets called before shutdown so that we can write the dump.  That’s what this thread stack is showing.

 

So far everything is looking good, the last thing to confirm is that the exception is the same one we saw in the logs.  A quick !PrintException (!pe) will show us the exception on the thread, but something doesn’t look right:

 

Where is the rest of the stack trace?  The stack trace here looks like the bottom half of the stack trace from the log, but we might reasonably conclude that this exception is not the same as the one in the log.  The key to resolving the disparity is to delve a little deeper into the exception object itself. 

 

Since an exception is an object like any other, we can employ !DumpObject (!do) on the address of the exception to inspect it more carefully.

 

The thing to notice is the _remoteStackTraceString.  When an exception is thrown it records the stack trace in the _stackTrace field on the exception object.  If the framework needs to marshal an already-thrown exception across a thread or remoting boundary it will need to rethrow it on a new thread in a new context.  But when rethrowing the exception it would replace the original stack trace with the stack from the new throw location.  In order to avoid losing this vital information, the framework “prep”s the exception by storing the original stack trace string in the _remoteStackTraceString.  Exception.ToString() prints out the remote stack trace prefixed by “Server stack trace:” which we saw in the log excerpt at the beginning.  Unfortunately !PrintException does not output this information.  Luckily, dumping the original stack trace is as simple as a !DumpObject on the field’s address.

 

And there we have the rest of the stack trace.  This technique can come in handy anytime the exception at hand just doesn’t seem to have all the information we need.  There’s always the possibility that the key to the whole issue is hidden there just beneath the surface, all we need is the proper tool to bring it to light.