SOS Debugging with the CLR (Part 1)
In this entry I was planning to cover some debugging hints and
tricks primarily with the SOS extension dll. A couple of things happened
after I started. First, I did a quick search on the
net and was very pleasantly surprised to see a lot of material on this already.
Since we created a lot of this stuff from scratch, we often forget to look for
this kind of stuff. I’m actually going to send some links around to the
team since there is a lot of good data here, and we haven’t invested a huge
amount in our own documentation (I assume you’ve read sos.htm? <g>).
Second, I wound up with more content than I expected. I generally write
these things at the Bear Creek Starbucks on my tmobile account (what did
we do before wireless, terminal server, broadband, and Tivo?). For some
reason, it’s like a common room at school: white noise facilitates volume.
So I’ve decided to keep all the overview material, but then concentrate on the
Windows debugging stack tricks and background. I’m going to split off and save
the trully SOS specific content for another post.
So given all that good stuff, I no longer need to write up the
seminal work on debugging, and will instead try and call out some things to augment that
material rather than repeat it. Let’s start off with some important links and background
material you’ll want to read up on:
|SOS Documentation||There is some background material that ships with the
SDK. These docs were literally written by our development team and
the PSS folks for the CLR. Suffice it to say we didn’t get a big
Doc budget here <g> The help files and samples live in the SDK
under the <SDK\v1.1\Tool Developers Guide\Samples\sos> directory.
|SOS Source Code||I’m not sure if you noticed it, but a version of this
code lives in the SSCLI distribution. Look in the \sscli\clr\src\tools\sos
directory. I think you’ll find most of the code is very similar to
the version in the full distribution.
Robbins MSDN Article
|This is a pretty thorough article with a sample
program to try out your skills on. To be honest, it is the entry I
originally set out to write (a sample application with some commands).
But since John has done it already, read this article and then this one.
PAG Guide for Debugging
|This is an impressive piece of documentation on doing
advanced debugging of ASP.NET including how to use SOS.DLL. Make
sure you grab a scone and a grande lattee before sitting down to read
this one (wow!).
First let me get the trivia out of the way. The original
name of the CLR team (chosen by team founder and former Microsoft Distinguished
Engineer Mike Toutonghi) was "Lighting". Larry Sullivan’s dev
team created an ntsd extension dll to help facilitate the bootstrapping of v1.0.
We called it strike.dll
(get it? "Lightning Strike"? yeah, I know, ba’dump bum). PSS really needed this in order to give us information back to the
team when it was time to debug nasty stress failures, which are almost always
done with the Windows debugger stack. But we didn’t want to hand out our full strike.dll, because it contained some "dangerous" commands that if you really
didn’t have our source code could cause you confusion and pain (even to other
Microsoft teams). So I pushed the team to create "Son of Strike" (Simon from our dev takes
credit/blame for this), and we shipped it with the product starting with Everett (aka
V1.1). Keep your eye on future developments in this space; I hadn’t
anticipated as much interest as we’ve gotten in the tool, and I think future
improvements in the Windows debuggers might have us ship the full meal deal next go
Background on Debugger Stacks
There are two supported debugger technologies that come from
Microsoft, the Windows Debugger Stack and Visual Studio.Net.
Windows Debugger Stack
This debugger is (currently) strictly an unmanaged debugger.
There is one core debugger engine that handles exceptions, enables a very
handy plug in model, and accepts commands. This is then wrapped with a set
of debugger front ends. cdb and ntsd are a command line version for user
mode debugging. They are identical except that cdb inherits your
console and ntsd creates a brand new one (mostly useful for debugging services
where you need a new console to be created). windbg is a GUI user mode
debugger that adds nice windows and integrated call stacks on top of the cdb
functionality. It has a command line window, so anything you can do on the
console you can also do inside this GUI shell. Finally there is KD, which
is the kernel debugger. It has the command console/command line behavior,
only you are debugging the kernel itself and therefore there are some extra
commands at your disposal.
The Windows debugger stack has a great facility called extension dlls. This basically allows you to write your own native dll which exports
a set of entry points that can be invoked from inside any Windows debugger. As
an extension dll author, you get to read and write process memory and do other
very basic things against the debuggee process. This is really a killer
feature, and very widely used inside Microsoft. The nice thing is you are
can compile using your normal product headers, and then add utility features
like "dump this tree of data structures with nice formatting to the console".
Now you produce that extension dll right out of your normal build with the rest
of the product, and you’re ready to go. Sos.dll and Strike.dll are just
I expect most people reading this entry are very familiar with
VS.Net and its capabilities. The obvious thing VS does well is GUI
debugging and RAD development. You won’t find any of the project system or
wizards in Windbg, but will find a lot of the same debugger windows (call
stacks, memory, registers, etc). VS.Net also allows you to step into RPC
calls, Web Services, and TSQL. It does not, however, do a good job at
extension dlls. The team added some very basic support for sos.dll in
version 7.1 (Everett), but personally I never use it because it falls way short
of the basic commands you want outside sos.dll (who doesn’t want to get all
their call stacks using "~*kb"?).
Which to Use?
98% of you reading this should just use VS.Net.
It is far easier and more approachable. Most of our engineers at Microsoft
use VS.Net to author things like the Base Class Libraries. However I do
personally feel that VS has the "last mile problem". In particular, I find
it to be ill suited to stress debugging. Most operations guys I know do
not want to install the remote components of VS (which currently includes DCOM!) on a
production server. It changes your environment too much. Remoting
the console of the Windows debuggers is far more widely used (all of the customer PSS
remotes we get to the engineering team come in this way).
Beyond this problem, stress debugging often involves things
like trying to figure out which threads are holding which lock objects and in
what order. Clicking through dialogs to get thread stacks to do this
sucks. It is so much easier to just type in "~*kb", and you will get a
call stack for every thread in the process in one nice output. And then
what really rocks: there are default extension dll commands like !critsec
that dump the contents of a critical section. You will find similar
commands for dumping lots of internal data structures, and doing some default
diagnosis. Finally, it is a lot easier to extract a context record (a
struct with all of the registers from a thread) and reset the thread. This
is very handy when dealing with AV’s in a process that have thrown an exception
and land in some nasty code.
So again, bottom line, plan to use VS.Net. But if
you’re hard core, then you will want to learn the Windows debuggers and extension dlls. Usage on
the CLR team (and similar teams like the Windows Shell) are about 50/50 each.
I’ve got engineers on my team that I can’t make use VS.Net because their life
just involves too many stress remotes and nasty unmanaged code (aren’t you glad
we’re doing it for you <g>).
Sos.dll falls primarily into the stress debugging bucket.
Internally in the CLR, we also use it to bootstrap a new system. For
example, we would have been dead without it when bootstrapping the 64-bit
version of the CLR (coming end of this month to the PDC at LA; to answer the
FAQ, we are not yet shipping a 64-bit version but we have announced it and demo’d it working at numerous public forums).
This section is the quick start for getting debugging working
on your machine.
Make sure you already have the .NET Framework and the SDK
the Windows Debugger stack. I usually install this to
c:\debuggers. Place this directory on
your path, eg: "set path=c:\debuggers;%path%;".
Note that I placed this path before the regular path on purpose, so that the
newest debugging tools are found before anything else you might have on your
Run the VSVars32.bat file if you care about the SDK on
your path (not necessary to run the debuggers)
Set up the symbol path for Windows symbols using
server. As an example, create a directory
c:\websymbols, and then
Example 1: Who Loaded These Dlls?
One thing I’ve always really liked about the Windows debuggers is
that you can do a certain amount of automated scripting while you are debugging.
The best I’ve come up with allows you to log all of the call stacks which loaded every dll in a process. First make sure you
set up your machine for
debugging. For my test, we’ll look at all the loaded dll’s in the
regasm utility by just showing its help text:
<cut out full call stacks for some
Let’s take a look at the commands:
This command will start logging all of the output from the
sxe -c"kb 10;g" ld
|‘sxe ld’ tells the debugger that whenever a
dll is loaded, give an exception. The -c is the command to run when
the event fires. In this case I’m running two: ‘kb 10’ gives us
the 10 top frames of the callstack where the load occurred, and ‘g’ says
restart execution. So this key command sequence says "give me 10
frames whenever you load a dll and then keep going".
|Starts the program.|
I’ve attached a couple of full call stack examples and the
abbreviated list of all dll’s loaded for reference ("findstr
ModLoad load.log") The ModLoad tags in the output show you the name of
the dll, followed by the call stack which forced it to get loaded. One
thing you’ll notice is a lot of extra engine goo in there. You may need to
play a bit more with the stack depth to get down into JIT’d code frames.
The regasm utility requires its own managed dll, regcode.dll,
to run. Let’s take a closer look at that loaded call stack (with more
frames than just 10 this time):
|ChildEBP RetAddr Args to
0012c9a0 77f5bb04 77f67948 00000718 ffffffff *SharedUserSystemCall+0xc
WARNING: Stack unwind information not available. Following frames may be
0012caa0 77f6133d 00168ff0 0012cb04 0012d01c ntdll!NtMapViewOfSection+0xc
0012cd48 77f570e0 00000000 00168ff0 0012d01c
0012cfdc 77e7d901 00168ff0 0012d01c 0012d014 ntdll!LdrLoadDll+0x1c5
0012d044 791b7b63 00152da0 00000000 00000009 KERNEL32!LoadLibraryExW+0xc8
0012d060 791c19d0 00152da0 00000000 00000009 mscorwks!WszLoadLibraryEx+0x5f
0012d088 791c17e9 00152e4c 00154290 00008000
0012d0a4 791c1855 00154080 00152e4c 00000000 mscorwks!PEFile__Setup+0x45
0012d0c0 791c564f 00152e4c 0012d1d4 00000000 mscorwks!PEFile__Create+0x38
0012d0d8 791ece29 00152e4c 00152e4c 0012d1d4
0012d14c 791eec92 00000001 00000000 00c09ff0
0012d190 791c4efe 0012d298 00000000 26000000 mscorwks!PEFile__Create+0x11a
0012d1d8 791eefa7 0012d298 00000000 26000000
0012d4bc 791ed2f4 00156018 00859ab0 0012dcbc
0012d73c 791ed195 0012d7e4 0012d7e8 0012d7ec
0012d75c 791ecfc7 0012dc8c 0012d7e4 0012d7e8
0012dc68 791eca5e 0012df24 0012e038 00000000
0012def4 791ecaae 23000002 0014b980 0014d080
0012df1c 791e54b5 00000000 23000002 0014b980
0012df50 791e551d 0012dfa8 0012df90 0012e038
0012df84 791b5404 0012e024 00000000 0012e038
0012dfcc 791df1a1 0012e024 00152080 0012e038
0012e02c 7944df48 0012e830 00000000 0012e488
0012e548 79438daa 00bf1d60 00bf1e0c 00bf0010
0012e5f0 7943b423 00bf1d60 0012e858 00bf0010
0012e608 7943b35a 00bf1d60 00bf0010 794310c6
0012e614 794310c6 00bf0010 0012e66c 7943143f
0012e620 7943143f 0012e734 0012e8b0 0012e728
0012e66c 794314e2 00152080 0012e80c 0012e858
0012e6f4 7943156c 0012e80c 0012e858 0012e734 MSCORJIT!jitNativeCode+0x95
0012e738 791dd630 79478e1c 0012e80c 0012e858
0012e780 791de06e 001526d8 0012e80c 0012e858
0012e8e8 791de4ec 008f5110 0012eab4 0012e9f0 mscorwks!JITFunction+0x2c7
0012ea20 791de6cf 008f5110 0012eab4 00000000 mscorwks!MakeJitWorker+0x2bb
0012eb0c 791d6a7e 00000000 0012f5f4 0012eb48
0012eb24 0014832e 0012eb48 00000000 00000000 mscorwks!PreStubWorker+0x42
0012eb58 791dc106 0012eba4 00000000 0012eb7c 0x14832e
0012ebdc 791dc1b9 008f510b 00152080 009125ac
0012ec04 791dc26b 00000000 009125ac 00152628 mscorwks!MethodDesc__Call+0x8e
0012ec80 791ba529 00152628 0012f654 00000000
0012f578 791b6a2c 0012f654 00000000 00000000
0012f58c 791d68e4 0012f654 0012f6a0 008f5080
0012f664 791d6a7e 00000000 0012f8b0 0012f6a0
0012f67c 0014832e 0012f6a0 00000004 05051b7c mscorwks!PreStubWorker+0x42
0012f6b0 791da434 0012f6fc 00000000 0012f6d4 0x14832e
0012f7c0 791da58a 008f507b 00152080 0012f7e0
0012f870 791da5f6 008f507b 00152080 790059a8
0012f898 7923d587 0012f928 00000000 00147c80 mscorwks!MethodDesc__Call+0x97
0012f950 7923d342 008f5080 00000001 00000000
0012fa64 7923d441 00152080 00000000 79041374
0012fa7c 7923d92f 00000000 0012fd70 00000000
0012fd60 791c6e73 00000001 0012fd90 0012ffe0
0012ffa0 791c6ef3 79000000 00080000 00000000 mscorwks!ExecuteEXE+0x1c0
0012ffb0 7917d0b8 0006f38c 791b0000 0012fff0 mscorwks!_CorExeMain+0x59
0012ffc0 77e814c7 00080000 0006f38c 7ffdf000 mscoree!_CorExeMain+0x30
0012fff0 00000000 7917d08c 00000000 78746341
Notice the blue lines in the call stack which have no symbol
names. These are managed frames. mscorwks!PreStubWorker is the
routine in the CLR which owns invoking the JIT compiler and back patching call
sites. You can use the !ClrStack command to get the managed call stack.
I’m going to drill harder on this in Part 2. The other pointers above have
a good tutorial so hopefully this is pretty obvious at this point.
Example 2: What Processes Did My App Run?
The CLR Performance team did an analysis on an internal
Microsoft business application,
which is worth reading up on. This application was produced by our
internal IT group using VB.Net, Web Services, SQL Server, etc. It is the
typical kind of multi-tier application you might be writing. One interesting
thing that came out of that analysis was the very interesting way in which the
XML Serializer class launches the C# compiler every time it starts up (16 times
in our internal application — ouch!).
I’m going to cover a couple of ways that you can debug your
application for this kind of behavior. First let’s use the Windows debuggers to watch every CreateProcess call:
Loaded Son of Strike data table version
Let’s take a look at the commands:
Here again we are firing a command we want to run when a
kernel32!CreateProcessW "!ClrStack;du poi(esp+8);g"
This command sets a break point on kernel32!CreateProcessW. I’m
running this on Windows XP, and so any create process call will go through
the Unicode (W) version of the API. Whenever this bp fires, I want to
execute the !ClrStack command from sos, and then display the command line
argument passed to Create Process. See the detailed explanation below.
After displaying all this information, a "g" command is executed so the
application keeps running.
Scanning through the output from the debugger, you can see
when the first XML serializer is created using System.CodeDOM.Compiler.
Once the source code for the serializer instance is cooked up, the C# compiler
is invoked to do the compilation so the code can be loaded and executed.
In this case you can see that a config file is passed to the csc.exe compiler.
An example of such a file in this application is:
/t:library /utf8output /R:"c:\windows\assembly\gac\system.xml\1.0.5000.0__b77a5c561934e089\system.xml.dll"
No surprises here. The generated code will utilize the
XML parser and various system classes to do your serialization work for your
unique type. The first few lines of the generated application can then be
found by examining the temp file (hint: you’ll need to do this before the file
gets cleaned up, iow while the bp is waiting for you to continue):
One last thing to puzzle through. What’s up with this
bp kernel32!CreateProcessW "!ClrStack;du poi(esp+8);g"
As I mentioned above, on an NT based Windows system all calls
ultimately go through the Unicode version of the system API’s. In this
case I want to look for all calls which
create a process. When this breakpoint fires, the instruction pointer
(eip) will be pointing at the first byte of the method. You can view the
code for this method using the unassemble ("u") command.
0:007> dd esp
In this case all of the Windows win32 api’s use the stdcall
calling convention (ebp chaining). The general layout of such a stack
frame is as follows:
esp ————–> | <current location
| <local #n> |
| <local #2> |
| <local #1> |
ebp ————–> | <previous ebp>
| <return address> | ebp + 4
| param 1
| ebp + 8
| param 2
| ebp + c
| param 3
| ebp + 0x10
At the point where the bp fires however, we have not yet set
up ebp (the prolog has not run). That means that esp is pointing at the
return address that was just pushed before the call. Here’s our picture
(before execution of the prolog):
esp ————–> |
| esp + 0
| param 1
| esp + 4 ;
| param 2
| esp + 8 ;
| param 3
| esp + c ; lpProcessAttributes, etc…
As you can see, you can now encode the parameters for the
method call relative to the current value of esp. Now combine that with
the poi() operator, which when dumping memory means "take what this expressions
resolves to as a pointer to data I want to dump". So one more time:
bp kernel32!CreateProcessW "!ClrStack;du poi(esp+8);g"
The command sets a breakpoint on CreateProcessW, executes a !ClrStack
command so you can see what caused it, and then finally dumps the unicode string
that esp+8 points to (lpCommandLine). Pretty easy huh? You can
experiment a bit with this technique and do more commands, such as adding a ‘kb
10’ to get the unmanaged frames as well as the managed ones. This is a
pretty powerful debugging technique, and very handy for doing lot’s of automated
Example 3: What Processes Did My App Run, Part 2
I mentioned above that there are many ways to solve a problem
like this. In this case we know that the C# compiler, csc.exe, is going to
get invoked. Let’s say you wanted to simply log every single invocation to
the C# compiler on your machine, no matter which process did it. The best
way to do this is using the Image File Execution Options registry key. The
easiest way to get access to this is running the gflags.exe program that came
with the Windows Debugger. This is pretty easy:
Start the application and set the Image File Name to
Click the radio button (*) Image File Options
Give the following for the Debugger edit box (lower
Check [x] the Debugger check box
Click Apply, then OK
This will create a key entry under "HKEY_LOCAL_MACHINE\SOFTWARE\Windows
NT\CurrentVersion\Image File Execution Options" for csc.exe. A Debbuger
key value is created with your command line. I find it quicker and easier
to simply use regedit to update this value at this point. If you want to
skip gflags, run the following .reg file contents through regedit:
Windows Registry Editor Version 5.00
File Execution Options\csc.exe]
Using regedit (which doesn’t have a limit for size of text you
can enter), make the Debugger string the following:
c:\debuggers\ntsd.exe -c ".logappend
Whenever csc.exe is executed, the ntsd.exe debugger will run.
The command will open c:\csc.log in append mode
so that any commands you run under the debugger get recorded. Next the
program execution block is dumped using !peb. This will record the command
line and process launch information. Then execution is continued using the
‘g’ command. The final ‘-G’ tells ntsd that when the program terminates,
don’t bother to give me a break point. Now launch your application, or
simply run csc.exe from the command line and examine the contents of
c:\csc.log. Here’s mine:
<… rest of
In addition to this kind of automated logging, I’ve also used
this technique to debug complicated programs that launch many applications (like
a build process). One warning: make sure to delete the registry key
once you are done, otherwise it’ll kick in even when you are building from
Wrap Up and Future Directions
In the future I expect to get
much tighter integration with the Windows Debugger Stack. This is really
important now that managed code is such a core part of so many products (you are
coming to the PDC right?). How much better would your life be if you could
just type ‘k’ and have a real call stack without having to do a hand merge using
sos.dll? I’m definitely looking forward to that world, but we aren’t there
The XML Serializer behavior as
described in the Headtrax overview demonstrates how easy it is to write a simple
and powerful application that can have some pretty interesting performance
issues. In this case it really is the design of the XML Serializer itself.
The Web Services team is aware of the down sides of this kind of design and
hopefully will do something to clear this up. To be clear, it is a
perfectly functional and powerful programming model, it just doesn’t optimize
for the startup performance of your application. And I’ll bet if you are
using this technology you probably didn’t actually know you were spawning copies
of C# just to do so. I recommend reading
Rico’s blog for more details on performance related recommendations.
In particular, you should avoid touching these types until you need them, so you
can at least amortize the cost over the run of the application.
That’s it for this post.
By now hopefully you picked up a couple of interesting tidbits (installing the
Windows debuggers, getting symbol server going, the new .loadby command, and
some scripting capabilities). What I’m planning to do for Part 2 is
digging more into sos specifics and hopefully filling in some blanks on some of
those commands. Please do send me any suggestions for that content or
questions you’d like to hear answered and I’ll see what I can do.
October 21, 2003