fix: net8 unknown stack trace methods for JIT methods (#3942)

* fix: net8 unknown stack trace methods for JIT methods * chore: changelog * chore: fix changelog * remove problematic assertion * fix: dispose before processing is done
getsentry · Feb 7, 2025 · d197cb2 · d197cb2
1 parent bea672a
commit d197cb2
Show file tree

Hide file tree

Showing 3 changed files with 59 additions and 18 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -5,6 +5,7 @@
 ### Fixes
 
 - OTel activities that are marked as not recorded are no longer sent to Sentry ([#3890](https://github.com/getsentry/sentry-dotnet/pull/3890))
+- Unknown stack frames in profiles on .NET 8+ ([#3942](https://github.com/getsentry/sentry-dotnet/pull/3942))
 - Deduplicate profiling stack frames ([#3941](https://github.com/getsentry/sentry-dotnet/pull/3941))
 
 ## 5.1.0

diff --git a/src/Sentry.Profiling/SampleProfilerSession.cs b/src/Sentry.Profiling/SampleProfilerSession.cs
@@ -12,31 +12,32 @@ namespace Sentry.Profiling;
 internal class SampleProfilerSession : IDisposable
 {
     private readonly EventPipeSession _session;
-    private readonly TraceLogEventSource _eventSource;
     private readonly SampleProfilerTraceEventParser _sampleEventParser;
     private readonly IDiagnosticLogger? _logger;
     private readonly SentryStopwatch _stopwatch;
     private bool _stopped = false;
+    private Task _processing;
 
-    private SampleProfilerSession(SentryStopwatch stopwatch, EventPipeSession session, TraceLogEventSource eventSource, IDiagnosticLogger? logger)
+    private SampleProfilerSession(SentryStopwatch stopwatch, EventPipeSession session, TraceLogEventSource eventSource, Task processing, IDiagnosticLogger? logger)
     {
         _session = session;
         _logger = logger;
-        _eventSource = eventSource;
-        _sampleEventParser = new SampleProfilerTraceEventParser(_eventSource);
+        EventSource = eventSource;
+        _sampleEventParser = new SampleProfilerTraceEventParser(EventSource);
         _stopwatch = stopwatch;
+        _processing = processing;
     }
 
     // Exposed only for benchmarks.
     internal static EventPipeProvider[] Providers = new[]
     {
-        // Note: all events we need issued by "DotNETRuntime" provider are at "EventLevel.Informational"
-        // see https://learn.microsoft.com/en-us/dotnet/fundamentals/diagnostics/runtime-events
-        // TODO replace Keywords.Default with a subset. Currently it is:
-        //   Default = GC | Type | GCHeapSurvivalAndMovement | Binder | Loader | Jit | NGen | SupressNGen
-        //                | StopEnumeration | Security | AppDomainResourceManagement | Exception | Threading | Contention | Stack | JittedMethodILToNativeMap
-        //                | ThreadTransfer | GCHeapAndTypeNames | Codesymbols | Compilation,
-        new EventPipeProvider(ClrTraceEventParser.ProviderName, EventLevel.Informational, (long) ClrTraceEventParser.Keywords.Default),
+        new EventPipeProvider(ClrTraceEventParser.ProviderName, EventLevel.Verbose, (long) (
+            ClrTraceEventParser.Keywords.Jit
+            | ClrTraceEventParser.Keywords.NGen
+            | ClrTraceEventParser.Keywords.Loader
+            | ClrTraceEventParser.Keywords.Binder
+            | ClrTraceEventParser.Keywords.JittedMethodILToNativeMap
+            )),
         new EventPipeProvider(SampleProfilerTraceEventParser.ProviderName, EventLevel.Informational),
         // new EventPipeProvider(TplEtwProviderTraceEventParser.ProviderName, EventLevel.Informational, (long) TplEtwProviderTraceEventParser.Keywords.Default)
     };
@@ -46,11 +47,14 @@ private SampleProfilerSession(SentryStopwatch stopwatch, EventPipeSession sessio
     // need a large buffer if we're connecting righ away. Leaving it too large increases app memory usage.
     internal static int CircularBufferMB = 16;
 
+    // Exposed for tests
+    internal TraceLogEventSource EventSource { get; }
+
     public SampleProfilerTraceEventParser SampleEventParser => _sampleEventParser;
 
     public TimeSpan Elapsed => _stopwatch.Elapsed;
 
-    public TraceLog TraceLog => _eventSource.TraceLog;
+    public TraceLog TraceLog => EventSource.TraceLog;
 
     // default is false, set 1 for true.
     private static int _throwOnNextStartupForTests = 0;
@@ -86,7 +90,7 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null)
             var eventSource = TraceLog.CreateFromEventPipeSession(session, TraceLog.EventPipeRundownConfiguration.Enable(client));
 
             // Process() blocks until the session is stopped so we need to run it on a separate thread.
-            Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning)
+            var processing = Task.Factory.StartNew(eventSource.Process, TaskCreationOptions.LongRunning)
                 .ContinueWith(_ =>
                 {
                     if (_.Exception?.InnerException is { } e)
@@ -95,7 +99,7 @@ public static SampleProfilerSession StartNew(IDiagnosticLogger? logger = null)
                     }
                 }, TaskContinuationOptions.OnlyOnFaulted);
 
-            return new SampleProfilerSession(stopWatch, session, eventSource, logger);
+            return new SampleProfilerSession(stopWatch, session, eventSource, processing, logger);
         }
         catch (Exception ex)
         {
@@ -108,15 +112,15 @@ public async Task WaitForFirstEventAsync(CancellationToken cancellationToken = d
     {
         var tcs = new TaskCompletionSource();
         var cb = (TraceEvent _) => { tcs.TrySetResult(); };
-        _eventSource.AllEvents += cb;
+        EventSource.AllEvents += cb;
         try
         {
             // Wait for the first event to be processed.
             await tcs.Task.WaitAsync(cancellationToken).ConfigureAwait(false);
         }
         finally
         {
-            _eventSource.AllEvents -= cb;
+            EventSource.AllEvents -= cb;
         }
     }
 
@@ -128,8 +132,9 @@ public void Stop()
             {
                 _stopped = true;
                 _session.Stop();
+                _processing.Wait();
                 _session.Dispose();
-                _eventSource.Dispose();
+                EventSource.Dispose();
             }
             catch (Exception ex)
             {

diff --git a/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs b/test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs
@@ -1,4 +1,5 @@
-using System.IO.Abstractions.TestingHelpers;
+using Microsoft.Diagnostics.Tracing;
+using Microsoft.Diagnostics.Tracing.Parsers.Clr;
 using Sentry.Internal.Http;
 
 namespace Sentry.Profiling.Tests;
@@ -180,6 +181,40 @@ public async Task Profiler_AfterTimeout_Stops()
         }
     }
 
+    [SkippableFact]
+    public async Task EventPipeSession_ReceivesExpectedCLREvents()
+    {
+        SampleProfilerSession? session = null;
+        SkipIfFailsInCI(() => session = SampleProfilerSession.StartNew(_testOutputLogger));
+        using (session)
+        {
+            var eventsReceived = new HashSet<string>();
+            session!.EventSource.Clr.All += (TraceEvent ev) => eventsReceived.Add(ev.EventName);
+
+            var loadedMethods = new HashSet<string>();
+            session!.EventSource.Clr.MethodLoadVerbose += (MethodLoadUnloadVerboseTraceData ev) => loadedMethods.Add(ev.MethodName);
+
+
+            await session.WaitForFirstEventAsync(CancellationToken.None);
+            var limitMs = 50;
+            var sut = new SamplingTransactionProfiler(_testSentryOptions, session, limitMs, CancellationToken.None);
+            RunForMs(limitMs * 5);
+            MethodToBeLoaded(100);
+            RunForMs(limitMs * 5);
+            sut.Finish();
+
+            Assert.Contains("Method/LoadVerbose", eventsReceived);
+            Assert.Contains("Method/ILToNativeMap", eventsReceived);
+
+            Assert.Contains("MethodToBeLoaded", loadedMethods);
+        }
+    }
+
+    private static long MethodToBeLoaded(int n)
+    {
+        return -n;
+    }
+
     [SkippableTheory]
     [InlineData(true)]
     [InlineData(false)]