SOS in Visual Studio Part 2

I found this old blog post on my box today. I had never gotten around to posting it.Hopefully, this will be useful to someone. 

 

In my last SOS post I promised to give a discussion on the CLR data structures you need to debug managed code with SOS. There is a great detailed article available here: https://msdn.microsoft.com/msdnmag/issues/05/05/JITCompiler/default.aspx
which explains this in good detail. However, I thought I’d still write an overview of the information and how it applies to SOS in VS.

 

Sos has a larger learning curve than VisualStudio, and I have found that this scares a lot of developers away from it. However, it really is worth time to learn to use it. Why? For two reasons: It has some very powerful features not available directly in Visual Studio and it enables you to debug managed code in crash dumps. (Yes, it is true that the Visual Studio debugger does not currently support debugging managed code from a crash dump).

 

There are three CLR data structures I think are most important when debugging using SOS. Figures 9 in the above MSDN article shows an excellent graphical representation of these types. These are data structures are:

 

1. MethodTable –Information about a class / type. This includes static class data, a table of method descriptors, pointers to the corresponding EEClass, pointers to other MethodTables for other VTables (such as interfaces implemented by the class) and a pointer to the class constructor. MethodTable is paired with an EEClass which together define the complete type.

 

2. EEClass – More static information about a class / type. Logically, EEClass and MethodTable are the same data structure.

 

3. MethodDesc – Information specific to a particular method such as the IL or Jit’ed instructions.

 

 

So, when an instance of an object appears in managed code, it is referenced through an OBJECTREF. An OBJECTREF is actually a handle (indirect pointer) to the instance of the class. This object instance contains instance data (fields), string literals, and a handle to the type’s MethodTable. If a managed method creates an instance of a type like this:

 

public void MoveCar()

{

    Wheel w = new Wheel()

}

 

The variable “w” appears as an objectref on the stack. Using this OBJECTREF, a developer using SOS can examine the variables instance data, static data, and type information.

 

As an example of debugging a small application using Visual Studio and SOS, I have enclosed a small application at the end of this post that contains two classes, Program (the driver) and Squid. The application will create an instance of Squid, set its length and color, and have it swim to a new location. Create a new C# console application in Visual Studio and replace the code in program.cs with the text in the enclosed file. Enable native debugging by right-mouse clicking the project node, and choosing Properties->Debug->Enable Unmanaged Code Debugging. Set a breakpoint in the line: Squid s = new Squid("Red", 10); and start debugging. Once the breakpoint is hit, step into the constructor of new instance of Squid. Step over the initialization of some of Squid’s fields. Next, Load SOS:

 

  1. Open the immediate window (Debug->Windows->Immediate)
  2. type “.load c:\windows\microsoft.net\framework\v2.50727\sos.dll” and hit enter.

 

Let’s examine the instance of Squid. Since the debugger is currently sitting in the constructor for squid, type !DumpStackObjects in the immediate window. SOS should print the following output:

 

OS Thread Id: 0x1c4 (452)

ESP/REG Object Name

0013f068 01319e8c System.String Red

0013f08c 01319e8c System.String Red

0013f094 01319ea4 ConsoleApplication6.Squid

0013f0c8 01319ea4 ConsoleApplication6.Squid

0013f0d0 01319ea4 ConsoleApplication6.Squid

0013f1c4 01319e8c System.String Red

0013f1c8 01319ea4 ConsoleApplication6.Squid

0013f1d4 01319ea4 ConsoleApplication6.Squid

0013f42c 01319ea4 ConsoleApplication6.Squid

0013f444 01319e7c System.Object[] (System.String[])

0013f45c 01319e7c System.Object[] (System.String[])

0013f534 01319e7c System.Object[] (System.String[])

0013f6e0 01319e7c System.Object[] (System.String[])

0013f708 01319e7c System.Object[] (System.String[])

These are the managed objects currently on the stack. We want to look at squid, so copy the value of the Object field next to squid (01319ea4 in my example). This is the value of the objectref handle on the stack. Type !DumpObj 01319ea4 in the immediate window. SOS will now print:

 

Name: ConsoleApplication6.Squid

MethodTable: 0090321c

EEClass: 00901458

Size: 24(0x18) bytes

 (C:\Documents and Settings\j\My Documents\Visual Studio 2005\Projects\ConsoleApplication6\ConsoleApplication6\bin\Debug\ConsoleApplication6.exe)

Fields:

      MT Field Offset Type VT Attr Value Name

790fa3e0 4000001 4 System.String 0 instance 01319e8c _color

790fed1c 4000002 8 System.Int32 0 instance 10 _length

790fed1c 4000003 c System.Int32 0 instance 0 posX

790fed1c 4000004 10 System.Int32 0 instance 0 posY

790fed1c 4000001 1c System.Int32 0 static 1 numRefs

SOS has just dumped the type of the object (ConsoleApplication6.Squid), a pointer to the method table and EEClass, the size of the object in bytes, the path to the module it is contained in, and the values of the instance and static fields.

 

Integral types such as int are easy to get the value of. For instance, the value of _length is 10. However, the value of the color string must be obtained by dumping its object as well. Copy its value (01319e8c) to the clipboard, and do another !dumpobj. SOS should now print something similar to this:

Name: System.String

MethodTable: 790fa3e0

EEClass: 790fa340

Size: 24(0x18) bytes

 (C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)

String: Red

Fields:

      MT Field Offset Type VT Attr Value Name

790fed1c 4000096 4 System.Int32 0 instance 4 m_arrayLength

790fed1c 4000097 8 System.Int32 0 instance 3 m_stringLength

790fbefc 4000098 c System.Char 0 instance 52 m_firstChar

790fa3e0 4000099 10 System.String 0 shared static Empty

   >> Domain:Value 0015bf68:790d6584 <<

79124670 400009a 14 System.Char[] 0 shared static WhitespaceChars

    >> Domain:Value 0015bf68:012a18a8 <<

 

The value of the string is in the “String” field. You can see the value is “Red”.

 

Alright, so now you know how to load SOS, and examine the state of variables in classes. What about getting a stack trace? SOS has three commands for getting a managed stack trance:

  1. !CLRStack – dump only the managed code on the stack for the current thread.
  2. !DumpStack – dump the managed and native stack for the current thread
  3. !EEStack – Execute !DumpStack on all threads.

 

!CLRStack is interesting if you are only looking at managed code. !DumpStack is far more verbose. I recommend turning on the symbol server to point to microsoft’s public symbols if you want to get an accurate stack from !DumpStack. !CLRStack will give you the values of parameters and locals if you pass the –p and –l flags when calling it. Let’s give it a try. From the constructor of Squid, execute !CLRStack. The output should look like this:

OS Thread Id: 0x754 (1876)

ESP EIP

0013f3f4 00e30133 ConsoleApplication6.Squid..ctor(System.String, Int32)

0013f440 00e300b2 ConsoleApplication6.Program.Main(System.String[])

0013f69c 79e88f63 [GCFrame: 0013f69c]

 

Now, do the same thing but passing –p and –l for parameters:

!CLRStack -p -l

OS Thread Id: 0x754 (1876)

ESP EIP

0013f3f4 00e30133 ConsoleApplication6.Squid..ctor(System.String, Int32)

    PARAMETERS:

        this = 0x01319ea4

        color = 0x01319e8c

        length = 0x0000000a

0013f440 00e300b2 ConsoleApplication6.Program.Main(System.String[])

    PARAMETERS:

        args = 0x01319e7c

    LOCALS:

        <CLR reg> = 0x00000000

0013f69c 79e88f63 [GCFrame: 0013f69c]

If you execute !DumpStack with the symbol path pointed to https://msdl.microsoft.com/download/symbols, you’ll get a much larger callstack. Here is an abbreviated version on my machine:

!DumpStack

OS Thread Id: 0x9fc (2556)

Current frame: _KiFastSystemCallRet@0 [d:\xpsprtm\base\ntos\rtl\i386\userdisp.asm:363]

ChildEBP RetAddr Caller,Callee

0013ec9c 7c90e9c0 _ZwWaitForSingleObject@12+0xc [d:\xpsprtm\base\ntdll\daytona\obj\i386\usrstubs.asm:2291]

0013eca0 7c8025cb rewait+0xd [d:\nt\base\win32\client\synch.c:1312], calling _ZwWaitForSingleObject@12 [d:\xpsprtm\base\ntdll\daytona\obj\i386\usrstubs.asm:2291]

0013ece4 7a00a929 EEJitManager::JitTokenToMethodHotSize+0x18 [f:\rtm\ndp\clr\src\vm\codeman.h:1540]

0013ed04 79e77fd1 CLREventWaitHelper+0x2f [f:\rtm\ndp\clr\src\vm\synch.cpp:699]

0013ed48 79e77f9a CLREvent::WaitEx+0x117 [f:\rtm\ndp\clr\src\vm\synch.cpp:798], calling CLREventWaitHelper [f:\rtm\ndp\clr\src\vm\synch.cpp:689]

0013ed7c 79f6e717 BaseWrapper<long volatile *,FunctionBase<long volatile *,&CounterIncrease,&CounterDecrease,0>,0,&CompareDefault<long volatile *>,0>::~BaseWrapper<long volatile *,FunctionBase<long volatile *,&CounterIncrease,&CounterDecrease,0>,0,&CompareDefault<long volatile *>,0>+0x23, calling _InterlockedDecrement@4 [d:\nt\base\win32\client\i386\critsect.asm:126]

0013ed98 79e77f50 CLREvent::Wait+0x17 [f:\rtm\ndp\clr\src\vm\synch.cpp:715], calling CLREvent::WaitEx [f:\rtm\ndp\clr\src\vm\synch.cpp:717]

0013eda8 7a0dd76f Thread::WaitSuspendEventsHelper+0xc7 [f:\rtm\ndp\clr\src\vm\threads.cpp:13986], calling CLREvent::Wait [f:\rtm\ndp\clr\src\vm\synch.cpp:714]

0013eddc 7c80261a $L84827 [d:\nt\base\win32\client\synch.c:1323], calling RtlDeactivateActivationContextUnsafeFast [d:\xpsprtm\base\ntdll\sxsctxact.c:614]

0013edf8 7c80a027 SetEvent+0x10 [d:\nt\base\win32\client\synch.c:423], calling _ZwSetEvent@8 [d:\xpsprtm\base\ntdll\daytona\obj\i386\usrstubs.asm:1875]

0013ee2c 7a0dd890 Thread::WaitSuspendEvents+0x16 [f:\rtm\ndp\clr\src\vm\threads.cpp:14025], calling Thread::WaitSuspendEventsHelper [f:\rtm\ndp\clr\src\vm\threads.cpp:13948]

0013ee3c 7a0ddfc8 Thread::RareEnablePreemptiveGC+0x84 [f:\rtm\ndp\clr\src\vm\threads.cpp:10155], calling Thread::WaitSuspendEvents [f:\rtm\ndp\clr\src\vm\threads.cpp:14008]

0013ee48 79f75d16 Thread::RareDisablePreemptiveGC+0xdd [f:\rtm\ndp\clr\src\vm\threads.cpp:9192], calling Thread::EnablePreemptiveGC [f:\rtm\ndp\clr\src\vm\threads.h:1896]

0013ee64 79e74411 ClrFlsSetValue+0x57 [f:\rtm\ndp\clr\src\inc\clrhost.h:179], calling _EH_epilog3 [f:\rtm\vctools\crt_bld\self_x86\crt\prebuild\eh\i386\ehprolg3.c:537]

0013ee68 79e74435 DecCantStopCount+0x10 [f:\rtm\ndp\clr\src\vm\util.hpp:933], calling ClrFlsSetValue [f:\rtm\ndp\clr\src\inc\clrhost.h:167]

0013ee80 7a2a593c PostSendEvent_Internal+0x34 [f:\rtm\ndp\clr\src\debug\ee\debugger.cpp:676]

0013ee88 7a2b95e0 DebuggerController::DispatchPatchOrSingleStep+0x184 [f:\rtm\ndp\clr\src\debug\ee\controller.cpp:2959], calling PostSendEvent_Internal [f:\rtm\ndp\clr\src\debug\ee\debugger.cpp:655]

0013eee8 7a2b973d DebuggerController::DispatchNativeException+0xf2 [f:\rtm\ndp\clr\src\debug\ee\controller.cpp:4369], calling DebuggerController::DispatchPatchOrSingleStep [f:\rtm\ndp\clr\src\debug\ee\controller.cpp:2789]

0013ef28 7a2a4cb9 Debugger::FirstChanceNativeException+0x37 [f:\rtm\ndp\clr\src\debug\ee\debugger.cpp:5005], calling DebuggerController::DispatchNativeException [f:\rtm\ndp\clr\src\debug\ee\controller.cpp:4222]

0013ef60 7a05f8dd CLRVectoredExceptionHandlerPhase2+0x97 [f:\rtm\ndp\clr\src\vm\excep.cpp:7287]

0013ef88 79e74411 ClrFlsSetValue+0x57 [f:\rtm\ndp\clr\src\inc\clrhost.h:179], calling _EH_epilog3 [f:\rtm\vctools\crt_bld\self_x86\crt\prebuild\eh\i386\ehprolg3.c:537]

0013efa0 79f97730 CLRVectoredExceptionHandler+0xd3 [f:\rtm\ndp\clr\src\vm\excep.cpp:7202], calling CLRVectoredExceptionHandlerPhase2 [f:\rtm\ndp\clr\src\vm\excep.cpp:7206]

0013efd0 79f9484a CPFH_FirstPassHandler+0x5a [f:\rtm\ndp\clr\src\vm\i386\excepx86.cpp:1300], calling CLRVectoredExceptionHandler [f:\rtm\ndp\clr\src\vm\excep.cpp:7098]

0013efec 7c93799c RtlLookupFunctionTable+0xae [d:\xpsprtm\base\ntos\rtl\lookup.c:539], calling RtlCaptureImageExceptionValues [d:\xpsprtm\base\ntos\rtl\lookup.c:320]

0013effc 79f949a2 COMPlusFrameHandler+0x120 [f:\rtm\ndp\clr\src\vm\i386\excepx86.cpp:1722], calling CPFH_FirstPassHandler [f:\rtm\ndp\clr\src\vm\i386\excepx86.cpp:1279]

0013f01c 7c9037bf ExecuteHandler2@20+0x26 [d:\xpsprtm\base\ntos\rtl\i386\xcptmisc.asm:224]

0013f040 7c90378b ExecuteHandler@20+0x24 [d:\xpsprtm\base\ntos\rtl\i386\xcptmisc.asm:184], calling ExecuteHandler2@20 [d:\xpsprtm\base\ntos\rtl\i386\xcptmisc.asm:200]

0013f064 7c937860 RtlDispatchException+0xb1 [d:\xpsprtm\base\ntos\rtl\i386\exdsptch.c:400], calling _RtlpExecuteHandlerForException@20 [d:\xpsprtm\base\ntos\rtl\i386\xcptmisc.asm:99]

0013f0a8 7c96e0d4 $L38802+0x8 [d:\xpsprtm\base\ntos\rtl\heapdbg.c:905], calling __SEH_epilog [d:\xpsprtm\base\crts\crtw32\misc\i386\sehprolg.asm:56]

0013f0ac 7c94a5d0 RtlFreeHeapSlowly+0x37 [d:\xpsprtm\base\ntos\rtl\heap.c:3960], calling RtlDebugFreeHeap [d:\xpsprtm\base\ntos\rtl\heapdbg.c:803]

0013f0b8 7c926abe $L40961+0x80 [d:\xpsprtm\base\ntos\rtl\heap.c:4334], calling __SEH_epilog [d:\xpsprtm\base\crts\crtw32\misc\i386\sehprolg.asm:56]

0013f0c8 7c91056d $L41223+0x30 [d:\xpsprtm\base\ntos\rtl\heap.c:3895], calling __SEH_epilog [d:\xpsprtm\base\crts\crtw32\misc\i386\sehprolg.asm:56]

0013f0f0 7c90eafa _KiUserExceptionDispatcher@8+0xe [d:\xpsprtm\base\ntos\rtl\i386\userdisp.asm:219], calling RtlDispatchException [d:\xpsprtm\base\ntos\rtl\i386\exdsptch.c:504]

0013f3f4 00de010e (MethodDesc 0x9030b0 +0x2e ConsoleApplication6.Squid..ctor(System.String, Int32)) ====> Exception cxr@13f128

 

 

 

 

Simple Test App:

using System;
using System.Collections.Generic;
using System.Text;

namespace ConsoleApplication6
{
class Squid
{
public static int numRefs;
private string _color;
private int _length;
private int posX;
private int posY;

        public Squid(string color, int length)
{
this.Color = color;
this.Length = length;
posX = 0;
posY = 0;
Squid.numRefs++;
}

        public string Color
{
get
{
return _color;
}
set
{
_color = value;
}
}

        public int Length
{
get
{
return _length;
}
set
{
_length = value;
}
}

        public void Swim(int newX, int newY)
{

        }
}

    class Program
{
static void Main(string[] args)
{
Squid s = new Squid("Red", 10);
s.Swim(15, 15);
}
}
}