C# – What makes the Visual Studio debugger stop evaluating a ToString override

cdebuggingvisual-studio-2015

Environment: Visual Studio 2015 RTM. (I haven't tried older versions.)

Recently, I've been debugging some of my Noda Time code, and I've noticed that when I've got a local variable of type NodaTime.Instant (one of the central struct types in Noda Time), the "Locals" and "Watch" windows don't appear to call its ToString() override. If I call ToString() explicitly in the watch window, I see the appropriate representation, but otherwise I just see:

variableName       {NodaTime.Instant}

which isn't very useful.

If I change the override to return a constant string, the string is displayed in the debugger, so it's clearly able to pick up that it's there – it just doesn't want to use it in its "normal" state.

I decided to reproduce this locally in a little demo app, and here's what I've come up with. (Note that in an early version of this post, DemoStruct was a class and DemoClass didn't exist at all – my fault, but it explains some comments which look odd now…)

using System;
using System.Diagnostics;
using System.Threading;

public struct DemoStruct
{
    public string Name { get; }

    public DemoStruct(string name)
    {
        Name = name;
    }

    public override string ToString()
    {
        Thread.Sleep(1000); // Vary this to see different results
        return $"Struct: {Name}";
    }
}

public class DemoClass
{
    public string Name { get; }

    public DemoClass(string name)
    {
        Name = name;
    }

    public override string ToString()
    {
        Thread.Sleep(1000); // Vary this to see different results
        return $"Class: {Name}";
    }
}

public class Program
{
    static void Main()
    {
        var demoClass = new DemoClass("Foo");
        var demoStruct = new DemoStruct("Bar");
        Debugger.Break();
    }
}

In the debugger, I now see:

demoClass    {DemoClass}
demoStruct   {Struct: Bar}

However, if I reduce the Thread.Sleep call down from 1 second to 900ms, there's still a short pause, but then I see Class: Foo as the value. It doesn't seem to matter how long the Thread.Sleep call is in DemoStruct.ToString(), it's always displayed properly – and the debugger displays the value before the sleep would have completed. (It's as if Thread.Sleep is disabled.)

Now Instant.ToString() in Noda Time does a fair amount of work, but it certainly doesn't take a whole second – so presumably there are more conditions that cause the debugger to give up evaluating a ToString() call. And of course it's a struct anyway.

I've tried recursing to see whether it's a stack limit, but that appears not to be the case.

So, how can I work out what's stopping VS from fully evaluating Instant.ToString()? As noted below, DebuggerDisplayAttribute appears to help, but without knowing why, I'm never going to be entirely confident in when I need it and when I don't.

Update

If I use DebuggerDisplayAttribute, things change:

// For the sample code in the question...
[DebuggerDisplay("{ToString()}")]
public class DemoClass

gives me:

demoClass      Evaluation timed out

Whereas when I apply it in Noda Time:

[DebuggerDisplay("{ToString()}")]
public struct Instant

a simple test app shows me the right result:

instant    "1970-01-01T00:00:00Z"

So presumably the problem in Noda Time is some condition that DebuggerDisplayAttribute does force through – even though it doesn't force through timeouts. (This would be in line with my expectation that Instant.ToString is easily fast enough to avoid a timeout.)

This may be a good enough solution – but I'd still like to know what's going on, and whether I can change the code simply to avoid having to put the attribute on all the various value types in Noda Time.

Curiouser and curiouser

Whatever is confusing the debugger only confuses it sometimes. Let's create a class which holds an Instant and uses it for its own ToString() method:

using NodaTime;
using System.Diagnostics;

public class InstantWrapper
{
    private readonly Instant instant;

    public InstantWrapper(Instant instant)
    {
        this.instant = instant;
    }

    public override string ToString() => instant.ToString();
}

public class Program
{
    static void Main()
    {
        var instant = NodaConstants.UnixEpoch;
        var wrapper = new InstantWrapper(instant);

        Debugger.Break();
    }
}

Now I end up seeing:

instant    {NodaTime.Instant}
wrapper    {1970-01-01T00:00:00Z}

However, at the suggestion of Eren in comments, if I change InstantWrapper to be a struct, I get:

instant    {NodaTime.Instant}
wrapper    {InstantWrapper}

So it can evaluate Instant.ToString() – so long as that's invoked by another ToString method… which is within a class. The class/struct part seems to be important based on the type of the variable being displayed, not what code needs
to be executed in order to get the result.

As another example of this, if we use:

object boxed = NodaConstants.UnixEpoch;

… then it works fine, displaying the right value. Colour me confused.

Best Answer

Update:

This bug has been fixed in Visual Studio 2015 Update 2. Let me know if you are still running into problems evaluating ToString on struct values using Update 2 or later.

Original Answer:

You are running into a known bug/design limitation with Visual Studio 2015 and calling ToString on struct types. This can also be observed when dealing with System.DateTimeSpan. System.DateTimeSpan.ToString() works in the evaluation windows with Visual Studio 2013, but does not always work in 2015.

If you are interested in the low level details, here's what's going on:

To evaluate ToString, the debugger does what's known as "function evaluation". In greatly simplified terms, the debugger suspends all threads in the process except the current thread, changes the context of the current thread to the ToString function, sets a hidden guard breakpoint, then allows the process to continue. When the guard breakpoint is hit, the debugger restores the process to its previous state and the return value of the function is used to populate the window.

To support lambda expressions, we had to completely rewrite the CLR Expression Evaluator in Visual Studio 2015. At a high level, the implementation is:

  1. Roslyn generates MSIL code for expressions/local variables to get the values to be displayed in the various inspection windows.
  2. The debugger interprets the IL to get the result.
  3. If there are any "call" instructions, the debugger executes a function evaluation as described above.
  4. The debugger/roslyn takes this result and formats it into the tree-like view that's shown to the user.

Because of the execution of IL, the debugger is always dealing with a complicated mix of "real" and "fake" values. Real values actually exist in the process being debugged. Fake values only exist in the debugger process. To implement proper struct semantics, the debugger always needs to make a copy of the value when pushing a struct value to the IL stack. The copied value is no longer a "real" value and now only exists in the debugger process. That means if we later need to perform function evaluation of ToString, we can't because the value doesn't exist in the process. To try and get the value we need to emulate execution of the ToString method. While we can emulate some things, there are many limitations. For example, we can't emulate native code and we can't execute calls to "real" delegate values or calls on reflection values.

With all of that in mind, here is what's causing the various behaviors you are seeing:

  1. The debugger isn't evaluating NodaTime.Instant.ToString -> This is because it is struct type and the implementation of ToString can't be emulated by the debugger as described above.
  2. Thread.Sleep seems to take zero time when called by ToString on a struct -> This is because the emulator is executing ToString. Thread.Sleep is a native method, but the emulator is aware of it and just ignores the call. We do this to try and get a value to show to the user. A delay wouldn't be helpful in this case.
  3. DisplayAttibute("ToString()") works. -> That is confusing. The only difference between the implicit calling of ToString and DebuggerDisplay is that any time-outs of the implicit ToString evaluation will disable all implicit ToString evaluations for that type until the next debug session. You may be observing that behavior.

In terms of the design problem/bug, this is something we are planning to address in a future release of Visual Studio.

Hopefully that clears things up. Let me know if you have more questions. :-)