Example of an Async Stack Trace

What is the output of this Console App?

class Program
{
    static async Task Main(string[] args)
    {
        await MethodOne();
    }

    public static async Task MethodOne()
    {
        await MethodTwo();
    }

    public static async Task MethodTwo()
    {
        await Task.Yield();
        throw new Exception();
    }
}

There’s an unhandled exception, so the full stack trace is printed to the Console:

Unhandled exception. System.Exception: Exception of type 'System.Exception' was thrown.
   at StackTraceDelegation.Program.MethodTwo() in 
D:\StackTraceDelegation\Program.cs:line 18
   at StackTraceDelegation.Program.MethodOne() in 
D:\StackTraceDelegation\Program.cs:line 13
   at StackTraceDelegation.Program.Main(String[] args) in 
D:\StackTraceDelegation\Program.cs:line 10
   at StackTraceDelegation.Program.<Main>(String[] args)

If you’ve been exploring the async/await State Machine so far, this output should look suspicious.

You know that async methods don’t just directly call each other. Instead, the compiler generates a State Machine for each one with a MoveNext method that executes the method body and handles pauses and continuations.

But the stack trace above doesn’t give any clues about this. It looks as if the methods just call each other in a synchronous fashion.

Why is that? Well, it turns out the runtime tries to make our life easier. It puts in the effort to hide the async complexities and present us with this beautiful stack trace.

This hasn’t always been the case. To prove that, see the output from the same program but ran in an older .Net version (4.5.1):

Unhandled Exception: System.Exception: Exception of type 'System.Exception' was thrown.
   at StackTraceDelegation.Program.<MethodTwo>d__2.MoveNext() in 
D:\StackTraceDelegation\Program.cs:line 18
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at StackTraceDelegation.Program.<MethodOne>d__1.MoveNext() in 
D:\StackTraceDelegation\Program.cs:line 13
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at StackTraceDelegation.Program.<Main>d__0.MoveNext() in 
D:\StackTraceDelegation\Program.cs:line 10
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at StackTrace.Program.<Main>(String[] args)

It’s uglier, but it makes a lot more sense. You can clearly see the following (logical) call chain:

MainStateMachine.MoveNext -> MethodOneStateMachine.MoveNext -> MethodTwoStateMachine.MoveNext

Also, recall that async execution pauses when an async operation occurs. At this point, we would lose the call chain if we don’t capture it somewhere. You’ll see the details on this below, but for now, just remember this is one of the responsibilities of the async/await State Machine workflow.

Before digging deeper into all of this magic, I want to concentrate on some direct implications of the good-looking stack trace and how it can lead to hurting your system if you’re not careful.

The “Refactoring”

Frankly, MethodOne doesn’t do anything. It just invokes MethodTwo:

public static async Task MethodOne()
{
    await MethodTwo();   
}

This means that MethodOne doesn’t have to be marked as async. It can just directly return the Task from MethodTwo, like so:

class Program
{
    static async Task Main(string[] args)
    {
        await MethodOne();
    }

    public static Task MethodOne() => MethodTwo();

    public static async Task MethodTwo()
    {
        await Task.Yield();
        throw new Exception();
    }
}

This looks like reasonable refactoring, and you would see it as a suggestion in many code reviews.

Before getting too excited, let’s rerun the program and see the new output:

System.Exception: Exception of type 'System.Exception' was thrown.
   at StackTrace.Program.MethodTwo() in 
D:\StackTraceDelegation\Program.cs:line 18
   at StackTrace.Program.Main(String[] args) in 
D:\StackTraceDelegation\Program.cs:line 10

Did you notice the difference with the initial version? Here it is once again:

Unhandled exception. System.Exception: Exception of type 'System.Exception' was thrown.
   at StackTraceDelegation.Program.MethodTwo() in 
D:\StackTraceDelegation\Program.cs:line 18
   at StackTraceDelegation.Program.MethodOne() in 
D:\StackTraceDelegation\Program.cs:line 13
   at StackTraceDelegation.Program.Main(String[] args) in 
D:\StackTraceDelegation\Program.cs:line 10
   at StackTraceDelegation.Program.<Main>(String[] args)

That’s right – MethodOne has disappeared from the Stack Trace.

How come?

Direct Task Forwarding in Async Methods Hurts Traceability

There are two questions we need to answer now – what happened and why?

The ”what” bit is clear – we lost a part of our stack trace by dropping the async keyword and directly returning the Task from the next method in the call chain.

Why is this bad?

Well, imagine some exception occurs in your Prod environment, and you’re reviewing the error logs. You will definitely expect to see MethodOne over there, won’t you? You may even want to search by MethodOne in your logs dashboard UI, like Kibana. Especially if MethodOne is some public entry point.

I’ve experienced that myself. A method “swallowed” in such a way can raise a lot of confusion and frustration.

I hope you agree.

Now, let’s move to the fun part!

Where Did MethodOne Go?

This section requires familiarity with the async/await machinery, at least at a conceptual level.

Let’s see the stack trace with the missing MethodOne in .Net 4.5.1

Unhandled Exception: System.Exception: Exception of type 'System.Exception' was thrown.
   at StackTraceDelegation.Program.<MethodTwo>d__2.MoveNext() in 
D:\StackTraceDelegation\Program.cs:line 18
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at StackTraceDelegation.Program.<Main>d__0.MoveNext() in 
D:\StackTraceDelegation\Program.cs:line 10
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at StackTrace.Program.<Main>(String[] args)

It’s time to reach out for a decompiler to see how our program looks behind the scenes.

Here is the body of MethodOne, which is precisely the same as the original version:

No surprises here.

Now, I assume you’re familiar with the mechanics of how a method is pushed and popped from the execution stack.

Simply put, once MethodOne returns, it disappears from our program. The caller receives the Task from MethodTwo. MethodOne is popped from the execution stack and vanishes without a trace.

Contrast that with the body of MethodTwo:

Again, if you have no idea why MethodTwo has been transformed in such a way, you may want to read through the Main Workflow and State Transitions article.

MethodTwo was marked with the async keyword. This means the compiler produces a State Machine for it. This State Machine is invoked (indirectly) from the underlined line above.

Then, the MoveNext method of the State Machine will run.

The State Machine and MoveNext for MethodTwo look like so:

At the underlined line, MoveNext (indirectly) registers itself as a continuation to the task awaiter from the Task.Yield() call.

Deep down inside the AwaitUnsafeOnCompleted invocation, the current stack trace is saved within the ExecutionContext so that MethodTwo will be “remembered” as part of the call chain.

This is why we get MethodTwo (and any other async method) in the exceptions’ stack trace.

The code that deals with all of this is quite challenging to follow. Feel free to do that on your own, but here’s just a tiny fragment for some intuition:

How About the Performance Overhead?

To reiterate, marking a method as async means it will be transformed into a State Machine by the compiler.

This certainly brings with itself some time & space execution overhead.

However, except for some sporadic cases, this should be pretty much unnoticeable.

Especially compared to losing segments of your stack traces, thus making potential problems harder to troubleshoot.

Summary

In this article, you’ve seen how stack traces are handled within an async execution.

You also explored how seemingly reasonable refactoring can make methods disappear from the stack trace. This should be avoided as it’s very frustrating when troubleshooting failures.

I hope this was useful. See you next time!

For additional in-depth materials on async/await in C#, you can check this Pluralsight course.