Archive for March, 2006

Please Stop Spamming the Debugger Output

When I'm writing a GUI or a multithreaded server application, I make heavy use of OutputDebugString (and various API's that map to it). This is a very useful tool when the act of stepping through an application has side effects that drastically change the experiment. Unfortunately, it looks everyone else likes this API, too.

I try to be courteous and pay my developer taxes here–when my application is deployed to customers, rest assured that it will not be writing debugger output by default. I put my calls to OutputDebugString on a switch in one way or another, or I just compile them out in release mode.

(This is not just being kind to anyone trying to debug something else on a machine running my application. I need to do this to avoid embarrassment. I curse quite a bit in my traces.)

Not everybody is taking the trouble to do this. To wit:

Debugger output spam from Visual Studio

If I open up dbmon or debugview and wave my mouse around a little, i'm inundated with messages from these applications:

  • Visual Studio 2005 [by far the worst].
  • Visual SourceSafe [a close second place].
  • Trillian
  • The remnants of Symantec products that I have not yet succeeded in disabling.

I find it particularly annoying that my development tools are hampering my development in this way.

Pointless Minesweeper Source Code

The source code for my Pointless Minesweeper Clone can be found here. Enjoy it.

The license is BSD (you may know this as the "hey, go nuts" license).

Pointless Minesweeper Clone

Minesweeper++

My roommate, a grizzled veteran of Cornell's CS 211, made an announcement a week or two ago. It was something along the lines of, "gee whiz, I'm glad they didn't make us write minesweeper as a project. It looks impossible." To prove my vast intellectual superiority I made a winforms clone in about six or seven hours, including the time it took to draw the graphics and perform extensive "QA."

You can start the clickonce app from this link.

Screenshot:

Minesweeper++ screenshot

The source will be forthcoming. Bugs and so forth, feel free to contact me. The rendering is a bit on the slow side for my tastes, so you needn't mention that.

Debugger Exercise: Displaying a Function’s Return Value

I found myself needing to automatically manipulate the return value of a managed function in release code today. I thought this would make an interesting little writeup.

For the purposes of the demonstration, let's use this example program:

class Program
{
    static void Main()
    {
        while (!Console.KeyAvailable)
        {
            Console.WriteLine(FooBar(false));
            Console.WriteLine(FooBar2());
        }
    }

    static string FooBar(bool b)
    {
        if (b)
        {
            return "b";
        }
        return "a";
    }

    static string FooBar2()
    {
        return FooBar(true);
    }
}

The function we're interested in will be FooBar. I've made things interesting by calling the function from two places–let's assume we're not sure where the function is called from. We'll make things more interesting still by accepting the limitation that we won't cheat and set a breakpoint on the ret instruction in FooBar. The function I needed to instrument today was a little monolithic, so let's take it as a given that we need to be able to handle a function that might be long and might have more than one exit point.

Compile this program and start it in WinDbg. Start by loading SOS:

0:003> .loadby sos mscorwks

The first thing we'll do is set a breakpoint on FooBar. (I'm going to do this manually so that these steps will work with the CLR v1.1. The new version of SOS makes this slightly easier. I'm also going to cover this quickly, so if you want a clearer explanation of what's going on in this next step see Eran Sandler's writeup here.)

To set the breakpoint, let the program run for a second so that the method is compiled by the JIT. Then we need to find and dump out the MethodTable for the class:

0:003> !name2ee retaddr!retaddr.Program
Module: 00912d5c (retaddr.exe)
Token: 0x02000002
MethodTable: 00913140
EEClass: 009112ec
Name: retaddr.Program

0:003> !dumpmt -md 00913140
EEClass: 009112ec
Module: 00912d5c
Name: retaddr.Program
mdToken: 02000002
BaseSize: 0xc
ComponentSize: 0x0
Number of IFaces in IFaceMap: 0
Slots in VTable: 8
--------------------------------------
MethodDesc Table
   Entry MethodDesc      JIT Name
...
00d00070   00913120      JIT retaddr.Program.Main()
00d000d8   00913128      JIT retaddr.Program.FooBar(Boolean)
00d00130   00913130      JIT retaddr.Program.FooBar2()
...

Now that we have the MethodTable, we need to dump out the MethodDesc for FooBar to get the virtual address of the jitted code.

0:003> !dumpmd 00913128
Method Name: retaddr.Program.FooBar(Boolean)
Class: 009112ec
MethodTable: 00913140
mdToken: 06000002
Module: 00912d5c
IsJitted: yes
m_CodeOrIL: 00d000d8

The compiled method begins at m_CodeOrIL (this is called "Method VA" in SOS 1.1). We can set a breakpoint there with "bp 00d000d8."

Here comes the trick. We know that the return address to the method should be on the top of the stack when the method is called. In other words, the ESP register points at the return address. We can set a dynamic breakpoint on that return address using a command like this:

bp 00d000d8 "bp poi(@esp); g"

If you try this, you'll notice that we break right after FooBar has returned to its caller. As with any function obeying one of the standard calling conventions, the return value is stored in the EAX register. We can give the dynamic breakpoint a command of its own that manipulates this value like this:

bp 00d000d8 "bp poi(@esp) \"!do -nofields @eax; g\"; g"

If we run the sample program now, we'll see this output repeating itself:

breakpoint 1 redefined
Name: System.String
MethodTable: 790fa3e0
EEClass: 790fa340
Size: 20(0x14) bytes
String: a

breakpoint 2 redefined
Name: System.String
MethodTable: 790fa3e0
EEClass: 790fa340
Size: 20(0x14) bytes
String: b

Voila.

Beware the OutOfMemoryException Red Herring

Low memory conditions have a way of executing lightly-or-never-tested code paths. Bugs in these paths can sometimes cast a penumbra over the real reason your application is crashing.

Worse, the resulting exceptions or crashes are likely to be more or less nondeterministic. Worse still, the most obvious steps with SOS rarely work once the CLR or the IIS worker process has started to OOM and has tossed you an access violation.

As a concrete example–this is a !clrstack from an application that appears to be crashing with an IOException.

0:026> !clrstack
Thread 26
ESP         EIP
0x10e3ea90  0x77e55dea [FRAME: GCFrame]

This doesn't tell us much, but if we look at the native stack:

0:026> k
ChildEBP RetAddr
10e3e9e8 79216aed kernel32!RaiseException+0x53
WARNING: Stack unwind information not available. Following frames may be wrong.
10e3ea40 79216a70 mscorsvr!GetAssemblyMDImport+0x2e1d4
10e3ea68 79216a24 mscorsvr!GetAssemblyMDImport+0x2e157
10e3ea78 79265ec2 mscorsvr!GetAssemblyMDImport+0x2e10b
10e3eab4 7924e9d3 mscorsvr!CoEEShutDownCOM+0x12dc1
10e3eac8 7c82eeb2 mscorsvr!GetMetaDataPublicInterfaceFromInternal+0x7e73
10e3eaec 7c82ee84 ntdll!ExecuteHandler2+0x26
10e3eb94 7c82ecc6 ntdll!ExecuteHandler+0x24
10e3eb94 77e55dea ntdll!KiUserExceptionDispatcher+0xe
10e3eee0 79216aed kernel32!RaiseException+0x53
10e3ef38 7924c8d0 mscorsvr!GetAssemblyMDImport+0x2e1d4
10e3efe8 791b3208 mscorsvr!GetMetaDataPublicInterfaceFromInternal+0x5d70
10e3eff4 791b3ad7 mscorsvr!Ordinal76+0x3208
10e3f108 791d3ef0 mscorsvr!Ordinal76+0x3ad7
10e3f1c4 791d3fa4 mscorsvr!GetCompileInfo+0x13e3
10e3f1ec 7931392f mscorsvr!GetCompileInfo+0x1497
10e3f21c 791cc3c8 mscorsvr!ReleaseFusionInterfaces+0x5f3d7
10e3f264 793139e1 mscorsvr!Ordinal76+0x1c3c8
10e3f2d8 7924a3f2 mscorsvr!ReleaseFusionInterfaces+0x5f489
10e3f2f0 791d4096 mscorsvr!GetMetaDataPublicInterfaceFromInternal+0x3892

We can see from the frames in the middle (the lower kernel32!RaiseException through the subsequent ntdll calls) that the current exception is being raised from inside another exception handler (a catch block, in managed terms). The current exception doesn't appear to reflect this:

0:026> !cen
System.IO.IOException (0xbab602fc)

0:026> !do 0xbab602fc
Name: System.IO.IOException
-----------------
Exception bab602fc in MT 79bd1234: System.IO.IOException

But with some wizardry, we can coerce the relevant information. We can hypothesize that the original exception would be passed as a parameter somewhere before the original call to kernel32!RaiseException. Isolating just that frame on the stack, and the frame before it:

0:026> kb
…
10e3eee0 79216aed e0434f4d 00000001 00000000 kernel32!RaiseException+0x53
…
10e3ef38 7924c8d0 bab5ce60 00000000 bab5ce60 mscorsvr!GetAssemblyMDImport+0x2e1d4

The address 0xbab5ce60 (second line) looks like a good candidate, being close to the address of the current exception while not being equal to it.

0:026> !do bab5ce60
Name: System.IO.IOException
-----------------
Exception bab5ce60 in MT 79bd1234: System.IO.IOException
_message: Unable to create a transport connection.
_innerException:
   Exception 06c6003c in MT 79b96cec: System.OutOfMemoryException
   _remoteStackTraceString:

Bingo. (Mind you, we haven't taken any steps yet to actually fix the problem.) This was relatively easy, since all of the relevant information could be reconstructed from the offending stack. In other situations, you may need to !DumpAllExceptions to see what has been happening recently in the application.

Note: a very good hint that you are looking at an OOM situation is that your crash dump is exactly two gigabytes in size.

The Russian Doll Approach to Web Services

Here's an anecdote for the WTF inbox. I assure you this is very real, but I cannot divulge any of the specifics.

Some time ago a friend of mine was talking to a web services vendor, who was explaining his versioning scheme. The vendor's approach was to make all of the web service functions accept a single parameter describing the function being called, and the version of the function requested. Prototypically:

public object Foo(FunctionCallInfo)

And what is FunctionCallInfo, you ask? Why, it is a strict XML document adhering to a schema that he would provide.

My observation, which my friend also arrived at independently, was that this person was basically creating an implementation of web services inside of web services. So nat'ralists observe, a flea / Hath smaller fleas that on him prey.

XML: the cause of, and solution to, all of your development problems.

What would do in this situation?

C++ and VS2005 Deployment PSA

This is a straightforward fix, but I couldn't find anything about it anywhere else. I have a handful of old ATL projects that have been upgraded over the years from Visual C++ 6.0, through VS2003 and are now being built using Visual C++ 8. I was trying to add them to a deployment project today, and kept running into this error:

Two or more objects have the same target location
('[targetdir]\regsvr32.trg').

regsvr32 error building a migrated C++ project

The issue is that the way libraries are registered has changed over the various incarnations of Visual Studio. My old projects were still using a post-build step to perform registration:

VC++ project using a post-build step to register itself

This apparently can create the output file that the deployment package is complaining about. The fix is to delete the post build steps and enable the modern registration option on the Linker's General tab.

VC++ project being registered via the new method.