Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Does EDI message provide benefit? "End of stack trace from previous location..." #9517

Closed
benaadams opened this issue Jan 8, 2018 · 15 comments
Assignees
Milestone

Comments

@benaadams
Copy link
Member

Using async (and ExceptionDispatchInfo in other areas) ends up outputting lots of lines that are:
--- End of stack trace from previous location where exception was thrown ---

I do get that its technically correct as it is where the exception was saved and restored, so a stitch point; just not sure what benefit it imparts to a user looking at the stack trace.

Example 1

System.Exception: Exception of type 'System.Exception' was thrown.
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at ExecutionContextTest.Program.<Main>d__0.MoveNext()

I'm not sure the benefit this has over: (resolving async aside dotnet/coreclr#14655)

Example 2

System.Exception: Exception of type 'System.Exception' was thrown.
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at ExecutionContextTest.Program.<Main>d__0.MoveNext()

For async the traces could be prefix if it is an async method (as its known while resolving the async method) for clues:

Example 3

System.Exception: Exception of type 'System.Exception' was thrown.
   at async ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at async ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at async ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at async ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
   at async ExecutionContextTest.Program.<Main>d__0.MoveNext()

And with Resolving async dotnet/coreclr#14655 that could become

Example 4

   at async ExecutionContextTest.Program.ExceptionTrace(int)+MoveNext()
   at async ExecutionContextTest.Program.ExceptionTrace(int)+MoveNext()
   at async ExecutionContextTest.Program.ExceptionTrace(int)+MoveNext()
   at async ExecutionContextTest.Program.ExceptionTrace(int)+MoveNext()
   at async ExecutionContextTest.Program.Main(string[])+MoveNext()

If it only output indicating when an async method was actually suspended and resumed it would be more of an interesting marker, but that's not what it currently does.

Does it currently provide benefits? Thoughts?

Aside: Xunit removes its own stacks but leaves in the EDI lines so you end up with

   at System.IO.Compression.CompressionStreamUnitTestBase.<Dispose_WithUnfinishedWriteAsync>d__5.MoveNext() in D:\j\workspace\windows-TGrou---f8ac6754\src\Common\tests\System\IO\Compression\CompressionStreamUnitTestBase.cs:line 208
--- End of stack trace from previous location where exception was thrown ---
--- End of stack trace from previous location where exception was thrown ---
--- End of stack trace from previous location where exception was thrown ---

/cc @stephentoub @tmat @noahfalk @aelij @jkotas @danmosemsft

@NickCraver
Copy link
Member

I've debugged a ton of async code and never found this to be useful...we remove it in presentation already. I really am very curious to hear actual use cases for it, but support removing it for the default experience.

@davkean
Copy link
Member

davkean commented Jan 8, 2018

I wasn't around for v1, but there was a benefit as a consumer of remoting to a separation between where an exception was thrown on a server, and then thrown on the client.

These days, however, where all I'm doing is looking at is async stack traces, these markers are meaningless and noise.

@benaadams
Copy link
Member Author

there was a benefit as a consumer of remoting to a separation between where an exception was thrown on a server, and then thrown on the client

Should outputting boundaries then be a settable flag that defaults to false?

e.g. I'm not sure; for example if WCF, forwards server errors into client stack; but if it did the flag could be set on the re-hydration point rather than just use of EDI as its become much more widespread.

@terrajobst
Copy link
Member

Agreed. AFAIK when we designed EDI we just plugged into the existing remoting infrastructure; the markers came with it and weren’t explicitly designed (but I could be wrong). I agree with Nick and David — they seem mostly noise to me.

@jkotas
Copy link
Member

jkotas commented Jan 8, 2018

I agree that these boundaries are noise when they are generated in C# language support library like the AsyncMethodBuilder. It makes sense to remove them for these cases.

I think the boundaries are still valuable when up stack libraries store and rethrow exceptions manually from different places.

@terrajobst
Copy link
Member

Why? Navigating the trace will reveal what’s going on.

@jkotas
Copy link
Member

jkotas commented Jan 8, 2018

I except that many people will get quite confused when they are going to see:

MethodA
MethodB

in the stacktrace and no obvious way how MethodB could have ever called MethodA in the source.

@terrajobst
Copy link
Member

But any of these methods will have an EDI.Throw(), no? IOW these will be from advanced users.

@benaadams
Copy link
Member Author

I agree that these boundaries are noise when they are generated in C# language support library like the AsyncMethodBuilder. It makes sense to remove them for these cases.

I think the boundaries are still valuable when up stack libraries store and rethrow exceptions manually from different places.

Looking at the code, its not straight forward to either/or as it is based on the values in rgiLastFrameFromForeignExceptionStackTrace which is queried at .ToString time and not set anywhere in the C#.

e.g. its fairly easy to completely switch it off; but doesn't seem as easy to partially switch it off (would need C++ changes)

@benaadams
Copy link
Member Author

Added PR for completely removing it (easier option) dotnet/coreclr#15781

Someone else would need to look at changing the unmanaged code if partial removal is preferred?

@benaadams
Copy link
Member Author

As an aside GetIsLastFrameFromForeignExceptionStackTrace is internal so you cannot add the boundary externally if you were enumerating the StackFrames manually

@jkotas
Copy link
Member

jkotas commented Jan 8, 2018

the existing remoting infrastructure; the markers came with it and weren’t explicitly designed (but I could be wrong)

The marker was explicitly designed and added as part of the EDI. It did not exist before EDI.

But any of these methods will have an EDI.Throw(), no?

Yes, there will be EDI.Throw() somewhere. If the stacktrace is longer, it will take you a while to figure out what is actually going on without the marker.

fairly easy to completely switch it off

If you just completely switch it off, I think it will leave questionable behaviors behind. For example, the stacktrace in this example is going to have method foo() twice in it. The lines are separated by the marker today so it kind of makes sense. Once they are not separated by the marker, it will just look like a bug.

static void foo()
{
    try {
        throw new Exception();
    }
    catch (Exception e) {
        ExceptionDispatchInfo.Throw(e);
    }
}

@davkean
Copy link
Member

davkean commented Jan 8, 2018

One option is to consider reducing the noise:

System.Exception: Exception of type 'System.Exception' was thrown.
at [Rethrown]ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
at [Rethrown]ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
at [Rethrown]ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
at [Rethrown]ExecutionContextTest.Program.<ExceptionTrace>d__2.MoveNext()
at ExecutionContextTest.Program.<Main>d__0.MoveNext()

Though, maybe we can make changes to ExceptionDispatchInfo itself that we can opt only particular scenarios into skipping the marker (such as async infrastructure).

@benaadams
Copy link
Member Author

Hmm... ok. The StackTrace prior to dotnet/coreclr#14652 would have been

System.Exception: Exception of type 'System.Exception' was thrown.
   at Program.<AsyncMethod>d__1.MoveNext() in C:\StackTraceAsync\Program.cs:line 27
--- 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.<DelayedAsync>d__2.MoveNext() in C:\StackTraceAsync\Program.cs:line 34
--- 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.<IntermediateAsync>d__3.MoveNext() in C:\StackTraceAsync\Program.cs:line 39
--- 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.<AsyncMethod>d__1.MoveNext() in C:\StackTraceAsync\Program.cs:line 27
--- End of stack trace from previous location where exception was thrown ---

So could conditionally if the last item is either as StateMachine as per dotnet/coreclr#14655; or in the System.Private.CoreLib assembly? (Is there a preferred way to do that?)

@benaadams
Copy link
Member Author

Switched off the boundary just for async and mscorlib dotnet/coreclr#15781

@msftgits msftgits transferred this issue from dotnet/coreclr Jan 31, 2020
@msftgits msftgits added this to the Future milestone Jan 31, 2020
@ghost ghost locked as resolved and limited conversation to collaborators Dec 18, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

7 participants