Fix memory leak when OpenTelemetry spans get filtered

CHANGELOG.md

@@ -10,6 +10,7 @@
 
 - The Sentry Middleware on ASP.NET Core no longer throws an exception after having been initialized multiple times ([#3185](https://github.com/getsentry/sentry-dotnet/pull/3185))
 - Empty strings are used instead of underscores to replace invalid metric tag values ([#3176](https://github.com/getsentry/sentry-dotnet/pull/3176))
+- Filtered OpenTelemetry spans are garbage collected correctly ([#3198](https://github.com/getsentry/sentry-dotnet/pull/3198))
 
 ### Dependencies
 

src/Sentry.OpenTelemetry/Sentry.OpenTelemetry.csproj

@@ -22,6 +22,7 @@
   <ItemGroup>
     <InternalsVisibleTo Include="Sentry.OpenTelemetry.AspNetCore" PublicKey="$(SentryPublicKey)" />
     <InternalsVisibleTo Include="Sentry.OpenTelemetry.Tests" PublicKey="$(SentryPublicKey)" />
+    <InternalsVisibleTo Include="Sentry.Benchmarks" PublicKey="$(SentryPublicKey)" />
   </ItemGroup>
 
 </Project>

src/Sentry.OpenTelemetry/SentrySpanProcessor.cs

@@ -19,6 +19,9 @@ public class SentrySpanProcessor : BaseProcessor<Activity>
     private readonly SentryOptions? _options;
     private readonly Lazy<IDictionary<string, object>> _resourceAttributes;
 
+    private static readonly long PruningInterval = TimeSpan.FromSeconds(5).Ticks;
+    internal long _lastPruned = 0;
+
     /// <summary>
     /// Constructs a <see cref="SentrySpanProcessor"/>.
     /// </summary>
@@ -88,6 +91,9 @@ public override void OnStart(Activity data)
 
             var span = (SpanTracer)parentSpan.StartChild(context);
             span.StartTimestamp = data.StartTimeUtc;
+            // Used to filter out spans that are not recorded when finishing a transaction.
+            span.SetFused(data);
+            span.IsFiltered = () => span.GetFused<Activity>() is { IsAllDataRequested: false, Recorded: false };
             _map[data.SpanId] = span;
         }
         else
@@ -113,8 +119,12 @@ public override void OnStart(Activity data)
                 );
             transaction.StartTimestamp = data.StartTimeUtc;
             _hub.ConfigureScope(scope => scope.Transaction = transaction);
+            transaction.SetFused(data);
             _map[data.SpanId] = transaction;
         }
+
+        // Housekeeping
+        PruneFilteredSpans();
     }
 
     /// <inheritdoc />
@@ -196,6 +206,45 @@ public override void OnEnd(Activity data)
         span.Finish(status);
 
         _map.TryRemove(data.SpanId, out _);
+
+        // Housekeeping
+        PruneFilteredSpans();
+    }
+
+    /// <summary>
+    /// Clean up items that may have been filtered out.
+    /// See https://github.com/getsentry/sentry-dotnet/pull/3198
+    /// </summary>
+    internal void PruneFilteredSpans(bool force = false)
+    {
+        if (!force && !NeedsPruning())
+        {
+            return;
+        }
+
+        foreach (var mappedItem in _map)
+        {
+            var (spanId, span) = mappedItem;
+            var activity = span.GetFused<Activity>();
+            if (activity is { Recorded: false, IsAllDataRequested: false })
+            {
+                _map.TryRemove(spanId, out _);
+            }
+        }
+    }
+
+    private bool NeedsPruning()
+    {
+        var lastPruned = Interlocked.Read(ref _lastPruned);
+        if (lastPruned > DateTime.UtcNow.Ticks - PruningInterval)
+        {
+            return false;
+        }
+
+        var thisPruned = DateTime.UtcNow.Ticks;
+        Interlocked.CompareExchange(ref _lastPruned, thisPruned, lastPruned);
+        // May be false if another thread gets there first
+        return Interlocked.Read(ref _lastPruned) == thisPruned;
     }
 
     private static Scope? GetSavedScope(Activity? activity)

src/Sentry/SentryTransaction.cs

@@ -263,9 +263,8 @@ public SentryTransaction(ITransactionTracer tracer)
         _breadcrumbs = tracer.Breadcrumbs.ToList();
         _extra = tracer.Extra.ToDict();
         _tags = tracer.Tags.ToDict();
-        _spans = tracer.Spans
-            .Where(s => s is not SpanTracer { IsSentryRequest: true }) // Filter sentry requests created by Sentry.OpenTelemetry.SentrySpanProcessor
-            .Select(s => new SentrySpan(s)).ToArray();
+
+        _spans = FromTracerSpans(tracer);
         _measurements = tracer.Measurements.ToDict();
 
         // Some items are not on the interface, but we only ever pass in a TransactionTracer anyway.
@@ -277,6 +276,51 @@ public SentryTransaction(ITransactionTracer tracer)
         }
     }
 
+    internal static SentrySpan[] FromTracerSpans(ITransactionTracer tracer)
+    {
+        // Filter sentry requests created by Sentry.OpenTelemetry.SentrySpanProcessor
+        var nonSentrySpans = tracer.Spans
+            .Where(s => s is not SpanTracer { IsSentryRequest: true });
+
+        if (tracer is not TransactionTracer { IsOtelInstrumenter: true })
+        {
+            return nonSentrySpans.Select(s => new SentrySpan(s)).ToArray();
+        }
+
+        Dictionary<SpanId, SpanId?> reHome = new();
+        var spans = nonSentrySpans.ToList();
+        foreach (var value in spans.ToArray())
+        {
+            if (value is not SpanTracer child)
+            {
+                continue;
+            }
+
+            // Remove any filtered spans
+            if (child.IsFiltered?.Invoke() == true)
+            {
+                reHome.Add(child.SpanId, child.ParentSpanId);
+                spans.Remove(child);
+            }
+        }
+
+        // Re-home any children of filtered spans
+        foreach (var value in spans)
+        {
+            if (value is not SpanTracer child)
+            {
+                continue;
+            }
+
+            while (child.ParentSpanId.HasValue && reHome.TryGetValue(child.ParentSpanId.Value, out var newParentId))
+            {
+                child.ParentSpanId = newParentId;
+            }
+        }
+
+        return spans.Select(s => new SentrySpan(s)).ToArray();
+    }
+
     /// <inheritdoc />
     public void AddBreadcrumb(Breadcrumb breadcrumb) =>
         _breadcrumbs.Add(breadcrumb);

src/Sentry/SpanTracer.cs

@@ -17,7 +17,7 @@ public class SpanTracer : ISpan
     public SpanId SpanId { get; internal set; }
 
     /// <inheritdoc />
-    public SpanId? ParentSpanId { get; }
+    public SpanId? ParentSpanId { get; internal set; }
 
     /// <inheritdoc />
     public SentryId TraceId { get; }
@@ -82,6 +82,8 @@ public void UnsetTag(string key) =>
     /// <inheritdoc />
     public void SetExtra(string key, object? value) => _data[key] = value;
 
+    internal Func<bool>? IsFiltered { get; set; }
+
     /// <summary>
     /// Initializes an instance of <see cref="SpanTracer"/>.
     /// </summary>

src/Sentry/TransactionTracer.cs

@@ -16,6 +16,8 @@ public class TransactionTracer : ITransactionTracer
     private readonly SentryStopwatch _stopwatch = SentryStopwatch.StartNew();
     private readonly Instrumenter _instrumenter = Instrumenter.Sentry;
 
+    internal bool IsOtelInstrumenter => _instrumenter == Instrumenter.OpenTelemetry;
+
     /// <inheritdoc />
     public SpanId SpanId
     {

test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs

@@ -122,7 +122,8 @@ public void OnNext_KnownKey_GetSpanInvoked(string key, bool addConnectionSpan)
         var spans = _fixture.Spans.Where(s => s.Operation != "abc");
         Assert.NotEmpty(spans);
 
-        Assert.True(GetValidator(key)(_fixture.Spans.First()));
+        var firstSpan = _fixture.Spans.OrderByDescending(x => x.StartTimestamp).First();
+        Assert.True(GetValidator(key)(firstSpan));
     }
 
     [Theory]

test/Sentry.OpenTelemetry.Tests/SentrySpanProcessorTests.cs

@@ -405,4 +405,101 @@ public void OnEnd_IsSentryRequest_DoesNotFinishTransaction(string urlKey)
 
         transaction.IsSentryRequest.Should().BeTrue();
     }
+
+    private static void FilterActivity(Activity activity)
+    {
+        // Simulates filtering an activity - see https://github.com/getsentry/sentry-dotnet/pull/3198
+        activity.IsAllDataRequested = false;
+        activity.ActivityTraceFlags &= ~ActivityTraceFlags.Recorded;
+    }
+
+    [Fact]
+    public void PruneFilteredSpans_FilteredTransactions_Pruned()
+    {
+        // Arrange
+        _fixture.Options.Instrumenter = Instrumenter.OpenTelemetry;
+        var sut = _fixture.GetSut();
+
+        using var parent = Tracer.StartActivity();
+        sut.OnStart(parent!);
+
+        FilterActivity(parent);
+
+        // Act
+        sut.PruneFilteredSpans(true);
+
+        // Assert
+        Assert.False(sut._map.TryGetValue(parent.SpanId, out var _));
+    }
+
+    [Fact]
+    public void PruneFilteredSpans_UnFilteredTransactions_NotPruned()
+    {
+        // Arrange
+        _fixture.Options.Instrumenter = Instrumenter.OpenTelemetry;
+        var sut = _fixture.GetSut();
+
+        using var parent = Tracer.StartActivity();
+        sut.OnStart(parent!);
+
+        // Act
+        sut.PruneFilteredSpans(true);
+
+        // Assert
+        Assert.True(sut._map.TryGetValue(parent.SpanId, out var _));
+    }
+
+    [Fact]
+    public void PruneFilteredSpans_FilteredSpans_Pruned()
+    {
+        // Arrange
+        _fixture.Options.Instrumenter = Instrumenter.OpenTelemetry;
+        var sut = _fixture.GetSut();
+
+        using var parent = Tracer.StartActivity();
+        sut.OnStart(parent!);
+
+        using var activity1 = Tracer.StartActivity();
+        sut.OnStart(activity1!);
+
+        using var activity2 = Tracer.StartActivity();
+        sut.OnStart(activity2!);
+
+        FilterActivity(activity2);
+
+        // Act
+        sut.PruneFilteredSpans(true);
+
+        // Assert
+        Assert.True(sut._map.TryGetValue(activity1.SpanId, out var _));
+        Assert.False(sut._map.TryGetValue(activity2.SpanId, out var _));
+    }
+
+    [Fact]
+    public void PruneFilteredSpans_RecentlyPruned_DoesNothing()
+    {
+        // Arrange
+        _fixture.Options.Instrumenter = Instrumenter.OpenTelemetry;
+        var sut = _fixture.GetSut();
+
+        sut._lastPruned = DateTimeOffset.MaxValue.Ticks; // fake a recent prune
+
+        using var parent = Tracer.StartActivity();
+        sut.OnStart(parent!);
+
+        using var activity1 = Tracer.StartActivity();
+        sut.OnStart(activity1!);
+
+        using var activity2 = Tracer.StartActivity();
+        sut.OnStart(activity2!);
+
+        FilterActivity(activity2);
+
+        // Act
+        sut.PruneFilteredSpans();
+
+        // Assert
+        Assert.True(sut._map.TryGetValue(activity1.SpanId, out var _));
+        Assert.True(sut._map.TryGetValue(activity2.SpanId, out var _));
+    }
 }

test/Sentry.Tests/Protocol/SentryTransactionTests.cs

@@ -571,4 +571,82 @@ public void ISpan_GetTransaction_FromSpan()
         // Assert
         Assert.Same(transaction, result);
     }
+
+    [Fact]
+    public void FromTracerSpans_Filters_SentryRequests()
+    {
+        // Arrange
+        var hub = Substitute.For<IHub>();
+        var context = new TransactionContext("name", "op")
+        {
+            Instrumenter = Instrumenter.OpenTelemetry
+        };
+        var tracer = new TransactionTracer(hub, context);
+        var span1 = (SpanTracer)tracer.StartChild(null, tracer.SpanId, "span1", Instrumenter.OpenTelemetry);
+        var span2 = (SpanTracer)tracer.StartChild(null, span1.SpanId, "span2", Instrumenter.OpenTelemetry);
+        span2.IsSentryRequest = true;
+        var span3 = (SpanTracer)tracer.StartChild(null, span2.SpanId, "span3", Instrumenter.OpenTelemetry);
+
+        // Act
+        var transaction = new SentryTransaction(tracer);
+
+        // Assert
+        var spans = transaction.Spans.ToArray();
+        spans.Length.Should().Be(2);
+        spans.Should().Contain(x => x.SpanId == span1.SpanId);
+        spans.Should().Contain(x => x.SpanId == span3.SpanId);
+    }
+
+    [Fact]
+    public void FromTracerSpans_OtelInstrumentation_FilteredSpansRemoved()
+    {
+        // Arrange
+        var hub = Substitute.For<IHub>();
+        var context = new TransactionContext("name", "op")
+        {
+            Instrumenter = Instrumenter.OpenTelemetry
+        };
+        var tracer = new TransactionTracer(hub, context);
+        var span1 = (SpanTracer)tracer.StartChild(null, tracer.SpanId, "span1", Instrumenter.OpenTelemetry);
+        var span2 = (SpanTracer)tracer.StartChild(null, span1.SpanId, "span2", Instrumenter.OpenTelemetry);
+        span2.IsFiltered = () => true;
+        var span3 = (SpanTracer)tracer.StartChild(null, span2.SpanId, "span3", Instrumenter.OpenTelemetry);
+        span3.IsFiltered = () => true;
+        var span4 = (SpanTracer)tracer.StartChild(null, span3.SpanId, "span4", Instrumenter.OpenTelemetry);
+
+        // Act
+        var transaction = new SentryTransaction(tracer);
+
+        // Assert
+        var spans = transaction.Spans.ToArray();
+        spans.Length.Should().Be(2);
+        spans.Should().Contain(x => x.SpanId == span1.SpanId);
+        var lastSpan = spans.SingleOrDefault(x => x.SpanId == span4.SpanId);
+        lastSpan.Should().NotBeNull();
+        lastSpan!.ParentSpanId.Should().Be(span1.SpanId);
+    }
+
+    [Fact]
+    public void FromTracerSpans_SentryInstrumentation_FilteredSpansRemain()
+    {
+        // Arrange
+        var hub = Substitute.For<IHub>();
+        var context = new TransactionContext("name", "op")
+        {
+            Instrumenter = Instrumenter.Sentry
+        };
+        var tracer = new TransactionTracer(hub, context);
+        var span1 = (SpanTracer)tracer.StartChild(null, tracer.SpanId, "span1", Instrumenter.OpenTelemetry);
+        var span2 = (SpanTracer)tracer.StartChild(null, span1.SpanId, "span2", Instrumenter.OpenTelemetry);
+        span2.IsFiltered = () => true;
+        var span3 = (SpanTracer)tracer.StartChild(null, span2.SpanId, "span3", Instrumenter.OpenTelemetry);
+        span3.IsFiltered = () => true;
+        tracer.StartChild(null, span3.SpanId, "span4", Instrumenter.OpenTelemetry);
+
+        // Act
+        var transaction = new SentryTransaction(tracer);
+
+        // Assert
+        transaction.Spans.Count.Should().Be(4);
+    }
 }