From fb2372a553c3319b9dc2ccfe00b92035bfe76721 Mon Sep 17 00:00:00 2001 From: LucasZF Date: Thu, 5 Aug 2021 13:12:14 -0300 Subject: [PATCH] Undo ef core changes. (#1152) --- CHANGELOG.md | 4 +- Sentry.sln | 7 - .../Sentry.Extensions.Logging.csproj | 1 - .../SentryDiagnosticSubscriber.cs | 35 --- .../SentryEFCoreListener.cs | 147 --------- .../SentryLoggerProvider.cs | 3 - .../SentryEFCoreListenerTests.cs | 280 ------------------ 7 files changed, 2 insertions(+), 475 deletions(-) delete mode 100644 src/Sentry.Extensions.Logging/SentryDiagnosticSubscriber.cs delete mode 100644 src/Sentry.Extensions.Logging/SentryEFCoreListener.cs delete mode 100644 test/Sentry.Extensions.Logging.Tests/SentryEFCoreListenerTests.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index 8d174f9722..eaa653fe15 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,9 +2,9 @@ ## Unreleased -### Features +### Fixes -- EF Core performance monitoring ([#1112](https://github.com/getsentry/sentry-dotnet/pull/1112)) +### Features ### Fixes diff --git a/Sentry.sln b/Sentry.sln index bcc5a04180..bf10ee2477 100644 --- a/Sentry.sln +++ b/Sentry.sln @@ -135,8 +135,6 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Sentry.Tunnel", "src\Sentry EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "Sentry.Tunnel.Tests", "test\Sentry.Tunnel.Tests\Sentry.Tunnel.Tests.csproj", "{BB54EF08-2FA1-498B-827B-32D905FB0F9F}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Sentry.Extensions.Logging.EfCore.Tests", "test\Sentry.Extensions.Logging.EfCore.Tests\Sentry.Extensions.Logging.EfCore.Tests.csproj", "{0547A8D6-FE06-424F-979D-0FFA7CCE6E6D}" -EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU @@ -303,10 +301,6 @@ Global {BB54EF08-2FA1-498B-827B-32D905FB0F9F}.Debug|Any CPU.Build.0 = Debug|Any CPU {BB54EF08-2FA1-498B-827B-32D905FB0F9F}.Release|Any CPU.ActiveCfg = Release|Any CPU {BB54EF08-2FA1-498B-827B-32D905FB0F9F}.Release|Any CPU.Build.0 = Release|Any CPU - {0547A8D6-FE06-424F-979D-0FFA7CCE6E6D}.Debug|Any CPU.ActiveCfg = Debug|Any CPU - {0547A8D6-FE06-424F-979D-0FFA7CCE6E6D}.Debug|Any CPU.Build.0 = Debug|Any CPU - {0547A8D6-FE06-424F-979D-0FFA7CCE6E6D}.Release|Any CPU.ActiveCfg = Release|Any CPU - {0547A8D6-FE06-424F-979D-0FFA7CCE6E6D}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -355,7 +349,6 @@ Global {066522A4-8380-4D29-8DD0-973B1EDF0B39} = {83263231-1A2A-4733-B759-EEFF14E8C5D5} {D2F8BF0E-7749-4C92-A4F1-7B96A9878458} = {AF6AF4C7-8AA2-4D59-8064-2D79560904EB} {BB54EF08-2FA1-498B-827B-32D905FB0F9F} = {83263231-1A2A-4733-B759-EEFF14E8C5D5} - {0547A8D6-FE06-424F-979D-0FFA7CCE6E6D} = {83263231-1A2A-4733-B759-EEFF14E8C5D5} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {0C652B1A-DF72-4EE5-A98B-194FE2C054F6} diff --git a/src/Sentry.Extensions.Logging/Sentry.Extensions.Logging.csproj b/src/Sentry.Extensions.Logging/Sentry.Extensions.Logging.csproj index 57a3a9c2c7..4f7fbff30c 100644 --- a/src/Sentry.Extensions.Logging/Sentry.Extensions.Logging.csproj +++ b/src/Sentry.Extensions.Logging/Sentry.Extensions.Logging.csproj @@ -11,7 +11,6 @@ - diff --git a/src/Sentry.Extensions.Logging/SentryDiagnosticSubscriber.cs b/src/Sentry.Extensions.Logging/SentryDiagnosticSubscriber.cs deleted file mode 100644 index ae31935a0c..0000000000 --- a/src/Sentry.Extensions.Logging/SentryDiagnosticSubscriber.cs +++ /dev/null @@ -1,35 +0,0 @@ -using System; -using System.Diagnostics; - -namespace Sentry.Extensions.Logging -{ - /// - /// Class that subscribes to specific listeners from DiagnosticListener. - /// - internal class SentryDiagnosticSubscriber : IObserver - { - private SentryEFCoreListener? _efInterceptor { get; set; } - - private IHub _hub { get; } - private SentryOptions _options { get; } - - public SentryDiagnosticSubscriber(IHub hub, SentryOptions options) - { - _hub = hub; - _options = options; - } - - public void OnCompleted() { } - - public void OnError(Exception error) { } - - public void OnNext(DiagnosticListener listener) - { - if (listener.Name == "Microsoft.EntityFrameworkCore") - { - _efInterceptor = new(_hub, _options); - listener.Subscribe(_efInterceptor); - } - } - } -} diff --git a/src/Sentry.Extensions.Logging/SentryEFCoreListener.cs b/src/Sentry.Extensions.Logging/SentryEFCoreListener.cs deleted file mode 100644 index 07ead9cf84..0000000000 --- a/src/Sentry.Extensions.Logging/SentryEFCoreListener.cs +++ /dev/null @@ -1,147 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Threading; -using Sentry.Extensibility; - -namespace Sentry.Extensions.Logging -{ - /// - /// Class that consumes Entity Framework Core events. - /// - internal class SentryEFCoreListener : IObserver> - { - private enum SentryEFSpanType - { - Connection, - QueryExecution, - QueryCompiler - } - - internal const string EFConnectionOpening = "Microsoft.EntityFrameworkCore.Database.Connection.ConnectionOpening"; - internal const string EFConnectionClosed = "Microsoft.EntityFrameworkCore.Database.Connection.ConnectionClosed"; - internal const string EFCommandExecuting = "Microsoft.EntityFrameworkCore.Database.Command.CommandExecuting"; - internal const string EFCommandExecuted = "Microsoft.EntityFrameworkCore.Database.Command.CommandExecuted"; - internal const string EFCommandFailed = "Microsoft.EntityFrameworkCore.Database.Command.CommandError"; - - /// - /// Used for EF Core 2.X and 3.X. - /// - /// - internal const string EFQueryStartCompiling = "Microsoft.EntityFrameworkCore.Query.QueryCompilationStarting"; - /// - /// Used for EF Core 2.X and 3.X. - /// - /// - internal const string EFQueryCompiling = "Microsoft.EntityFrameworkCore.Query.QueryModelCompiling"; - internal const string EFQueryCompiled = "Microsoft.EntityFrameworkCore.Query.QueryExecutionPlanned"; - - private IHub _hub { get; } - private SentryOptions _options { get; } - - private AsyncLocal> _spansCompilerLocal = new(); - private AsyncLocal> _spansQueryLocal = new(); - private AsyncLocal> _spansConnectionLocal = new(); - - public SentryEFCoreListener(IHub hub, SentryOptions options) - { - _hub = hub; - _options = options; - } - - private ISpan? AddSpan(SentryEFSpanType type, string operation, string? description) - { - if (_hub.GetSpan()?.StartChild(operation, description) is { } span && - GetSpanBucket(type) is { } asyncLocalSpan) - { - asyncLocalSpan.Value = new WeakReference(span); - return span; - } - return null; - } - - private ISpan? TakeSpan(SentryEFSpanType type) - { - if (GetSpanBucket(type)?.Value is { } reference && reference.TryGetTarget(out var span)) - { - return span; - } - _options.DiagnosticLogger?.LogWarning("Trying to close a span that was already garbage collected. {0}", type); - return null; - } - - private AsyncLocal>? GetSpanBucket(SentryEFSpanType type) - => type switch - { - SentryEFSpanType.QueryCompiler => _spansCompilerLocal, - SentryEFSpanType.QueryExecution => _spansQueryLocal, - SentryEFSpanType.Connection => _spansConnectionLocal, - _ => null - }; - - public void OnCompleted() { } - - public void OnError(Exception error) { } - - public void OnNext(KeyValuePair value) - { - try - { - //Query compiler Span - if (value.Key == EFQueryStartCompiling || value.Key == EFQueryCompiling) - { - AddSpan(SentryEFSpanType.QueryCompiler, "db.query_compiler", FilterNewLineValue(value.Value)); - } - else if (value.Key == EFQueryCompiled) - { - TakeSpan(SentryEFSpanType.QueryCompiler)?.Finish(SpanStatus.Ok); - } - - //Connection Span - //A transaction may or may not show a connection with it. - else if (value.Key == EFConnectionOpening) - { - AddSpan(SentryEFSpanType.Connection, "db.connection", null); - } - else if (value.Key == EFConnectionClosed) - { - TakeSpan(SentryEFSpanType.Connection)?.Finish(SpanStatus.Ok); - } - - //Query Execution Span - else if (value.Key == EFCommandExecuting) - { - AddSpan(SentryEFSpanType.QueryExecution, "db.query", FilterNewLineValue(value.Value)); - } - else if (value.Key == EFCommandFailed) - { - TakeSpan(SentryEFSpanType.QueryExecution)?.Finish(SpanStatus.InternalError); - } - else if (value.Key == EFCommandExecuted) - { - TakeSpan(SentryEFSpanType.QueryExecution)?.Finish(SpanStatus.Ok); - } - } - catch (Exception ex) - { - _options.DiagnosticLogger?.LogError("Failed to intercept EF Core event.", ex); - } - } - - /// - /// Get the Query with error message and remove the uneeded values. - /// - /// - /// Compiling query model: - /// EF intialize...\r\nEF Query... - /// becomes: - /// EF Query... - /// - /// the query to be parsed value - /// the filtered query - internal static string? FilterNewLineValue(object? value) - { - var str = value?.ToString(); - return str?.Substring(str.IndexOf('\n') + 1); - } - } -} diff --git a/src/Sentry.Extensions.Logging/SentryLoggerProvider.cs b/src/Sentry.Extensions.Logging/SentryLoggerProvider.cs index 9e5fe41d81..7d441091e5 100644 --- a/src/Sentry.Extensions.Logging/SentryLoggerProvider.cs +++ b/src/Sentry.Extensions.Logging/SentryLoggerProvider.cs @@ -17,7 +17,6 @@ public class SentryLoggerProvider : ILoggerProvider private readonly SentryLoggingOptions _options; private readonly IDisposable? _scope; private readonly IDisposable? _disposableHub; - private readonly IDisposable? _diagnosticListener; internal IHub Hub { get; } @@ -70,7 +69,6 @@ internal SentryLoggerProvider( { hub.ConfigureScope(callback); } - _diagnosticListener = DiagnosticListener.AllListeners.Subscribe(new SentryDiagnosticSubscriber(hub, options)); } } @@ -88,7 +86,6 @@ public void Dispose() { _scope?.Dispose(); _disposableHub?.Dispose(); - _diagnosticListener?.Dispose(); } } } diff --git a/test/Sentry.Extensions.Logging.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.Extensions.Logging.Tests/SentryEFCoreListenerTests.cs deleted file mode 100644 index a7797707ee..0000000000 --- a/test/Sentry.Extensions.Logging.Tests/SentryEFCoreListenerTests.cs +++ /dev/null @@ -1,280 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Linq; -using NSubstitute; -using Xunit; - -namespace Sentry.Extensions.Logging.Tests -{ - public class SentryEFCoreListenerTests - { - internal const string EFQueryCompiling = SentryEFCoreListener.EFQueryCompiling; - internal const string EFQueryCompiled = SentryEFCoreListener.EFQueryCompiled; - internal const string EFConnectionOpening = SentryEFCoreListener.EFConnectionOpening; - internal const string EFCommandExecuting = SentryEFCoreListener.EFCommandExecuting; - internal const string EFCommandExecuted = SentryEFCoreListener.EFCommandExecuted; - internal const string EFCommandFailed = SentryEFCoreListener.EFCommandFailed; - internal const string EFConnectionClosed = SentryEFCoreListener.EFConnectionClosed; - - private Func GetValidator(string type) => - type switch - { - var x when - x == EFQueryCompiling || - x == EFQueryCompiled - => (span) => span.Description != null && span.Operation == "db.query_compiler", - var x when - x == EFConnectionOpening || - x == EFConnectionClosed - => (span) => span.Description == null && span.Operation == "db.connection", - var x when - x == EFCommandExecuting || - x == EFCommandExecuting || - x == EFCommandFailed - => (span) => span.Description != null && span.Operation == "db.query", - _ => throw new NotSupportedException() - }; - - private class ThrowToStringClass - { - public override string ToString() => throw new Exception("ThrowToStringClass"); - } - - private class Fixture - { - internal TransactionTracer Tracer { get; } - - public IReadOnlyCollection Spans => Tracer?.Spans; - public IHub Hub { get; set; } - public Fixture() - { - Hub = Substitute.For(); - Tracer = new TransactionTracer(Hub, "foo", "bar"); - Hub.GetSpan().ReturnsForAnyArgs((_) => Spans?.LastOrDefault(s => !s.IsFinished) ?? Tracer); - Hub.CaptureEvent(Arg.Any(), Arg.Any()).Returns((_) => - { - Spans.LastOrDefault(s => s.IsFinished is false)?.Finish(SpanStatus.InternalError); - return SentryId.Empty; - }); - } - } - - private readonly Fixture _fixture = new(); - - [Fact] - public void OnNext_UnknownKey_SpanNotInvoked() - { - // Assert - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - - // Act - interceptor.OnNext(new("Unknown", null)); - - // Assert - hub.DidNotReceive().GetSpan(); - } - - [Theory] - [InlineData(EFQueryCompiling, "data")] - [InlineData(EFConnectionOpening, null)] - [InlineData(EFCommandExecuting, "data")] - public void OnNext_KnownKey_GetSpanInvoked(string key, string value) - { - // Arrange - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - - // Act - interceptor.OnNext(new(key, value)); - - // Assert - hub.Received(1).GetSpan(); - var child = _fixture.Spans.First(s => GetValidator(key)(s)); - } - - [Fact] - public void OnNext_HappyPath_IsValid() - { - // Arrange - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - var expectedSql = "SELECT * FROM ..."; - var efSql = "ef Junk\r\nSELECT * FROM ..."; - - // Act - interceptor.OnNext(new(EFQueryCompiling, efSql)); - interceptor.OnNext(new(EFQueryCompiled, efSql)); - interceptor.OnNext(new(EFConnectionOpening, null)); - interceptor.OnNext(new(EFCommandExecuting, efSql)); - interceptor.OnNext(new(EFCommandExecuted, efSql)); - interceptor.OnNext(new(EFConnectionClosed, efSql)); - - // Assert - hub.Received(3).GetSpan(); - var compilerSpan = _fixture.Spans.First(s => GetValidator(EFQueryCompiling)(s)); - var connectionSpan = _fixture.Spans.First(s => GetValidator(EFConnectionOpening)(s)); - var commandSpan = _fixture.Spans.First(s => GetValidator(EFCommandExecuting)(s)); - // Validate if all spans were finished. - Assert.All(_fixture.Spans, (span) => - { - Assert.True(span.IsFinished); - if (span.Operation == "db.connection") - { - Assert.Null(span.Description); - } - else - { - Assert.Equal(expectedSql, span.Description); - } - Assert.Equal(SpanStatus.Ok, span.Status); - }); - // Check connections between spans. - Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); - } - - [Fact] - public void OnNext_HappyPathWithError_TransactionWithErroredCommand() - { - // Arrange - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - var expectedSql = "SELECT * FROM ..."; - var efSql = "ef Junk\r\nSELECT * FROM ..."; - - // Act - interceptor.OnNext(new(EFQueryCompiling, efSql)); - interceptor.OnNext(new(EFQueryCompiled, efSql)); - interceptor.OnNext(new(EFConnectionOpening, null)); - interceptor.OnNext(new(EFCommandExecuting, efSql)); - interceptor.OnNext(new(EFCommandFailed, efSql)); - interceptor.OnNext(new(EFConnectionClosed, efSql)); - - // Assert - hub.Received(3).GetSpan(); - var compilerSpan = _fixture.Spans.First(s => GetValidator(EFQueryCompiling)(s)); - var connectionSpan = _fixture.Spans.First(s => GetValidator(EFConnectionOpening)(s)); - var commandSpan = _fixture.Spans.First(s => GetValidator(EFCommandFailed)(s)); - - // Validate if all spans were finished. - Assert.All(new[] { compilerSpan, connectionSpan }, - (span) => - { - Assert.True(span.IsFinished); - Assert.Equal(SpanStatus.Ok, span.Status); - }); - - // Assert the failed command. - Assert.True(commandSpan.IsFinished); - Assert.Equal(SpanStatus.InternalError, commandSpan.Status); - - // Check connections between spans. - Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); - - Assert.Equal(expectedSql, commandSpan.Description); - } - - [Fact] - public void OnNext_HappyPathWithError_TransactionWithErroredCompiler() - { - // Arrange - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - var expectedSql = "SELECT * FROM ..."; - var efSql = "ef Junk\r\nSELECT * FROM ..."; - - // Act - interceptor.OnNext(new(EFQueryCompiling, efSql)); - hub.CaptureEvent(new SentryEvent(), null); - - // Assert - hub.Received(1).GetSpan(); - var compilerSpan = _fixture.Spans.First(s => GetValidator(EFQueryCompiling)(s)); - - Assert.True(compilerSpan.IsFinished); - Assert.Equal(SpanStatus.InternalError, compilerSpan.Status); - - Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); - - Assert.Equal(expectedSql, compilerSpan.Description); - } - - [Fact] - public void OnNext_ThrowsException_ExceptionIsolated() - { - // Arrange - var hub = _fixture.Hub; - var interceptor = new SentryEFCoreListener(hub, new SentryOptions()); - var exceptionReceived = false; - - // Act - try - { - interceptor.OnNext(new(EFQueryCompiling, new ThrowToStringClass())); - } - catch (Exception) - { - exceptionReceived = true; - } - - // Assert - Assert.False(exceptionReceived); - } - - [Fact] - public void FilterNewLineValue_StringWithNewLine_SubStringAfterNewLine() - { - // Arrange - var text = "1234\r\nSELECT *...\n FROM ..."; - var expectedText = "SELECT *...\n FROM ..."; - - // Act - var value = SentryEFCoreListener.FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } - - [Fact] - public void FilterNewLineValue_NullObject_NullString() - { - // Act - var value = SentryEFCoreListener.FilterNewLineValue(null); - - // Assert - Assert.Null(value); - } - - [Fact] - public void FilterNewLineValue_OneLineString_OneLineString() - { - // Arrange - var text = "1234"; - var expectedText = "1234"; - - // Act - var value = SentryEFCoreListener.FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } - - [Fact] - public void FilterNewLineValue_EmptyString_EmptyString() - { - // Arrange - var text = ""; - var expectedText = ""; - - // Act - var value = SentryEFCoreListener.FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } - } -}