OMG! They Killed My Stacktrace!

I can’t get that flashing red light on my desktop out of my mind. It’s nagging me. What is it? Oh my… I just killed the build! How embarrassing – only a few weeks on the team and I’m already a trouble-maker. Resistance is futile. The flashing red light got me. Five acceptance tests are failing on the build server. Hold on – those tests are working on my machine! Can’t I just add a works on my machine badge and carry on with the other things I have in the work pipeline? The “getting things done guy” inside me says yes, but my engineer heart tells me no. I roll up my sleeves and start analyzing what went wrong.

🔗Me against five failing acceptance tests, round one: fight!

I open up the failing acceptance tests and analyze them and the code underneath. I ask myself questions:

• Are there potential flaws in the execution logic of the production code? If so…
  • Was the code written under the wrong assumptions?
  • Did the test expose a race condition in the code?
• Are there potential flaws in the execution or synchronization logic of the acceptance tests? If so…
  • Was the test code written under the wrong assumptions?

I couldn’t find anything. Let’s do a git blame. Yes, I correctly changed the acceptance tests before I implemented my new feature. The tests had been failing, and when I implemented the anticipated changes they went green. I think I need to take a step back. What are the tests actually trying to achieve?

All the failing tests check whether the NServiceBus core framework correctly handles and rethrows exceptions being raised in the user code. We verify whether the correct exceptions occurred and furthermore we verify whether the stack trace represents the correct execution logic. The code looks something like this (drastically simplified):

public class When_handler_throws
{
    [Test]
    public void Should_receive_exception_from_handler()
    {
        var invoker = new HandlerInvoker(new Handler());

        var exception = Assert.Throws<InvalidOperationException>(() => invoker.Invoke(new object()));

        StackTraceAssert.StartsWith(@"at NServiceBus.AcceptanceTests.Exceptions.When_handler_throws.Handler.Handle(Object message) at NServiceBus.AcceptanceTests.Exceptions.When_handler_throws.HandlerInvoker.Invoke(Object message)", exception.StackTrace);
    }

    [DebuggerNonUserCode]
    public class HandlerInvoker
    {
        readonly Handler handler;

        public HandlerInvoker(Handler handler)
        {
            this.handler = handler;
        }

        public void Invoke(object message)
        {
            handler.Handle(message);
        }
    }

    public class Handler
    {
        public void Handle(object message)
        {
            throw new InvalidOperationException("Uuups");
        }
    }
}

Here is the output on my local machine:

And here is the output on the build server:

at NServiceBus.AcceptanceTests.Exceptions.When_handler_throws.Handler.Handle(Object message)
at NUnit.Framework.Assert.Throws(IResolveConstraint expression, TestDelegate code, String message, Object[] args)
  Expected string length 92 but was 193. Strings differ at index 92.

  Expected: "...Handler.Handle(Object message)"

  But was:  "...Handler.Handle(Object message)\r\nat NServiceBus.AcceptanceT..."

  --------------------------------------------^

I could burst into tears! Maybe Szymon, a coworker of mine, could shed some light on this issue. He agrees to play the rubber duck.

🔗Me (and Szymon) against five failing acceptance tests, round two: fight!

Szymon said with a cool and dry voice:

Have you tried turning it on and off again? I mean switching from Debug to Release build on your local machine?

Duh! One second later:

This is something you kinda know in the back of your brain but tend to forget:

• Debug build != Release build != how the code behaves when the debugger is attached*

This is exactly what got me here.

🔗And the winner is us, by a knockout!

We quickly discussed whether we should remove the DebuggerNonUserCode attribute and decided to keep it because the HandlerInvoker class is totally internal and doesn’t need to be exposed in the stack trace. What options are left to make the tests green?

• Add separate assertions with ifdef for DEBUG and RELEASE
• Remove the stack trace assertions

We decided to remove the stack trace assertions because they didn’t provide much value and were testing too many internals. Plus, the Assert.Throws is already enough to verify whether the framework does the right thing. One git commit and git push origin develop later, the build was green again on my local machine and this time, also on the build server!

Every great fighter reflects upon what went well or poorly after a fight to improve for the next combat situation. Here’s what I learned from this one:

• Debug build is different from the Release build.
• Your code can behave differently when the debugger is attached.
• Bringing in another pair of eyes, as I did with Szymon, is a useful technique to get to the bottom of the problem quicker than you’d ever be able to alone.

I’m certain these small tips will make you a winner, too.

* For more background on Debug vs Release, here is some reference material:

• Scott Hanselman - Release IS NOT Debug: 64bit Optimizations and C# Method Inlining in Release Build Call Stacks
• Eric Lippert - What does the optimize switch do?

About the author: Daniel Marbach is a solution architect at Particular Software, Microsoft Integration MVP, coach and passionate blogger.