Runtime: Make stack traces readable

[davkean]

Now that Task, async and await are prevalent - stack traces have become a lot less readable.

Here's one that I was sent today:

System.InvalidOperationException: The specified API "ConditionedProperties" is not available because ProjectLoadSettings.DoNotEvaluateElementsWithFalseCondition was set when loading this project.
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInvalidOperation(String resourceName, Object[] args) in e:\projects\msbuild_3\src\Shared\ErrorUtilities.cs:line 304
   at Microsoft.Build.Evaluation.Project.get_ConditionedProperties() in e:\projects\msbuild_3\src\Build\Definition\Project.cs:line 709
   at Microsoft.VisualStudio.ProjectSystem.CoreProjectConfigurationsDimensionsProvider.<GetProjectConfigurationDimensionsAsync>d__7.MoveNext()
--- 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 Microsoft.VisualStudio.ProjectSystem.DeclaredDimensionsProjectConfigurationsService.<CalculateKnownProjectConfigurationsAsync>d__9.MoveNext()
--- 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 Microsoft.VisualStudio.ProjectSystem.UnconfiguredProjectCache`1.<GetValueAsync>d__6.MoveNext()
--- 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 Microsoft.VisualStudio.ProjectSystem.ProjectConfigurationsServiceBase.<GetKnownProjectConfigurationsAsync>d__55.MoveNext()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<UpdateProjectContextAsync>d__24.MoveNext()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.VisualStudio.ProjectSystem.DefaultingProjectConfigurationsServiceBase.<GetProjectConfigurationAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
--- 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.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<UpdateProjectContextAndSubscriptionsAsync>d__23.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Implementation.VSUnconfiguredProjectIntegrationService.<GetActiveProjectConfigurationAsync>d__68.MoveNext()
--- 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.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.VisualStudio.ProjectSystem.VS.Implementation.VSUnconfiguredProjectIntegrationService.<RefreshActiveProjectConfigurationAsync>d__62.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<InitializeCoreAsync>d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
--- 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 Microsoft.VisualStudio.ProjectSystem.VS.NuGet.NuGetRestorer.<RefreshActiveConfigurationAsync>d__18.MoveNext()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.Subscriptions.DependencySubscriptionsHost.<InitializeCoreAsync>d__45.MoveNext()
--- 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 Microsoft.VisualStudio.ProjectSystem.OnceInitializedOnceDisposedAsync.<<-ctor>b__4_0>d.MoveNext()
--- 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 Microsoft.VisualStudio.Threading.AsyncLazy`1.<>c__DisplayClass13_1.<<GetValueAsync>b__0>d.MoveNext()
--- 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 Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<EnsureInitialized>d__19.MoveNext()

Here it is minus the noise:

System.InvalidOperationException: The specified API "ConditionedProperties" is not available because ProjectLoadSettings.DoNotEvaluateElementsWithFalseCondition was set when loading this project.
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInvalidOperation(String resourceName, Object[] args) in e:\projects\msbuild_3\src\Shared\ErrorUtilities.cs:line 304
   at Microsoft.Build.Evaluation.Project.get_ConditionedProperties() in e:\projects\msbuild_3\src\Build\Definition\Project.cs:line 709
   at Microsoft.VisualStudio.ProjectSystem.CoreProjectConfigurationsDimensionsProvider.<GetProjectConfigurationDimensionsAsync>d__7.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.DeclaredDimensionsProjectConfigurationsService.<CalculateKnownProjectConfigurationsAsync>d__9.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.UnconfiguredProjectCache`1.<GetValueAsync>d__6.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.ProjectConfigurationsServiceBase.<GetKnownProjectConfigurationsAsync>d__55.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<UpdateProjectContextAsync>d__24.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.DefaultingProjectConfigurationsServiceBase.<GetProjectConfigurationAsync>d__3.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<UpdateProjectContextAndSubscriptionsAsync>d__23.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Implementation.VSUnconfiguredProjectIntegrationService.<GetActiveProjectConfigurationAsync>d__68.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Implementation.VSUnconfiguredProjectIntegrationService.<RefreshActiveProjectConfigurationAsync>d__62.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<InitializeCoreAsync>d__20.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.NuGet.NuGetRestorer.<RefreshActiveConfigurationAsync>d__18.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.Subscriptions.DependencySubscriptionsHost.<InitializeCoreAsync>d__45.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.OnceInitializedOnceDisposedAsync.<<-ctor>b__4_0>d.MoveNext()
   at Microsoft.VisualStudio.Threading.AsyncLazy`1.<>c__DisplayClass13_1.<<GetValueAsync>b__0>d.MoveNext()
   at Microsoft.VisualStudio.ProjectSystem.VS.Tree.Dependencies.CrossTarget.CrossTargetSubscriptionHostBase.<EnsureInitialized>d__19.MoveNext()

Much more understandable/readable.

Is there something we can do to collapse/reduce the noise here?

[NickCraver]

We've got the same issue, not ideal (since this should be done on generation ideally), but we handle text-based versions after the fact like this:

Current code (again, string-based, but gives an idea): https://github.com/NickCraver/StackExchange.Exceptional/blob/master/src/StackExchange.Exceptional.Shared/ExceptionalUtils.StackTrace.cs

I'd love to see the framework do this much better. It's one of the big negatives to taking a codebase async.

[stephentoub]

https://github.com/dotnet/corefx/issues/1370

[roryprimrose]

Yep, totally agree. I use https://github.com/aelij/AsyncFriendlyStackTrace to clean up the stack traces when logging them.

[aelij]

Also: https://github.com/dotnet/coreclr/issues/2813

[karelz]

Closing as duplicate of dotnet/runtime#14434
(if you think it is not a dupe, please let me know and we can reopen)

[NickCraver]

Aren't these different issues? dotnet/runtime#14434 is talking about APIs, this is literally what the .ToSting() outputs, which may be a consumer of said API or may not use it at all.

[davkean]

Yep, these are two different issues.

[karelz]

It was not clear to me from the above description that you're asking for a change in Exception.StackTrace and/or in Exception.ToString().
That may have interesting AppCompat impact + difference between platforms. OTOH it would be very nice and sane default vs. the full 'unreadable' stack today.

Ultimately, we will IMO solve both issues together - they have the same solution. Either way we will need a new API (either providing the full call stack, or the sane call stack). The only question is, if the default StackTrace and ToString() return the sane call stack or the full call stack.
So I would still suggest to close it as dupe, but I won't fight over it ;) ...

[davkean]

We could fix Exception.StackTrace without providing an API or provide an API without fixing Exception.StackTrace. Hence why I see them as separate.

[noahfalk]

@davidfowl can correct me if I'm wrong but I don't think the mentions of an API in dotnet/runtime#14434 were meant to be a fundamental requirement. He wanted better stack trace text, and then he speculated that a new API is how he would get it. If there is a way he gets better text without a new API I bet he is still happy.

[benaadams]

Had a go at changing the StackTrace by changing the stack :)

Has some outstanding issues/questions though https://github.com/dotnet/coreclr/pull/14564

[danmosemsft]

@benaadams after your various CoreCLR changes including the nice https://github.com/dotnet/coreclr/pull/14655 what if anything remains to improve the original example stack in this issue?

[benaadams]

@danmosemsft with now merged
dotnet/coreclr#14652 "Hide post exception stack frames"
https://github.com/dotnet/coreclr/pull/15781 "Remove Edi boundary for async"

if/when https://github.com/dotnet/coreclr/pull/14655 "Resolve iterators and async methods in stacktrace" is merged (seems to have C# compiler approval? https://github.com/dotnet/coreclr/pull/14655#issuecomment-346192988) this will be resolved

[danmosemsft]

Great!

[karelz]

Thanks @benaadams for pushing it through!

[lahma]

Thank you @benaadams for having the patience and will to push forward great things that developers enjoy in their daily work!

[yaakov-h]

Can this please be considered for porting to .NET Framework CLR?

[karelz]

@yaakov-h it would help to have list of ALL required PRs which formed the improvement.
We will also have to check compatibility - the bar is much higher in .NET Framework.

Marking for consideration (disclaimer: I am currently not aware of ETA on when we will do next sweep of changes to port into .NET Framework)

[benaadams]

https://github.com/dotnet/coreclr/pull/14652 is already netfx-port-consider

Other two are https://github.com/dotnet/coreclr/pull/15781 and https://github.com/dotnet/coreclr/pull/14655

[karelz]

@benaadams I would prefer to have 1 issue with clear list of all contributing PRs and let's mark that one as netfx-port-consider. We do not want to end up in situation where half of the PRs make it and half won't. At least not by accident.
Is the list of the 3 merged PRs complete?

[benaadams]

Is the list of the 3 merged PRs complete?

Yes