Remove Edi boundary for async by benaadams · Pull Request #15781 · dotnet/coreclr

benaadams · 2018-01-08T06:09:56Z

Switch off EDI boundary for async

Removes:

--- End of stack trace from previous location where exception was thrown ---

Resolves https://github.com/dotnet/coreclr/issues/15779

benaadams · 2018-01-08T10:23:00Z

@jkotas PTAL

benaadams · 2018-01-08T10:38:25Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs

            }
        }

-        public virtual MethodBase GetMethodBase(int i)


No point in virtuals on non-inherited internal class

benaadams · 2018-01-08T10:55:16Z

It use the same method to detect async as the open PR #14655 which seems to be approved approach by C# team #14655 (comment)?

MattGal · 2018-01-08T18:15:38Z

@dotnet-bot test cross please

benaadams · 2018-01-08T18:23:09Z

OSX Failure 02:35:06 fatal error: error in backend: IO failure on output stream.

benaadams · 2018-01-08T18:23:32Z

@dotnet-bot test OSX10.12 x64 Checked Innerloop Build and Test

noahfalk · 2018-01-09T00:03:51Z

src/mscorlib/src/System/Diagnostics/Stackframe.cs


 namespace System.Diagnostics
 {
-    // There is no good reason for the methods of this class to be virtual.


I think we should split the cleanup off to its own PR to make sure it doesn't get squashed together with the other changes during checkin. It helps to avoid having a few important changes hidden amongst numerous refactorings.

Simplified just to this change

noahfalk · 2018-01-09T00:10:40Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs

-                        sb.Append(Environment.NewLine);
-                        sb.Append(SR.Exception_EndStackTraceFromPreviousThrow);
+                        if (sf.GetIsLastFrameFromForeignExceptionStackTrace() && 
+                            !(declaringType?.Assembly.FullName.StartsWith(CoreLib.Name, StringComparison.Ordinal) ?? false) && // Skip EDI boundary for mscorlib


Doing a direct comparison on the assembly object seems likely to be faster and more robust. Something like
static Assembly CorelibAssembly = typeof(object).Assembly?

noahfalk · 2018-01-09T00:16:52Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs

+                    if (declaringType != null && declaringType.IsDefined(typeof(CompilerGeneratedAttribute)) &&
+                        (typeof(IAsyncStateMachine).IsAssignableFrom(declaringType)))
+                    {
+                        isAsync = true;


Could you add some perf numbers? I had a vague memory you already benchmarked and it was barely noticeable but just want to confirm. Some customers use stack traces on their hot path and get very sad when we slow them down (microsoft/dotnet#529)

In this case isAsync only needs to be calculated once we determine IsLastFrameFromForeignException is true, but I know if your other use case you need to check it for every frame anyways.

Hmm... I tested against throwing the exception and it was insignificant - but I didn't look at just creating a StackTrace - however this is in the .ToString path so wouldn't impact the linked example.

Never the less, will check

stephentoub · 2018-01-11T17:31:24Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs

    // There is no good reason for the methods of this class to be virtual.  
    public class StackTrace
    {
+        private static Assembly s_corelibAssembly = typeof(object).Assembly;


stephentoub · 2018-01-11T17:34:00Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs

+                        typeof(IAsyncStateMachine).IsAssignableFrom(declaringType))
+                    {
+                        isAsync = true;
+                    }


bool isAsync = declaringType != null && ...;

?

stephentoub · 2018-01-11T17:39:06Z

src/mscorlib/src/System/Diagnostics/Stacktrace.cs


-                    if (sf.GetIsLastFrameFromForeignExceptionStackTrace())
+                    if (sf.GetIsLastFrameFromForeignExceptionStackTrace() &&
+                        declaringType?.Assembly != s_corelibAssembly && // Skip EDI boundary for mscorlib


Why is this disabled for all of corelib? There aren't many places in corelib where EDI.Capture is used, but there are a few, and I'm wondering if this may result in a worse experience for some of them.

For example, exceptions that occur in Lazy<T>.Value are propagated but also cached via EDI for subsequent access. Thus with a program like:

using System; class Program { static void Main() { var l = new Lazy<int>(() => { throw new Exception("hello"); }); try { int i = l.Value; } catch (Exception e) { Console.WriteLine(e); } Console.WriteLine(); try { int i = l.Value; } catch (Exception e) { Console.WriteLine(e); } } }

currently this will output:

System.Exception: hello at Program.<>c.<Main>b__0_0() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 8 at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode) in E:\A\_work\1522\s\src\mscorlib\shared\System\Lazy.cs:line 330 at System.Lazy`1.ExecutionAndPublication(LazyHelper executionAndPublication, Boolean useDefaultConstructor) in E:\A\_work\1522\s\src\mscorlib\shared\System\Lazy.cs:line 348 at System.Lazy`1.CreateValue() in E:\A\_work\1522\s\src\mscorlib\shared\System\Lazy.cs:line 436 at Program.Main() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 9 System.Exception: hello at Program.<>c.<Main>b__0_0() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 8 at System.Lazy`1.ViaFactory(LazyThreadSafetyMode mode) in E:\A\_work\1522\s\src\mscorlib\shared\System\Lazy.cs:line 324 --- End of stack trace from previous location where exception was thrown --- at System.Lazy`1.CreateValue() in E:\A\_work\1522\s\src\mscorlib\shared\System\Lazy.cs:line 432 at Program.Main() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 11

but with this change that --- End of stack trace... won't show, which might suggest to the caller that the exception is actually occurring as part of invoking the delegate on this call, rather than it coming from being cached.

Or consider:

using System; using System.Threading.Tasks; class Program { static void Main() { var t = Task.Run(() => { throw new Exception("hello"); }); t.GetAwaiter().GetResult(); } }

Today this will output:

Unhandled Exception: System.Exception: hello at Program.<>c.<Main>b__0_0() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 8 at System.Threading.Tasks.Task`1.InnerInvoke() in E:\A\_work\1522\s\src\mscorlib\src\System\Threading\Tasks\future.cs:line 610 at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state) in E:\A\_work\1522\s\src\mscorlib\shared\System\Threading\ExecutionContext.cs:line 151 at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot) in E:\A\_work\1522\s\src\mscorlib\src\System\Threading\Tasks\Task.cs:line 2440 --- End of stack trace from previous location where exception was thrown --- at Program.Main() in c:\Users\stoub\Desktop\CoreClrTest\test.cs:line 10

That helps to highlight that Wait isn't actually calling ExecuteWithThreadLocal, but if you remove the --- End of stack trace... part, how does the developer know that?

😞

Will have to narrow further

Perhaps attribute on method is way forward?

attribute seems reasonable, and matches the pattern we used for StackTraceHidden handling

Just switched it off for async; can address other areas if/when they arise

benaadams · 2018-01-14T04:51:39Z

Changed to just off for async; can address other areas if/when they arise

benaadams · 2018-01-14T08:56:21Z

Tizen

FAILED   - JIT/Regression/VS-ia64-JIT/V1.2-M01/b12263/b12263/b12263.sh
 BEGIN EXECUTION
 /home/coreclr/bin/tests/Windows_NT.x64.Checked/Tests/coreoverlay/corerun b12263.exe
 qemu: Unsupported syscall: 389

qemu: uncaught target signal 11 (Segmentation fault) - core dumped
 ./b12263.sh: line 243:  2459 Segmentation fault      (core dumped) $_DebuggerFullPath "$CORE_ROOT/corerun" $ExePath $CLRTestExecutionArguments
 Expected: 100
 Actual: 139
 END EXECUTION - FAILED

benaadams · 2018-01-14T12:21:24Z

Ubuntu arm Cross Debug Innerloop Build

FAILED   - JIT/Regression/CLR-x86-JIT/V1-M09.5-PDC/b32560/b32560/b32560.sh
  BEGIN EXECUTION
  /home/coreclr/bin/tests/Windows_NT.x64.Debug/Tests/coreoverlay/corerun b32560.exe
  ./b32560.sh: line 243:  1837 Segmentation fault      (core dumped) 
    $_DebuggerFullPath "$CORE_ROOT/corerun" $ExePath $CLRTestExecutionArguments
  Expected: 100
  Actual: 139
  END EXECUTION - FAILED

benaadams · 2018-01-14T12:22:17Z

@dotnet-bot test Tizen armel Cross Checked Innerloop Build and Test
@dotnet-bot test Ubuntu arm Cross Debug Innerloop Build

noahfalk · 2018-01-17T01:50:41Z

I'm happy if Stephen is. Thanks!

stephentoub · 2018-01-17T15:52:31Z

@benaadams, can you share a before/after with this change?

benaadams · 2018-01-17T17:38:39Z

Pre

System.Exception: Exception of type 'System.Exception' was thrown.
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<MethodAsync>d__1.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 22
--- End of stack trace from previous location where exception was thrown ---
   at asyncexceptions.Program.<Main>d__0.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 12

Post

System.Exception: Exception of type 'System.Exception' was thrown.
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<RecursiveAsync>d__2.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 32
   at asyncexceptions.Program.<MethodAsync>d__1.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 22
   at asyncexceptions.Program.<Main>d__0.MoveNext() in C:\Work\Things\asyncexceptions\Program.cs:line 12

benaadams · 2018-01-17T17:39:57Z

Test

class Program
{
    static async Task Main(string[] args)
    {
        try
        {
            await MethodAsync();
        }
        catch (Exception e)
        {
            Console.WriteLine(e);
        }
    }

    static async Task MethodAsync()
    {
        await RecursiveAsync(5);
    }

    static async Task RecursiveAsync(int count)
    {
        if (count == 0)
        {
            throw new Exception();
        }

        await RecursiveAsync(count - 1);
    }
}

stephentoub · 2018-01-17T17:51:26Z

Ok, thanks, looks ok to me.

benaadams · 2018-01-28T11:44:40Z

netfx-port-consider?

benaadams force-pushed the edi-boundary branch from c8b30c3 to 02a5eed Compare January 8, 2018 10:21

benaadams commented Jan 8, 2018

View reviewed changes

noahfalk reviewed Jan 9, 2018

View reviewed changes

benaadams force-pushed the edi-boundary branch from 02a5eed to a1e1b8a Compare January 9, 2018 00:17

stephentoub reviewed Jan 11, 2018

View reviewed changes

benaadams changed the title ~~Remove Edi boundary~~ [WIP] Remove Edi boundary Jan 11, 2018

Skip EDI boundary for async

ded78a3

benaadams force-pushed the edi-boundary branch from a1e1b8a to ded78a3 Compare January 14, 2018 04:49

benaadams changed the title ~~[WIP] Remove Edi boundary~~ Remove Edi boundary for async Jan 14, 2018

stephentoub approved these changes Jan 17, 2018

View reviewed changes

stephentoub merged commit 33ce0e2 into dotnet:master Jan 17, 2018

benaadams deleted the edi-boundary branch January 17, 2018 22:28

benaadams mentioned this pull request Jan 24, 2018

Resolve iterators and async methods in stacktrace #14655

Merged

ascott18 mentioned this pull request Apr 16, 2021

Captured stack traces do not benefit from improvements to async stack traces added in .NET Core 2.1 microsoft/ApplicationInsights-dotnet#2234

Closed

Conversation

benaadams commented Jan 8, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

benaadams commented Jan 8, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

benaadams commented Jan 8, 2018

Uh oh!

MattGal commented Jan 8, 2018

Uh oh!

benaadams commented Jan 8, 2018

Uh oh!

benaadams commented Jan 8, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

stephentoub Jan 11, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

benaadams commented Jan 14, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

benaadams commented Jan 14, 2018

Uh oh!

benaadams commented Jan 14, 2018

Uh oh!

benaadams commented Jan 14, 2018

Uh oh!

noahfalk commented Jan 17, 2018

Uh oh!

stephentoub commented Jan 17, 2018

Uh oh!

benaadams commented Jan 17, 2018

Uh oh!

benaadams commented Jan 17, 2018

Uh oh!

stephentoub commented Jan 17, 2018

Uh oh!

benaadams commented Jan 28, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

benaadams commented Jan 8, 2018 •

edited

Loading

stephentoub Jan 11, 2018 •

edited

Loading

benaadams commented Jan 14, 2018 •

edited

Loading