Intelligible stack traces for async, iterators and Dictionary (key not found)
.NET Core 2.1 now has intelligible async stack traces!
But what do I mean by this bold claim?
Well, you can now determine the correct overload that was called for async and iterator methods; just from the stacktrace, which was not possible previously:
System.Collections.Generic.KeyNotFoundException: The given key '0' was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.Sequence(Int32 start)+MoveNext()
at Program.Sequence(Int32 start, Int32 end)+MoveNext()
at Program.MethodAsync()
at Program.MethodAsync(Int32 v0)
at Program.MethodAsync(Int32 v0, Int32 v1)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2, Int32 v3)
at Program.Main(String[] args)
Issue: “Make stack traces readable”
David Kean(@davkean) raised the following issue: Make stack traces readable dotnet/corefx#24627
in corefx on Oct 13, 2017
Now that Task, async and await are prevalent - stack traces have become a lot less readable.
The stack trace output in .NET for async has been winding me up for 5 years…
It only occurred to me in October 2017; when I saw this issue, that since .NET Core is now fully open source, I could actually change it.
As a refresher; the code at the bottom of this post will output the following stack trace for the thrown exception:
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at System.ThrowHelper.ThrowKeyNotFoundException()
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.<Sequence>d__8.MoveNext()
at Program.<Sequence>d__7.MoveNext()
at Program.<MethodAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Program.<MethodAsync>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Program.<MethodAsync>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Program.<MethodAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Program.<MethodAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Program.<Main>d__1.MoveNext()
(Line numbers removed for brevity e.g. in C:\Work\Exceptions\Program.cs:line 14)
Sometimes with even more verbose glue sections:
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
The general purpose of a stack trace is to determine where in the source code the error occurred and the path that got it to that point.
However, async stack traces up till now have been both impenetrable and contain a lot of unhelpful noise.
PR: “Hide post exception stack frames”
A stack trace is generally expected to be the direct flow out from where an exception is thrown to where its caught.
When an async function resumes with an exception; it performs some extra steps to determine how to respond and ensure cleanup has been done before continuing.
While these extra steps get added to the call stack, they don’t help in anyway determine the call stack as they occur after the exception.
So as well as being very noisy and repeative, they don’t add value in determining how the code reached that point.
The call stack that happened and the call stack that is reported don’t agree:
After removing these post exception stack frames:
Hide post exception stack frames dotnet/coreclr#14652; the stack trace starts to become
more approachable:
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.<Sequence>d__7.MoveNext()
at Program.<Sequence>d__6.MoveNext()
at Program.<MethodAsync>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Program.<MethodAsync>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Program.<MethodAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Program.<MethodAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Program.<MethodAsync>d__1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Program.<Main>d__0.MoveNext()
And the reported call stack now agrees with the actual call stack:
PR: “Remove Edi boundary for async”
The exceptions in async are propagated using the ExceptionDispatchInfo class. This marks a boundary at each join point with:
--- End of stack trace from previous location where exception was thrown ---
This is to inform you that two call stacks have been merged; and a transition has occurred.
In async this is so frequent it’s just noise and adds no value.
After Remove Edi boundary for async dotnet/coreclr#15781 all of the stack trace becomes valuable:
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.<Sequence>d__7.MoveNext()
at Program.<Sequence>d__6.MoveNext()
at Program.<MethodAsync>d__5.MoveNext()
at Program.<MethodAsync>d__4.MoveNext()
at Program.<MethodAsync>d__3.MoveNext()
at Program.<MethodAsync>d__2.MoveNext()
at Program.<MethodAsync>d__1.MoveNext()
at Program.<Main>d__0.MoveNext()
PR: “Resolve iterators and async methods in stacktrace”
At this point the stacktrace is now clean from noise. However, it’s still hard to determine what exactly is being called.
The stacktrace contains the method signatures for the async statemachine infrastructure; created by the C# compiler, not for the original source code.
You can detemine the method name as that’s present; but you can’t determine the exact overload that was called without digging deeper.
After Resolve iterators and async methods in stacktrace dotnet/coreclr#14655 the
stacktrace is much closer to the orignial source:
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.Sequence(Int32 start)+MoveNext()
at Program.Sequence(Int32 start, Int32 end)+MoveNext()
at Program.MethodAsync()
at Program.MethodAsync(Int32 v0)
at Program.MethodAsync(Int32 v0, Int32 v1)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2, Int32 v3)
at Program.Main(String[] args)
PR: “Key item added to KeyNotFoundException”
I picked “Key Not Found” to throw the exception in the example; because there is an additional bonus.
Anirudh Agnihotry(@Anipik) added Key item added to KeyNotFoundException dotnet/coreclr#15201
This means the exception now actually gives you the information as to which key wasn’t found:
System.Collections.Generic.KeyNotFoundException: The given key '0' was not present in the dictionary.
at System.Collections.Generic.Dictionary`2.get_Item(TKey key)
at Program.Sequence(Int32 start)+MoveNext()
at Program.Sequence(Int32 start, Int32 end)+MoveNext()
at Program.MethodAsync()
at Program.MethodAsync(Int32 v0)
at Program.MethodAsync(Int32 v0, Int32 v1)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2)
at Program.MethodAsync(Int32 v0, Int32 v1, Int32 v2, Int32 v3)
at Program.Main(String[] args)
Downlevel runtimes and going further
Hopefully, this will be coming to Mono shortly and .NET Framework at a later stage; but if you are
on an earlier runtime version (.NET Core 1.0 - 2.0; .NET Framework or Mono) you can get a similar effect; plus more,
by using the Ben.Demystifier NuGet package and using .Demystify() on your exception:
catch (Exception e)
{
Console.WriteLine(e.Demystify());
}
This produces a richer output that matches C# source code; but its nice to have it built in!
System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary.
at TValue System.Collections.Generic.Dictionary<TKey, TValue>.get_Item(TKey key)
at IEnumerable<int> Program.Sequence(int start)+MoveNext()
at IEnumerable<int> Program.Sequence(int start, int end)+MoveNext()
at async Task<int> Program.MethodAsync()
at async Task<int> Program.MethodAsync(int v0)
at async Task<int> Program.MethodAsync(int v0, int v1)
at async Task<int> Program.MethodAsync(int v0, int v1, int v2)
at async Task<int> Program.MethodAsync(int v0, int v1, int v2, int v3)
at async Task Program.Main(string[] args)
.NET Core 2.1 will be the best version of .NET Core for many reasons; this is just one of the little things that makes it better…
Code for exception and stacktraces above
Code that generates the exception and stacktrace for the above:
class Program
{
static Dictionary<int, int> _dict = new Dictionary<int, int>();
static async Task Main(string[] args)
{
try
{
var value = await MethodAsync(1, 2, 3, 4);
Console.WriteLine(value);
}
catch (Exception e)
{
Console.WriteLine(e);
}
}
static async Task<int> MethodAsync(int v0, int v1, int v2, int v3)
=> await MethodAsync(v0, v1, v2);
static async Task<int> MethodAsync(int v0, int v1, int v2)
=> await MethodAsync(v0, v1);
static async Task<int> MethodAsync(int v0, int v1)
=> await MethodAsync(v0);
static async Task<int> MethodAsync(int v0)
=> await MethodAsync();
static async Task<int> MethodAsync()
{
await Task.Delay(1000);
int value = 0;
foreach (var i in Sequence(0, 5))
{
value += i;
}
return value;
}
static IEnumerable<int> Sequence(int start, int end)
{
for (var i = start; i <= end; i++)
{
foreach (var item in Sequence(i))
{
yield return item;
}
}
}
static IEnumerable<int> Sequence(int start)
{
var end = start + 10;
for (var i = start; i <= end; i++)
{
_dict[i] = _dict[i] + 1; // Throws exception
yield return i;
}
}
}
Get in touch!
For press: press@ageofascent.com.