dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.08k stars 4.7k forks source link

Provide an API for traversing/reasoning about async call stacks #14434

Open davidfowl opened 9 years ago

davidfowl commented 9 years ago

Any tool that shows exceptions today also shows the callstack. With the introduction of the async keyword (yield was the same I guess), it's becoming increasingly harder to show reasonable call stacks because of the async state machine. It would be nice if there was an API somewhere that could be used to clean up the async state machine and pretty print a call stack with readable method names (tools like reflector do this).

Here's an example of a typical error page in an MVC 6 application:

image

Maxwe11 commented 9 years ago

:+1: :clap:

HaloFour commented 9 years ago

Check out this article from MSDN Magazine:

Async Programming: Async Causality Chain Tracking

It would have something like that built-in. However if it would have to capture the stack trace at the point of awaiting it would probably add a non-trivial amount of overhead, as the article mentions.

AlfredoMS commented 9 years ago

@HaloFour @davidfowl Async Causality tracking existsin mscorlib, see https://github.com/dotnet/coreclr/blob/master/src/mscorlib/src/System/Threading/Tasks/AsyncCausalityTracer.cs VS2013 uses it to populate some of the information in the Task window. Although I would agree it needs to be improved for xplat and there could be more tools taking advantage of its output.

HaloFour commented 9 years ago

Hrm, doesn't look like something you can use programmatically from within your own program? I used the tricks from that MSDN Magazine article to implement better exception messages in my web app as it was heavily async. On Apr 14, 2015 7:57 PM, "Alfredo Menendez Sancho" notifications@github.com wrote:

@HaloFour https://github.com/HaloFour @davidfowl https://github.com/davidfowl Async Causality tracking existsin mscorlib, see https://github.com/dotnet/coreclr/blob/master/src/mscorlib/src/System/Threading/Tasks/AsyncCausalityTracer.cs VS2013 uses it to populate some of the information in the Task window. Although I would agree it needs to be improved for xplat and there could be more tools taking advantage of its output.

— Reply to this email directly or view it on GitHub https://github.com/dotnet/corefx/issues/1370#issuecomment-93117933.

noahfalk commented 8 years ago

Adding @tmat @davidfowl Have you talked to the Roslyn guys about this at all? Ostensibly the abstraction you are trying to restore comes in two parts: 1) The framework provides the Task libraries. The fact that TaskAwaiter.GetResult() has calls to TaskAwaiter.HandleNonSuccessAndDebuggerNotification is a framework detail, so it would seem reasonable that any algorithm to clean up that part of the stack trace is owned by the framework. 2) The C# compiler provides the implementation of async and code-rewriting that creates the async state machines. Once we hit runtime the only information that could tie d__43.MoveNext() to a source location is contained inside custom debug information records in the PDB.

I'd assume the Roslyn Expression Evaluator, which runs within Visual Studio Debugger, has the algorithms you are looking for to sanitize these stack traces. Given that ASP.NET is already loading the compiler portion of Roslyn to runtime compilation, maybe we should also have you guys load the debugger portions of Roslyn for diagnostics such as this? I'm hoping @tmat can shed a little more light on how this is factored, or give us bad news that some key component is inside VS debugger itself rather than in the EE.

davidfowl commented 8 years ago

@tmat @gregg-miskelly Any ideas for this one? We could use heuristics to collapse the state machine frames (perhaps hide anything compiler generated?)

/cc @Tratcher

RichiCoder1 commented 8 years ago

Wanted say this would be a big win. Async stack traces are a serious pain to diagnose, and adding a mechanism to erase implementation details (TaskAwaiter, GetResult, ThrowForNonSuccess) and unify the generated state machines into something comprehensible would be amazing.

gregg-miskelly commented 8 years ago

The code that the VS debugger uses for walking the async stack isn't open, but I am happy to point Microsoft employees to it. The only role that the EE has in this is to give the 'MoveNext' method a better name.

gregg-miskelly commented 8 years ago

Though I should say that if the problem we are trying to solve is the stack trace for an exception object (and not some sort of new 'Environment.GetAsyncStack()') then I am not sure that any of the code that the debugger has will be all that useful. We likely need enhancements/enlightenments between the stack trace code and the task implementation code to make that story good.

noahfalk commented 8 years ago

The debugger has code that understands the C# async state machine and how it relates back to the source the user originally authored right? Presumably that is the key bit that is missing.

I agree the solution would look a bit different if we were modifying Exception.StackTrace vs. creating a new API, but I think both solutions would require reversing the C# compiler's state machine construction.

gregg-miskelly commented 8 years ago

If we are only concerned with fixing Exception.StackTrace, I actually think we don't need to decode the state machine because the method in the state machine class (.MoveNext) is on the stack already. What we need to do is clean up the task goo. It might also be nice to use method/class names that the user understands rather than the metadata names.

noahfalk commented 8 years ago

Folks in this issue might find @aelij's work interesting: https://github.com/dotnet/coreclr/issues/2813

aelij commented 8 years ago

I think both solutions would require reversing the C# compiler's state machine construction.

That's what I do in order to get the original method name. The downside is that it's compiler- and language-specific. Perhaps a long-term solution could be to have the compiler emit an attribute for the async state machine class that includes a string with the original method's signature. That way we could also print the full parameter list.

tmat commented 8 years ago

We emit Async/IteratorStateMachineAttribute on the kickoff method that points to the state machine type.

We will emit reverse mapping to Portable PDBs (I don't think we do that right now, but certainly will do so for dotnet cli release): https://github.com/dotnet/corefx/blob/master/src/System.Reflection.Metadata/specs/PortablePdb-Metadata.md#StateMachineMethodTable

We do stack cleanup and formatting for the REPL as well: http://source.roslyn.io/#Microsoft.CodeAnalysis.Scripting/Hosting/ObjectFormatter/CommonObjectFormatter.cs,d92226e92a7dee26,references

there is a few hacks that I want to get cleaned up at some point, but it generally works.

tmat commented 8 years ago

BTW, scripting has a dependency on the entire Roslyn compiler, which for most apps is an overkill. I wonder if we should split the parts that don't actually need the compiler into a separate assembly that doesn't depend on anything other than SRM and immutable collections.

davidfowl commented 8 years ago

Just catching back up on this thread and it seems like we might have enough pieces to throw something together.

gdoron commented 8 years ago

Is this issue related to the fact that many times though we have pdb files on the servers, we get stacktrace of line 0?

System.NullReferenceException: Object reference not set to an instance of an object. at Yooocan.Web.Controllers.VendorController.d16.MoveNext() in C:\git\Yooocan\src\Yooocan.Web\Controllers\VendorController.cs:line 0 --- 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.AspNetCore.Mvc.Internal.ObjectMethodExecutor.d401.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.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionFilterAsync>d__28.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAsync>d__18.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.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.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.AspNetCore.Authentication.AuthenticationMiddleware1.d18.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.d18.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.AspNetCore.Authentication.AuthenticationMiddleware1.<Invoke>d__18.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware1.d18.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.AspNetCore.Authentication.AuthenticationMiddleware`1.d18.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware`1.d18.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.AspNetCore.Diagnostics.StatusCodePagesMiddleware.d3.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.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.d__6.MoveNext()

karelz commented 7 years ago

@joperezr please work with @noahfalk and @tmat to work on high-level idea. Let's mark the issue appropriately then (ideally "up for grabs" with direction).

mattzink commented 7 years ago

Is this being actively worked? Many large .NET projects are adding hacks to reverse the async leaky abstraction in stack traces. This should be handled by the platform, as is done in Go and Python

noahfalk commented 7 years ago

I'm not aware of any active work, though its possible something is happening outside my view.

benaadams commented 6 years ago

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

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

benaadams commented 6 years ago

Tool that produces clean ResolvedStackTraces https://github.com/benaadams/Ben.Demystifier