getsentry / sentry-dotnet

Sentry SDK for .NET
https://docs.sentry.io/platforms/dotnet
MIT License
566 stars 203 forks source link

Incorrect stack traces for UWP in .NET Native #3316

Open jamescrosswell opened 3 weeks ago

jamescrosswell commented 3 weeks ago

Originally posted by @tipa in https://github.com/getsentry/sentry-dotnet/issues/3240#issuecomment-2063345520

Today I received another funny stack trace (it is the raw stack trace) - https://timopartl.sentry.io/issues/5216095235:


System.ArgumentException: Value does not fall within the expected range.
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in GetResult
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in GetResult
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in GetResult
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in GetResult
  Module "System.Runtime.ExceptionServices.ExceptionDispatchInfo", in Throw
  Module "System.Runtime.CompilerServices.TaskAwaiter", in GetResult

It's from a manually captured exception, but the crash report I was referring to in my last comment was from a crash (and also it was the raw stack trace), here's the link: https://timopartl.sentry.io/issues/5178256155

Here's another example project to reproduce the issue (run in Release mode). It logs the stack trace manually as breadcrumb, and this is what I see in the dashboard: Sentry_UWP.zip

stack trace: image

stack trace from breadcrumb:

at Sentry_UWP.SubPage.Toggle_Toggled(Object, RoutedEventArgs) + 0x8
   at Windows.Foundation.AsyncOperationProgressHandler`2.Invoke(IAsyncOperationWithProgress`2, TProgress) + 0x2e
   at __Interop.Intrinsics.HasThisCall__13[TArg0](Object, IntPtr, Object, TArg0) + 0x36
   at Sentry_UWP!<BaseAddress>+0x4d29d0
   at System.Runtime.InteropServices.McgMarshal.ThrowOnExternalCallFailed(Int32, RuntimeTypeHandle) + 0x21
   at __Interop.ComCallHelpers.Call(__ComObject, RuntimeTypeHandle, Int32, SByte) + 0xc0
   at __Interop.ForwardComStubs.Stub_29[TThis](__ComObject, Boolean, Int32) + 0x37
   at Sentry_UWP.SubPage.OnNavigatedTo(NavigationEventArgs) + 0x56
   at Windows.UI.Xaml.Controls.Page.global::Windows.UI.Xaml.Controls.IPageOverrides.OnNavigatedTo(NavigationEventArgs) + 0xa
   at Sentry_UWP!<BaseAddress>+0x4e498e

This is a very simple example so there's not a lot information missing, but I would at least expect to see the line Sentry_UWP.SubPage.OnNavigatedTo(NavigationEventArgs). If you want me to, I can try to produce a crash that has a longer stack trace with more information missing. But I think even this small exmaple shows that there's something wrong.

jamescrosswell commented 3 weeks ago

I can't really debug this properly. It doesn't appear to be possible to substitute a project reference to Sentry.csproj for the NuGet package reference in the demo project provided.

However I think I see what's causing this: https://github.com/getsentry/sentry-dotnet/blob/233e95b5a2104819c735a29490c1aaf6b336f1fd/src/Sentry/Internal/DebugStackTrace.cs#L380-L388

In a UWP app, which is targeting .NET Framework, we do have AOT effectively for release builds (if UseDotNetNativeToolchain is true) and so TryCreateManagedFrame is going to fail and return null... and we won't run TryCreateNativeAOTFrame because we only run that in .NET 8 or later.

This can be confirmed by capturing the debug info to a file:

  Debug: Creating SentryStackTrace. isCurrentStackTrace: False.
  Debug: Skipping debug image for module 'TimoUwp.exe' because assembly wasn't found: ''
  Debug: Could not resolve stack frame 'Windows.Foundation.AsyncOperationProgressHandler`2.Invoke(IAsyncOperationWithProgress`2, TProgress) + 0x2e at offset 46 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame '__Interop.Intrinsics.HasThisCall__13[TArg0](Object, IntPtr, Object, TArg0) + 0x36 at offset 54 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame 'TimoUwp!<BaseAddress>+0x4d2b50 at offset 112 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame 'System.Runtime.InteropServices.McgMarshal.ThrowOnExternalCallFailed(Int32, RuntimeTypeHandle) + 0x21 at offset 33 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame '__Interop.ComCallHelpers.Call(__ComObject, RuntimeTypeHandle, Int32, SByte) + 0xc0 at offset 192 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame '__Interop.ForwardComStubs.Stub_29[TThis](__ComObject, Boolean, Int32) + 0x37 at offset 55 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame 'TimoUwp.SubPage.OnNavigatedTo(NavigationEventArgs) + 0x56 at offset 86 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame 'Windows.UI.Xaml.Controls.Page.global::Windows.UI.Xaml.Controls.IPageOverrides.OnNavigatedTo(NavigationEventArgs) + 0xa at offset 10 in file:line:column <filename unknown>:0:0 '
  Debug: Could not resolve stack frame 'TimoUwp!<BaseAddress>+0x4e4b0e at offset 110 in file:line:column <filename unknown>:0:0 '
  Debug: Created DebugStackTrace with 1 frames.

You can see a bunch of in app frames get dropped there because we can't symbolicate these.

Very tricky to resolve... especially since it's so difficult to debug (logging is pretty much the only weapon we have here).

tipa commented 3 weeks ago

The reason why I added this issue to the other issue that was about trimming is because I think this issue is also related to trimming. When you use this line in Default.rd.xml (it's present by default when you create a new UWP app in Visual Studio), trimming is disabled: <Assembly Name="*Application*" Dynamic="Required All" />

When you're running the app then, the second line shows up in Sentry:

System.DivideByZeroException: Attempted to divide by zero.
  Module "Sentry_UWP.SubPage", in Toggle_Toggled
  Module "Sentry_UWP.SubPage", in OnNavigatedTo

Maybe there's more use of reflection somwehere that causes this problem.

Would this be the expected strack trace to show up anyways? Are frames like these expected to be dropped? They're also not showing in the "raw stack trace"

at Windows.UI.Xaml.Controls.Page.global::Windows.UI.Xaml.Controls.IPageOverrides.OnNavigatedTo(NavigationEventArgs) + 0xa
bitsandfoxes commented 3 weeks ago

We might get some benefits out of having this merged? https://github.com/getsentry/sentry-dotnet/issues/3282

bitsandfoxes commented 3 weeks ago

Additionally, maybe we should put a guard around enabling AOT on platforms where we know we don't properly support it. Just so users don't get surprised by unexpected outcomes.

bitsandfoxes commented 4 days ago

we should put a guard around enabling AOT

Scratching that. See https://github.com/getsentry/sentry-dotnet/pull/3343#issuecomment-2095585674 We're going to attempt to fix this step by step.