Having Fun with WinDBG

I’ve been spending lots of quality time with WinDBG and the rest of the Windows Debugging Tools, and ran into something I thought was fun to do.

For the sake of keeping it simple, let’s say I have a sample console application that looks like this:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Runtime.CompilerServices;

class Program {
  static void Main(string[] args) {
    Program p = new Program();
    for ( int i = 0; i < 10; i++ ) {
      p.RunTest("Test Run No. " + i, i);
    }
  }
  [MethodImpl(MethodImplOptions.NoInlining)]
  public void RunTest(String msg, int executionNumber) {
    Console.WriteLine("Executing test");
  }
}

Now, imagine I’m debugging such an application and I’d like to figure out what is passed as parameters to the RunTest() method, seeing as how the application doesn’t actually print those values directly. This seems contrived, but a classic case just like this one is a method that throws an ArgumentException because of a bad parameter input but the exception message doesn’t specify what the parameter value itself was.

For the purposes of this post, I’ll be compiling using release x86 as the target and running on 32-bit Windows. Now, let’s start a debug session on this sample application. Right after running it in the debugger, it will break right at the unmanaged entry point:

Microsoft (R) Windows Debugger Version 6.11.0001.404 X86
Copyright (c) Microsoft Corporation. All rights reserved.

CommandLine: .\DbgTest.exe
Symbol search path is: *** Invalid ***
****************************************************************************
* Symbol loading may be unreliable without a symbol search path.           *
* Use .symfix to have the debugger choose a symbol path.                   *
* After setting your symbol path, use .reload to refresh symbol locations. *
****************************************************************************
Executable search path is:
ModLoad: 012f0000 012f8000   DbgTest.exe
ModLoad: 777f0000 77917000   ntdll.dll
ModLoad: 73cf0000 73d3a000   C:\Windows\system32\mscoree.dll
ModLoad: 77970000 77a4c000   C:\Windows\system32\KERNEL32.dll
(f9c.d94): Break instruction exception - code 80000003 (first chance)
eax=00000000 ebx=00000000 ecx=001cf478 edx=77855e74 esi=fffffffe edi=7783c19e
eip=77838b2e esp=001cf490 ebp=001cf4c0 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for ntdll.dll -
ntdll!DbgBreakPoint:
77838b2e cc              int     3

Now let’s fix the symbol path and also make sure SOS is loaded at the right time:

0:000> .sympath srv*C:\symbols*http://msdl.microsoft.com/download/symbols
Symbol search path is: srv*C:\symbols*http://msdl.microsoft.com/download/symbols
Expanded Symbol search path is: srv*c:\symbols*http://msdl.microsoft.com/download/symbols
0:000> .reload
Reloading current modules
......
0:000> sxe -c ".loadby sos clr" ld:mscorlib
0:000> g
(1020.12c8): Unknown exception - code 04242420 (first chance)
ModLoad: 70b80000 71943000   C:\Windows\assembly\NativeImages_v4.0.30319_32\mscorlib\246f1a5abb686b9dcdf22d3505b08cea\mscorlib.ni.dll
eax=00000001 ebx=00000000 ecx=0014e601 edx=00000000 esi=7ffdf000 edi=20000000
eip=77855e74 esp=0014e5dc ebp=0014e630 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
ntdll!KiFastSystemCallRet:
77855e74 c3              ret

At this point, managed code is not executing yet, but we’ve got SOS loaded. Now, what I’d like to do is set an initial breakpoint in the RunTest() method. Because it’s a managed method, we’d need to wait until it is jitted to be able to grab the generated code entry point. Instead of doing all that work, I’ll just use the !BPMD command included in SOS to set a pending breakpoint [1] on it, the resume execution:

0:000> !BPMD DbgTest.exe Program.RunTest
Adding pending breakpoints...
0:000> g
(110c.121c): CLR notification exception - code e0444143 (first chance)
(110c.121c): CLR notification exception - code e0444143 (first chance)
(110c.121c): CLR notification exception - code e0444143 (first chance)
JITTED DbgTest!Program.RunTest(System.String, Int32)
Setting breakpoint: bp 001600D0 [Program.RunTest(System.String, Int32)]
Breakpoint 0 hit
eax=000d37fc ebx=0216b180 ecx=0216b180 edx=0216b814 esi=0216b18c edi=00000000
eip=001600d0 esp=002fece0 ebp=002fecf4 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
001600d0 55              push    ebp

Now he debugger has stopped execution on the first call to RunTest, so we can actually examine the values of the method arguments:

0:000> !CLRStack -p
OS Thread Id: 0x121c (0)
Child SP IP       Call Site
002fece0 001600d0 Program.RunTest(System.String, Int32)
    PARAMETERS:
        this () = 0x0216b180
        msg () = 0x0216b814
        executionNumber (0x002fece4) = 0x00000000

So the first parameter is the this pointer, as this is a method call. The msg parameter is a string, so let’s examine that as well:

0:000> !dumpobj -nofields 0x0216b814
Name:        System.String
MethodTable: 70e9f9ac
EEClass:     70bd8bb0
Size:        42(0x2a) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      Test Run No. 0

Now let’s look at this at a slightly lower level:

0:000> kbn3
 # ChildEBP RetAddr  Args to Child
WARNING: Frame IP not in any known module. Following frames may be wrong.
00 002fecdc 001600ab 00000000 00000000 004aa100 0x1600d0
01 002fecf4 727221db 002fed14 7272e021 002fed80 0x1600ab
02 002fed04 72744a2a 002fedd0 00000000 002feda0 clr!CallDescrWorker+0x33
0:000> !IP2MD 0x1600d0
MethodDesc:   000d37fc
Method Name:  Program.RunTest(System.String, Int32)
Class:        000d1410
MethodTable:  000d3810
mdToken:      06000002
Module:       000d2e9c
IsJitted:     yes
CodeAddr:     001600d0
Transparency: Critical
0:000> !IP2MD 0x1600ab
MethodDesc:   000d37f0
Method Name:  Program.Main(System.String[])
Class:        000d1410
MethodTable:  000d3810
mdToken:      06000001
Module:       000d2e9c
IsJitted:     yes
CodeAddr:     00160070
Transparency: Critical

Here we see the top 3 stack frames including the first 3 parameters to the call, and from the !IP2MD calls you can see the first 2 are the calls to RunTest() and Main(), just as we would expect.

The parameters displayed by the kb command, however, seem a bit weird for the RunTest call: 00000000 00000000 004aa100. These are, literally, the values on the stack:

0:000> dd esp L8
002fece0  001600ab 00000000 00000000 004aa100
002fecf0  002fed20 002fed04 727221db 002fed14

Notice that at the top of the stack we have the return address to the place in Main() where the method call happened, followed by the “3 parameters” displayed by kb. However, this isn’t actually correct.

The CLR uses a calling convention that resembles the FASTCALL convention a bit. That means that in this case, the left-most parameter would be passed in the ECX register, the next one in EDX and the rest on the stack. In our case, this means that the value of the this pointer will go in ECX:

0:000> r ecx
ecx=0216b180
0:000> !dumpobj ecx
Name:        Program
MethodTable: 000d3810
EEClass:     000d1410
Size:        12(0xc) bytes
File:        C:\temp\DbgTest\bin\release\DbgTest.exe
Fields:
None

It also means that the msg argument will go in EDX:

0:000> r edx
edx=0216b814
0:000> !dumpobj -nofields edx
Name:        System.String
MethodTable: 70e9f9ac
EEClass:     70bd8bb0
Size:        42(0x2a) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      Test Run No. 0

So the value executionNumber argument will go in the stack, and we’ll find it at [esp+4]:

0:000> dd [esp+4] L1
002fece4  00000000

We could even disassemble the small piece of code in Main that calls RunTest, by backing up a bit before the current return address, and you’ll see how the value of i is pushed into the stack from the edi register and how the ecx and edx are likewise prepared for the call:

0:000> u 001600ab-12 L8
0016009b e87076b870      call    mscorlib_ni+0x2b7710 (70e37710)
001600a0 57              push    edi
001600a1 8bd0            mov     edx,eax
001600a3 8bcb            mov     ecx,ebx
001600a5 ff1504380d00    call    dword ptr ds:[0D3804h]
001600ab 47              inc     edi
001600ac 83ff0a          cmp     edi,0Ah

Knowing all this, if we wanted to print out the values of the msg and executionNumber parameters on all remaining calls to RunTest, we could replace the breakpoint setup by the !BPMD command with a regular breakpoint that executes a command and then continues execution. This would look something like this:

0:000> * remove existing breakpoint
0:000> bc 0
0:000> * check start address of RunTest
0:000> !name2ee DbgTest.exe Program.RunTest
Module:      000d2e9c
Assembly:    DbgTest.exe
Token:       06000002
MethodDesc:  000d37fc
Name:        Program.RunTest(System.String, Int32)
JITTED Code Address: 001600d0
0:000> * set breakpoint
0:000> bp 001600d0 "!dumpobj -nofields edx; dd [esp+4] L1; g"
0:000> g
Name:        System.String
MethodTable: 70e9f9ac
EEClass:     70bd8bb0
Size:        42(0x2a) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      Test Run No. 1
002fece4  00000001
Executing test
Name:        System.String
MethodTable: 70e9f9ac
EEClass:     70bd8bb0
Size:        42(0x2a) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      Test Run No. 2
002fece4  00000002
Executing test
Name:        System.String
MethodTable: 70e9f9ac
EEClass:     70bd8bb0
Size:        42(0x2a) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      Test Run No. 3
002fece4  00000003
...

As you can see, we’re indeed getting the values of both our arguments without problems in the debugger log (which we could easily write to a file using the .logopen command). This is a simple scenario, but can still prove useful sometimes. Of course, you could argue that going through all these contortions might be over the top, given that the !ClrStack -p command can give you parameters to each function in the call stack. The answer is that !ClrStack doesn’t make it easy to dump just the first frame, not does it combine with other commands so that you can easily use !DumpObj on the parameter values.

[1] If !BPMD doesn’t seem to work, it’s likely because the CLR debugger notifications are disabled. See this post on how to fix it (for .NET 4.0, just remember to replace mscorwks for clr).


			

1 comment

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>