From a1fb23f234edd42de64559ed868e90478fa2d69f Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Mon, 29 May 2023 19:48:54 +1200 Subject: [PATCH 01/32] Refactored Add/Finish spans logic into Helper classes --- .../CommandDiagnosticSourceHelper.cs | 42 +++++++ .../ConnectionDiagnosticSourceHelper.cs | 42 +++++++ .../DiagnosticSourceHelper.cs | 103 ++++++++++++++++++ .../QueryCompilerDiagnosticSourceHelper.cs | 22 ++++ .../DiagnosticSource/SentryEFCoreListener.cs | 93 ++++------------ src/Sentry/SpanTracer.cs | 8 ++ src/Sentry/TransactionTracer.cs | 21 ++++ .../DiagnosticSourceHelperTests.cs | 58 ++++++++++ .../SentryEFCoreListenerTests.cs | 52 --------- 9 files changed, 315 insertions(+), 126 deletions(-) create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs create mode 100644 test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..7f43b0d644 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs @@ -0,0 +1,42 @@ +namespace Sentry.Internal.DiagnosticSource; + +internal class CommandDiagnosticSourceHelper : DiagnosticSourceHelper +{ + internal CommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, spanLocal, diagnosticSourceValue) + { + } + + protected override string Operation => "db.query"; + protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; + + protected override ISpan GetParentSpan(ITransaction transaction) + => transaction.GetLastActiveSpan() ?? transaction.GetDbParentSpan(); + + // protected override void SetSpanReference(ISpan span) + // { + // if (span is SpanTracer spanTracer) + // { + // spanTracer.TraceData["Query"] = Description; + // } + // } + + protected override ISpan? GetSpanReference() + { + return base.GetSpanReference(); + // Try to return a correlated span if we can find one. + // if (diagnosticSourceValue is CommandEventData connectionEventData && + // transaction.TryGetSpanFromTraceData(s => + // s.TraceData["CommandId"] is Guid commandId + // && commandId == connectionEventData.CommandId, out var correlatedSpan) + // ) + // { + // return correlatedSpan; + // } + + // If we only have a span for one unfinished query then we can assume it's the one we want. + + // Otherwise we have no way of knowing which Transaction to return so we'll just return null. + // This shouldn't ordinarily happen so we'll log a warning. + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..b7505a63e8 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs @@ -0,0 +1,42 @@ +namespace Sentry.Internal.DiagnosticSource; + +internal class ConnectionDiagnosticSourceHelper : DiagnosticSourceHelper +{ + internal ConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, spanLocal, diagnosticSourceValue) + { + } + + protected override string Operation => "db.connection"; + protected override string Description => null!; + + protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); + + // protected override void SetSpanReference(ISpan span) + // { + // if (span is SpanTracer spanTracer) + // { + // spanTracer.TraceData["Connection"] = Description; + // } + // } + + protected override ISpan? GetSpanReference() + { + return base.GetSpanReference(); + // Try to return a correlated span if we can find one. + // if (diagnosticSourceValue is ConnectionEventData connectionEventData && + // transaction.TryGetSpanFromTraceData(s => + // s.TraceData["ConnectionId"] is Guid connectionId + // && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) + // ) + // { + // return correlatedSpan; + // } + + // If we only have a span for one unfinished db connection we can assume it's the one we want. + + // Otherwise we have no way of knowing which Transaction to return so we'll just return null. + // This shouldn't ordinarily happen so we'll log a warning. + + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs new file mode 100644 index 0000000000..acf468be2e --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs @@ -0,0 +1,103 @@ +using Sentry.Extensibility; + +namespace Sentry.Internal.DiagnosticSource; + +internal abstract class DiagnosticSourceHelper +{ + private SentryOptions Options { get; } + protected AsyncLocal> SpanLocal { get; } + protected object? DiagnosticSourceValue { get; } + private ITransaction? Transaction { get; set; } + protected abstract string Operation { get; } + protected abstract string Description { get; } + + internal DiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + { + Options = options; + SpanLocal = spanLocal; + DiagnosticSourceValue = diagnosticSourceValue; + Transaction = hub.GetTransactionIfSampled(); + } + + internal void AddSpan() + { + Options.LogDebug($"(Sentry add span {Operation})"); + LogTransactionSpans(); + if (Transaction == null) + { + return; + } + + var parent = GetParentSpan(Transaction); + var child = parent.StartChild(Operation, Description); + + SetSpanReference(child); + } + + internal void FinishSpan(SpanStatus status) + { + if (Transaction == null) + { + return; + } + + Options.LogDebug($"(Sentry finish span {Operation})"); + LogTransactionSpans(); + + var sourceSpan = GetSpanReference(); + if (sourceSpan == null) + { + Options.LogWarning("Trying to close a span that was already garbage collected. {0}", Operation); + return; + } + + sourceSpan.Finish(status); + } + + private void LogTransactionSpans() + { + if (Transaction == null) + { + Options.LogDebug($"(Sentry transaction is null)"); + return; + } + + Options.LogDebug("Transaction Spans"); + Options.LogDebug("-----------------"); + foreach (var span in Transaction.Spans) + { + Options.LogDebug($"id: {span.SpanId} operation: {span.Operation}"); + } + } + + /// + /// Get the Query with error message and remove the unneeded values. + /// + /// + /// Compiling query model: + /// EF initialize...\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?[(str.IndexOf('\n') + 1)..]; + } + + protected abstract ISpan GetParentSpan(ITransaction transaction); + + protected virtual void SetSpanReference(ISpan span) + { + SpanLocal.Value = new WeakReference(span); + } + + protected virtual ISpan? GetSpanReference() + { + return (SpanLocal.Value is { } reference && reference.TryGetTarget(out var startedSpan)) + ? startedSpan + : null; + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..0d6cc52773 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs @@ -0,0 +1,22 @@ +namespace Sentry.Internal.DiagnosticSource; + +internal class QueryCompilerDiagnosticSourceHelper : DiagnosticSourceHelper +{ + internal QueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, spanLocal, diagnosticSourceValue) + { + } + + protected override string Operation => "db.query.compile"; + protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; + + protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); + + // protected override void SetSpanReference(ISpan span) + // { + // if (span is SpanTracer spanTracer) + // { + // spanTracer.TraceData["Query"] = Description; + // } + // } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs index 04e50a3f8f..6db7320f44 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs @@ -7,13 +7,6 @@ namespace Sentry.Internal.DiagnosticSource; /// 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"; @@ -52,85 +45,54 @@ public SentryEFCoreListener(IHub hub, SentryOptions options) internal void DisableQuerySpan() => _logQueryEnabled = false; - private void AddSpan(SentryEFSpanType type, string operation, string? description) - { - var transaction = _hub.GetTransactionIfSampled(); - if (transaction == null) - { - return; - } - - var parent = type == SentryEFSpanType.QueryExecution - ? transaction.GetLastActiveSpan() ?? transaction.GetDbParentSpan() - : transaction.GetDbParentSpan(); - - var child = parent.StartChild(operation, description); - - var asyncLocalSpan = GetSpanBucket(type); - asyncLocalSpan.Value = new WeakReference(child); - } - - private ISpan? TakeSpan(SentryEFSpanType type) - { - var transaction = _hub.GetTransactionIfSampled(); - if (transaction == null) - { - return null; - } - - if (GetSpanBucket(type).Value is { } reference && reference.TryGetTarget(out var startedSpan)) - { - return startedSpan; - } + public void OnCompleted() { } - _options.LogWarning("Trying to close a span that was already garbage collected. {0}", type); - return null; - } + public void OnError(Exception error) { } - private AsyncLocal> GetSpanBucket(SentryEFSpanType type) - => type switch - { - SentryEFSpanType.QueryCompiler => _spansCompilerLocal, - SentryEFSpanType.QueryExecution => _spansQueryLocal, - SentryEFSpanType.Connection => _spansConnectionLocal, - _ => throw new($"Unknown SentryEFSpanType: {type}") - }; + private QueryCompilerDiagnosticSourceHelper QueryCompilerDiagnosticSourceHelper(object? diagnosticsSourceValue) => + new(_hub, _options, _spansCompilerLocal, diagnosticsSourceValue); - public void OnCompleted() { } + private ConnectionDiagnosticSourceHelper ConnectionDiagnosticSourceHelper(object? diagnosticsSourceValue) => + new(_hub, _options, _spansConnectionLocal, diagnosticsSourceValue); - public void OnError(Exception error) { } + private CommandDiagnosticSourceHelper CommandDiagnosticSourceHelper(object? diagnosticsSourceValue) => + new(_hub, _options, _spansQueryLocal, diagnosticsSourceValue); public void OnNext(KeyValuePair value) { try { + // Because we have to support the .NET framework, we can't get at strongly typed diagnostic source events. + // We do know they're objects, that can be converted to strings though... and we can get the correlation + // data we need from there by parsing the string. Not as reliable, but works against all frameworks. + var diagnosticSourceValue = value.Value?.ToString(); switch (value.Key) { // Query compiler span case EFQueryStartCompiling or EFQueryCompiling: - AddSpan(SentryEFSpanType.QueryCompiler, "db.query.compile", FilterNewLineValue(value.Value)); + QueryCompilerDiagnosticSourceHelper(value.Value).AddSpan(); break; case EFQueryCompiled: - TakeSpan(SentryEFSpanType.QueryCompiler)?.Finish(SpanStatus.Ok); + QueryCompilerDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); break; // Connection span (A transaction may or may not show a connection with it.) case EFConnectionOpening when _logConnectionEnabled: - AddSpan(SentryEFSpanType.Connection, "db.connection", null); + ConnectionDiagnosticSourceHelper(value.Value).AddSpan(); break; case EFConnectionClosed when _logConnectionEnabled: - TakeSpan(SentryEFSpanType.Connection)?.Finish(SpanStatus.Ok); + ConnectionDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); break; // Query Execution span case EFCommandExecuting when _logQueryEnabled: - AddSpan(SentryEFSpanType.QueryExecution, "db.query", FilterNewLineValue(value.Value)); + CommandDiagnosticSourceHelper(value.Value).AddSpan(); break; case EFCommandFailed when _logQueryEnabled: - TakeSpan(SentryEFSpanType.QueryExecution)?.Finish(SpanStatus.InternalError); + CommandDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.InternalError); break; case EFCommandExecuted when _logQueryEnabled: - TakeSpan(SentryEFSpanType.QueryExecution)?.Finish(SpanStatus.Ok); + CommandDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); break; } } @@ -139,21 +101,4 @@ public void OnNext(KeyValuePair value) _options.LogError("Failed to intercept EF Core event.", ex); } } - - /// - /// Get the Query with error message and remove the unneeded values. - /// - /// - /// Compiling query model: - /// EF initialize...\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?[(str.IndexOf('\n') + 1)..]; - } } diff --git a/src/Sentry/SpanTracer.cs b/src/Sentry/SpanTracer.cs index 66d4aa10ae..442b4f2a3b 100644 --- a/src/Sentry/SpanTracer.cs +++ b/src/Sentry/SpanTracer.cs @@ -63,6 +63,14 @@ public void UnsetTag(string key) => /// public void SetExtra(string key, object? value) => _data[key] = value; + /// + /// Can be used to store data for the duration of the Trace. This data is not sent to Sentry. + /// + /// For example, information from a DiagnosticSource event can be stored here and used to correlate + /// with subsequent DiagnosticSource events in order to construct an accurate Span hierarchy. + /// + internal ConcurrentDictionary TraceData = new(); + /// /// Initializes an instance of . /// diff --git a/src/Sentry/TransactionTracer.cs b/src/Sentry/TransactionTracer.cs index 513716cb85..053230f756 100644 --- a/src/Sentry/TransactionTracer.cs +++ b/src/Sentry/TransactionTracer.cs @@ -308,3 +308,24 @@ public void Finish(Exception exception) => SpanId, IsSampled); } + +internal static class TransactionTracerExtensions +{ + internal static ISpan? SpanFromTraceData(this ITransaction transaction, Func match) + { + return transaction.TryGetSpanFromTraceData(match, out var span) + ? span + : null; + } + + internal static bool TryGetSpanFromTraceData(this ITransaction transaction, Func match, out ISpan? span) + { + if (transaction is TransactionTracer transactionTracer) + { + span = transactionTracer.Spans.SingleOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); + return span is not null; + } + span = null; + return false; + } +} diff --git a/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs b/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs new file mode 100644 index 0000000000..046b7ee416 --- /dev/null +++ b/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs @@ -0,0 +1,58 @@ +using Sentry.Internal.DiagnosticSource; + +namespace Sentry.DiagnosticSource.Tests; + +public class DiagnosticSourceHelperTests +{ + [Fact] + public void FilterNewLineValue_StringWithNewLine_SubStringAfterNewLine() + { + // Arrange + var text = "1234\r\nSELECT *...\n FROM ..."; + var expectedText = "SELECT *...\n FROM ..."; + + // Act + var value = DiagnosticSourceHelper.FilterNewLineValue(text); + + // Assert + Assert.Equal(expectedText, value); + } + + [Fact] + public void FilterNewLineValue_NullObject_NullString() + { + // Act + var value = DiagnosticSourceHelper.FilterNewLineValue(null); + + // Assert + Assert.Null(value); + } + + [Fact] + public void FilterNewLineValue_OneLineString_OneLineString() + { + // Arrange + var text = "1234"; + var expectedText = "1234"; + + // Act + var value = DiagnosticSourceHelper.FilterNewLineValue(text); + + // Assert + Assert.Equal(expectedText, value); + } + + [Fact] + public void FilterNewLineValue_EmptyString_EmptyString() + { + // Arrange + var text = ""; + var expectedText = ""; + + // Act + var value = DiagnosticSourceHelper.FilterNewLineValue(text); + + // Assert + Assert.Equal(expectedText, value); + } +} diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 25631bff17..f51b16ef5b 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -382,56 +382,4 @@ public void OnNext_TakeSpanWithoutSpan_ShowsGarbageCollectorError(string operati .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); } - - [Fact] - public void FilterNewLineValue_StringWithNewLine_SubStringAfterNewLine() - { - // Arrange - var text = "1234\r\nSELECT *...\n FROM ..."; - var expectedText = "SELECT *...\n FROM ..."; - - // Act - var value = FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } - - [Fact] - public void FilterNewLineValue_NullObject_NullString() - { - // Act - var value = FilterNewLineValue(null); - - // Assert - Assert.Null(value); - } - - [Fact] - public void FilterNewLineValue_OneLineString_OneLineString() - { - // Arrange - var text = "1234"; - var expectedText = "1234"; - - // Act - var value = FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } - - [Fact] - public void FilterNewLineValue_EmptyString_EmptyString() - { - // Arrange - var text = ""; - var expectedText = ""; - - // Act - var value = FilterNewLineValue(text); - - // Assert - Assert.Equal(expectedText, value); - } } From 80d24bb9610d1a927d33019c0b776a2b45bc78d1 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Mon, 29 May 2023 22:13:44 +1200 Subject: [PATCH 02/32] Implemented logic to correlate Add/Finish spans using Diagnostic ConnectionId and CommandId --- .../CommandDiagnosticSourceHelper.cs | 76 ++++++++++++++----- .../ConnectionDiagnosticSourceHelper.cs | 54 ++++++++----- .../DiagnosticSourceHelper.cs | 4 +- .../QueryCompilerDiagnosticSourceHelper.cs | 12 +-- .../Sentry.DiagnosticSource.csproj | 8 +- src/Sentry/TransactionTracer.cs | 9 ++- 6 files changed, 110 insertions(+), 53 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs index 7f43b0d644..d57e29ba4c 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs @@ -1,3 +1,7 @@ +#if NETSTANDARD2_1_OR_GREATER +using Microsoft.EntityFrameworkCore.Diagnostics; +#endif + namespace Sentry.Internal.DiagnosticSource; internal class CommandDiagnosticSourceHelper : DiagnosticSourceHelper @@ -11,32 +15,66 @@ internal CommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLoc protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; protected override ISpan GetParentSpan(ITransaction transaction) - => transaction.GetLastActiveSpan() ?? transaction.GetDbParentSpan(); + { +#if NETSTANDARD2_1_OR_GREATER + // We can use the ConnectionId to find the connection this command is associated with. + if (DiagnosticSourceValue is CommandEventData connectionEventData && + transaction.TryGetSpanFromTraceData(s => + s.TraceData["ConnectionId"] is Guid connectionId + && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) + ) + { + if (correlatedSpan is not null) + { + return correlatedSpan; + } + } + // TODO: Log warning... this shouldn't happen +#endif + return transaction.GetLastActiveSpan() ?? transaction.GetDbParentSpan(); + } + +#if NETSTANDARD2_1_OR_GREATER - // protected override void SetSpanReference(ISpan span) - // { - // if (span is SpanTracer spanTracer) - // { - // spanTracer.TraceData["Query"] = Description; - // } - // } + protected override void SetSpanReference(ISpan span) + { + if (span is SpanTracer spanTracer && DiagnosticSourceValue is CommandEventData commandEventData) + { + spanTracer.TraceData["ConnectionId"] = commandEventData.ConnectionId; + spanTracer.TraceData["CommandId"] = commandEventData.CommandId; + return; + } + + base.SetSpanReference(span); + } - protected override ISpan? GetSpanReference() + protected override ISpan? GetSpanReference(ITransaction transaction) { - return base.GetSpanReference(); // Try to return a correlated span if we can find one. - // if (diagnosticSourceValue is CommandEventData connectionEventData && - // transaction.TryGetSpanFromTraceData(s => - // s.TraceData["CommandId"] is Guid commandId - // && commandId == connectionEventData.CommandId, out var correlatedSpan) - // ) - // { - // return correlatedSpan; - // } + if (DiagnosticSourceValue is CommandEventData connectionEventData && + transaction.TryGetSpanFromTraceData(s => + s.TraceData["CommandId"] is Guid commandId + && commandId == connectionEventData.CommandId, out var correlatedSpan) + ) + { + return correlatedSpan; + } // If we only have a span for one unfinished query then we can assume it's the one we want. + try + { + return transaction.Spans + .OrderByDescending(x => x.StartTimestamp) + .SingleOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); + } + catch (InvalidOperationException) + { + // This exception is thrown if SingleOrDefault matches more than one element + } // Otherwise we have no way of knowing which Transaction to return so we'll just return null. - // This shouldn't ordinarily happen so we'll log a warning. + // TODO: This shouldn't ordinarily happen so we'll log a warning. + return null; } +#endif } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs index b7505a63e8..bb07b06c93 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs @@ -1,3 +1,7 @@ +#if NETSTANDARD2_1_OR_GREATER +using Microsoft.EntityFrameworkCore.Diagnostics; +#endif + namespace Sentry.Internal.DiagnosticSource; internal class ConnectionDiagnosticSourceHelper : DiagnosticSourceHelper @@ -12,31 +16,43 @@ internal ConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, Async protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); - // protected override void SetSpanReference(ISpan span) - // { - // if (span is SpanTracer spanTracer) - // { - // spanTracer.TraceData["Connection"] = Description; - // } - // } +#if NETSTANDARD2_1_OR_GREATER + protected override void SetSpanReference(ISpan span) + { + if (span is SpanTracer spanTracer && DiagnosticSourceValue is ConnectionEventData connectionEventData) + { + spanTracer.TraceData["ConnectionId"] = connectionEventData.ConnectionId; + return; + } + } - protected override ISpan? GetSpanReference() + protected override ISpan? GetSpanReference(ITransaction transaction) { - return base.GetSpanReference(); // Try to return a correlated span if we can find one. - // if (diagnosticSourceValue is ConnectionEventData connectionEventData && - // transaction.TryGetSpanFromTraceData(s => - // s.TraceData["ConnectionId"] is Guid connectionId - // && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) - // ) - // { - // return correlatedSpan; - // } + if (DiagnosticSourceValue is ConnectionEventData connectionEventData && + transaction.TryGetSpanFromTraceData(s => + s.TraceData["ConnectionId"] is Guid connectionId + && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) + ) + { + return correlatedSpan; + } // If we only have a span for one unfinished db connection we can assume it's the one we want. + try + { + return transaction.Spans + .OrderByDescending(x => x.StartTimestamp) + .SingleOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); + } + catch (InvalidOperationException) + { + // This exception is thrown if SingleOrDefault matches more than one element + } // Otherwise we have no way of knowing which Transaction to return so we'll just return null. - // This shouldn't ordinarily happen so we'll log a warning. - + // TODO: This shouldn't ordinarily happen so we'll log a warning. + return null; } +#endif } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs index acf468be2e..9ff9b029c3 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs @@ -44,7 +44,7 @@ internal void FinishSpan(SpanStatus status) Options.LogDebug($"(Sentry finish span {Operation})"); LogTransactionSpans(); - var sourceSpan = GetSpanReference(); + var sourceSpan = GetSpanReference(Transaction); if (sourceSpan == null) { Options.LogWarning("Trying to close a span that was already garbage collected. {0}", Operation); @@ -94,7 +94,7 @@ protected virtual void SetSpanReference(ISpan span) SpanLocal.Value = new WeakReference(span); } - protected virtual ISpan? GetSpanReference() + protected virtual ISpan? GetSpanReference(ITransaction transaction) { return (SpanLocal.Value is { } reference && reference.TryGetTarget(out var startedSpan)) ? startedSpan diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs index 0d6cc52773..5f9e853eb6 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs @@ -1,3 +1,7 @@ +#if NETSTANDARD2_1_OR_GREATER +using Microsoft.EntityFrameworkCore.Diagnostics; +#endif + namespace Sentry.Internal.DiagnosticSource; internal class QueryCompilerDiagnosticSourceHelper : DiagnosticSourceHelper @@ -11,12 +15,4 @@ internal QueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, As protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); - - // protected override void SetSpanReference(ISpan span) - // { - // if (span is SpanTracer spanTracer) - // { - // spanTracer.TraceData["Query"] = Description; - // } - // } } diff --git a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj index 75ccb002d1..19c2f8a321 100644 --- a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj +++ b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj @@ -13,10 +13,14 @@ - + + + + + - + diff --git a/src/Sentry/TransactionTracer.cs b/src/Sentry/TransactionTracer.cs index 053230f756..9906ee5fa0 100644 --- a/src/Sentry/TransactionTracer.cs +++ b/src/Sentry/TransactionTracer.cs @@ -309,6 +309,8 @@ public void Finish(Exception exception) => IsSampled); } +#if NETSTANDARD2_1_OR_GREATER + internal static class TransactionTracerExtensions { internal static ISpan? SpanFromTraceData(this ITransaction transaction, Func match) @@ -320,12 +322,13 @@ internal static class TransactionTracerExtensions internal static bool TryGetSpanFromTraceData(this ITransaction transaction, Func match, out ISpan? span) { + span = null; if (transaction is TransactionTracer transactionTracer) { span = transactionTracer.Spans.SingleOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); - return span is not null; } - span = null; - return false; + return span is not null; } } + +#endif From 54fe8a2ca14dafe6e6543341caf1a01d7656f952 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 1 Jun 2023 15:36:50 +1200 Subject: [PATCH 03/32] Replaced AsyncLocl with Correlation IDs extracted from EF diagnostic events --- CHANGELOG.md | 3 +- .../CommandDiagnosticSourceHelper.cs | 80 ---------- .../ConnectionDiagnosticSourceHelper.cs | 58 ------- .../DiagnosticSourceHelper.cs | 103 ------------- .../EFCommandDiagnosticSourceHelper.cs | 46 ++++++ .../EFConnectionDiagnosticSourceHelper.cs | 46 ++++++ .../EFDiagnosticSourceHelper.cs | 145 ++++++++++++++++++ .../EFQueryCompilerDiagnosticSourceHelper.cs | 43 ++++++ .../QueryCompilerDiagnosticSourceHelper.cs | 18 --- .../DiagnosticSource/SentryEFCoreListener.cs | 6 +- .../Sentry.DiagnosticSource.csproj | 6 +- src/Sentry/Sentry.csproj | 34 +--- src/Sentry/TransactionTracer.cs | 24 --- .../DiagnosticSourceHelperTests.cs | 8 +- .../SentryEFCoreListenerTests.cs | 61 ++++++-- test/Sentry.NLog.Tests/SentryTargetTests.cs | 2 +- 16 files changed, 345 insertions(+), 338 deletions(-) delete mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs delete mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs delete mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs delete mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index 71b1efe35f..a0df06b995 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,7 +5,8 @@ ## Fixes - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) - +- Fix/db spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) +- ## 3.33.0 ### Features diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs deleted file mode 100644 index d57e29ba4c..0000000000 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/CommandDiagnosticSourceHelper.cs +++ /dev/null @@ -1,80 +0,0 @@ -#if NETSTANDARD2_1_OR_GREATER -using Microsoft.EntityFrameworkCore.Diagnostics; -#endif - -namespace Sentry.Internal.DiagnosticSource; - -internal class CommandDiagnosticSourceHelper : DiagnosticSourceHelper -{ - internal CommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, spanLocal, diagnosticSourceValue) - { - } - - protected override string Operation => "db.query"; - protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; - - protected override ISpan GetParentSpan(ITransaction transaction) - { -#if NETSTANDARD2_1_OR_GREATER - // We can use the ConnectionId to find the connection this command is associated with. - if (DiagnosticSourceValue is CommandEventData connectionEventData && - transaction.TryGetSpanFromTraceData(s => - s.TraceData["ConnectionId"] is Guid connectionId - && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) - ) - { - if (correlatedSpan is not null) - { - return correlatedSpan; - } - } - // TODO: Log warning... this shouldn't happen -#endif - return transaction.GetLastActiveSpan() ?? transaction.GetDbParentSpan(); - } - -#if NETSTANDARD2_1_OR_GREATER - - protected override void SetSpanReference(ISpan span) - { - if (span is SpanTracer spanTracer && DiagnosticSourceValue is CommandEventData commandEventData) - { - spanTracer.TraceData["ConnectionId"] = commandEventData.ConnectionId; - spanTracer.TraceData["CommandId"] = commandEventData.CommandId; - return; - } - - base.SetSpanReference(span); - } - - protected override ISpan? GetSpanReference(ITransaction transaction) - { - // Try to return a correlated span if we can find one. - if (DiagnosticSourceValue is CommandEventData connectionEventData && - transaction.TryGetSpanFromTraceData(s => - s.TraceData["CommandId"] is Guid commandId - && commandId == connectionEventData.CommandId, out var correlatedSpan) - ) - { - return correlatedSpan; - } - - // If we only have a span for one unfinished query then we can assume it's the one we want. - try - { - return transaction.Spans - .OrderByDescending(x => x.StartTimestamp) - .SingleOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); - } - catch (InvalidOperationException) - { - // This exception is thrown if SingleOrDefault matches more than one element - } - - // Otherwise we have no way of knowing which Transaction to return so we'll just return null. - // TODO: This shouldn't ordinarily happen so we'll log a warning. - return null; - } -#endif -} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs deleted file mode 100644 index bb07b06c93..0000000000 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/ConnectionDiagnosticSourceHelper.cs +++ /dev/null @@ -1,58 +0,0 @@ -#if NETSTANDARD2_1_OR_GREATER -using Microsoft.EntityFrameworkCore.Diagnostics; -#endif - -namespace Sentry.Internal.DiagnosticSource; - -internal class ConnectionDiagnosticSourceHelper : DiagnosticSourceHelper -{ - internal ConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, spanLocal, diagnosticSourceValue) - { - } - - protected override string Operation => "db.connection"; - protected override string Description => null!; - - protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); - -#if NETSTANDARD2_1_OR_GREATER - protected override void SetSpanReference(ISpan span) - { - if (span is SpanTracer spanTracer && DiagnosticSourceValue is ConnectionEventData connectionEventData) - { - spanTracer.TraceData["ConnectionId"] = connectionEventData.ConnectionId; - return; - } - } - - protected override ISpan? GetSpanReference(ITransaction transaction) - { - // Try to return a correlated span if we can find one. - if (DiagnosticSourceValue is ConnectionEventData connectionEventData && - transaction.TryGetSpanFromTraceData(s => - s.TraceData["ConnectionId"] is Guid connectionId - && connectionId == connectionEventData.ConnectionId, out var correlatedSpan) - ) - { - return correlatedSpan; - } - - // If we only have a span for one unfinished db connection we can assume it's the one we want. - try - { - return transaction.Spans - .OrderByDescending(x => x.StartTimestamp) - .SingleOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); - } - catch (InvalidOperationException) - { - // This exception is thrown if SingleOrDefault matches more than one element - } - - // Otherwise we have no way of knowing which Transaction to return so we'll just return null. - // TODO: This shouldn't ordinarily happen so we'll log a warning. - return null; - } -#endif -} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs deleted file mode 100644 index 9ff9b029c3..0000000000 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceHelper.cs +++ /dev/null @@ -1,103 +0,0 @@ -using Sentry.Extensibility; - -namespace Sentry.Internal.DiagnosticSource; - -internal abstract class DiagnosticSourceHelper -{ - private SentryOptions Options { get; } - protected AsyncLocal> SpanLocal { get; } - protected object? DiagnosticSourceValue { get; } - private ITransaction? Transaction { get; set; } - protected abstract string Operation { get; } - protected abstract string Description { get; } - - internal DiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - { - Options = options; - SpanLocal = spanLocal; - DiagnosticSourceValue = diagnosticSourceValue; - Transaction = hub.GetTransactionIfSampled(); - } - - internal void AddSpan() - { - Options.LogDebug($"(Sentry add span {Operation})"); - LogTransactionSpans(); - if (Transaction == null) - { - return; - } - - var parent = GetParentSpan(Transaction); - var child = parent.StartChild(Operation, Description); - - SetSpanReference(child); - } - - internal void FinishSpan(SpanStatus status) - { - if (Transaction == null) - { - return; - } - - Options.LogDebug($"(Sentry finish span {Operation})"); - LogTransactionSpans(); - - var sourceSpan = GetSpanReference(Transaction); - if (sourceSpan == null) - { - Options.LogWarning("Trying to close a span that was already garbage collected. {0}", Operation); - return; - } - - sourceSpan.Finish(status); - } - - private void LogTransactionSpans() - { - if (Transaction == null) - { - Options.LogDebug($"(Sentry transaction is null)"); - return; - } - - Options.LogDebug("Transaction Spans"); - Options.LogDebug("-----------------"); - foreach (var span in Transaction.Spans) - { - Options.LogDebug($"id: {span.SpanId} operation: {span.Operation}"); - } - } - - /// - /// Get the Query with error message and remove the unneeded values. - /// - /// - /// Compiling query model: - /// EF initialize...\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?[(str.IndexOf('\n') + 1)..]; - } - - protected abstract ISpan GetParentSpan(ITransaction transaction); - - protected virtual void SetSpanReference(ISpan span) - { - SpanLocal.Value = new WeakReference(span); - } - - protected virtual ISpan? GetSpanReference(ITransaction transaction) - { - return (SpanLocal.Value is { } reference && reference.TryGetTarget(out var startedSpan)) - ? startedSpan - : null; - } -} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..6eb97bb887 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -0,0 +1,46 @@ +using Sentry.Internal.Extensions; + +namespace Sentry.Internal.DiagnosticSource; + +// ReSharper disable once InconsistentNaming +internal class EFCommandDiagnosticSourceHelper : EFDiagnosticSourceHelper +{ + internal EFCommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, diagnosticSourceValue) + { + } + + protected override string Operation => "db.query"; + protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; + + private Guid? CommandId => DiagnosticSourceValue?.GetGuidProperty("CommandId"); + // The following would be more restrictive but harder to mock/test + // DiagnosticSourceValue?.GetType().FullName == "Microsoft.EntityFrameworkCore.Diagnostics.CommandEventData" + // ? DiagnosticSourceValue?.GetGuidProperty("CommandId") : + // null; + + private bool CorrelatedSpan(SpanTracer span) => + span.TraceData.ContainsKey(nameof(CommandId)) && + span.TraceData[nameof(CommandId)] is Guid traceCommandId && + CommandId == traceCommandId; + + protected override ISpan? GetSpanReference(ITransaction transaction) + { + // Try to return a correlated span if we can find one. + if (TryGetSpanFromTraceData(transaction, CorrelatedSpan, out var correlatedSpan)) + { + return correlatedSpan; + } + return base.GetSpanReference(transaction); + } + + protected override void SetSpanReference(ISpan span) + { + if (span is SpanTracer spanTracer) + { + spanTracer.TraceData[nameof(CommandId)] = CommandId; + return; + } + base.SetSpanReference(span); + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..241a10b1a6 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -0,0 +1,46 @@ +using Sentry.Internal.Extensions; + +namespace Sentry.Internal.DiagnosticSource; + +// ReSharper disable once InconsistentNaming +internal class EFConnectionDiagnosticSourceHelper : EFDiagnosticSourceHelper +{ + internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, diagnosticSourceValue) + { + } + + protected override string Operation => "db.connection"; + protected override string Description => null!; + + private Guid? ConnectionId => DiagnosticSourceValue?.GetGuidProperty("ConnectionId"); + // The following would be more restrictive but harder to mock/test + // DiagnosticSourceValue?.GetType().FullName == "Microsoft.EntityFrameworkCore.Diagnostics.ConnectionEventData" + // ? DiagnosticSourceValue?.GetGuidProperty("ConnectionId") : + // null; + + private bool CorrelatedSpan(SpanTracer span) => + span.TraceData.ContainsKey(nameof(ConnectionId)) && + span.TraceData[nameof(ConnectionId)] is Guid traceConnectionId && + ConnectionId == traceConnectionId; + + protected override ISpan? GetSpanReference(ITransaction transaction) + { + // Try to return a correlated span if we can find one. + if (TryGetSpanFromTraceData(transaction, CorrelatedSpan, out var correlatedSpan)) + { + return correlatedSpan; + } + return base.GetSpanReference(transaction); + } + + protected override void SetSpanReference(ISpan span) + { + if (span is SpanTracer spanTracer) + { + spanTracer.TraceData[nameof(ConnectionId)] = ConnectionId; + return; + } + base.SetSpanReference(span); + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..438cfbcba6 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -0,0 +1,145 @@ +using Sentry.Extensibility; + +namespace Sentry.Internal.DiagnosticSource; + +// ReSharper disable once InconsistentNaming +internal abstract class EFDiagnosticSourceHelper +{ + private SentryOptions Options { get; } + protected object? DiagnosticSourceValue { get; } + private ITransaction? Transaction { get; set; } + protected abstract string Operation { get; } + protected abstract string Description { get; } + + internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options, object? diagnosticSourceValue) + { + Options = options; + DiagnosticSourceValue = diagnosticSourceValue; + Transaction = hub.GetTransactionIfSampled(); + } + + internal void AddSpan() + { + Options.LogDebug($"(Sentry add span {Operation})"); + LogTransactionSpans(); + if (Transaction == null) + { + return; + } + + var parent = GetParentSpan(Transaction); + var child = parent.StartChild(Operation, Description); + + SetSpanReference(child); + } + + internal void FinishSpan(SpanStatus status) + { + if (Transaction == null) + { + return; + } + + Options.LogDebug($"(Sentry finish span {Operation})"); + LogTransactionSpans(); + + var sourceSpan = GetSpanReference(Transaction); + if (sourceSpan == null) + { + Options.LogWarning("Trying to close a span that was already garbage collected. {0}", Operation); + return; + } + + sourceSpan.Finish(status); + } + + private void LogTransactionSpans() + { + if (Transaction == null) + { + Options.LogDebug($"(Sentry transaction is null)"); + return; + } + + Options.LogDebug("Transaction Spans"); + Options.LogDebug("-----------------"); + foreach (var span in Transaction.Spans) + { + Options.LogDebug($"id: {span.SpanId} operation: {span.Operation}"); + } + } + + /// + /// Get the Query with error message and remove the unneeded values. + /// + /// + /// Compiling query model: + /// EF initialize...\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?[(str.IndexOf('\n') + 1)..]; + } + + /// + /// Finds an appropriate parent for EF diagnostic spans. Note that in our implementaion we're "flattening" these. + /// Spans from and + /// will both have the same parent as those of . + /// + /// We've done this for two reasons: + /// 1. We could show these underneath the relevant connection, but each command often gets it's own connection which + /// makes the resulting waterfall diagram hard to read. + /// 2. Sentry has a performance to errors feature which detects n + 1 problems on OM frameworks... but this only + /// works if all of the "n" queries have the same parent span in the transaction. Again, since queries ofen run + /// on their own connection, if we wrap each query in a connection span, it breaks the performance error handling + /// + private ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); + + protected virtual void SetSpanReference(ISpan span) + { + Options.LogDebug($"No Span reference found when adding {Operation} Span."); + } + + protected virtual ISpan? GetSpanReference(ITransaction transaction) + { + Options.LogDebug($"No Span reference found when getting {Operation}. Taking the first unfinished span instead."); + return transaction.Spans + .OrderByDescending(x => x.StartTimestamp) + .FirstOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); + } + + protected static bool TryGetSpanFromTraceData(ITransaction transaction, Func match, out ISpan? span) + { + span = null; + if (transaction is TransactionTracer transactionTracer) + { + try + { + span = transactionTracer.Spans.SingleOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); + } + catch (InvalidOperationException) + { + // If SingleOrDefault matches no element or more than one element + return false; + } + } + return span is not null; + } + + protected static bool TryGetFirstSpanFromTraceData(ITransaction transaction, Func match, out ISpan? span) + { + span = null; + if (transaction is TransactionTracer transactionTracer) + { + span = transactionTracer.Spans + .OrderBy(s => s.StartTimestamp) + .FirstOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); + } + return span is not null; + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs new file mode 100644 index 0000000000..5b972479c0 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs @@ -0,0 +1,43 @@ +using Sentry.Internal.Extensions; + +namespace Sentry.Internal.DiagnosticSource; + +// ReSharper disable once InconsistentNaming +internal class EFQueryCompilerDiagnosticSourceHelper : EFDiagnosticSourceHelper +{ + internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) + : base(hub, options, diagnosticSourceValue) + { + } + + protected override string Operation => "db.query.compile"; + protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; + + private string QueryExpression => Description; + + private bool SameExpression(SpanTracer span) => + span.TraceData.ContainsKey(nameof(QueryExpression)) && + span.TraceData[nameof(QueryExpression)] is string traceQueryExpression && + QueryExpression == traceQueryExpression; + + protected override ISpan? GetSpanReference(ITransaction transaction) + { + // In the case of Query Compilation events, we don't get any correlation id from the diagnostic data. The best + // we can do is to use the query expression. This isn't guaranteed to be unique so we grab the first match. + if (TryGetFirstSpanFromTraceData(transaction, SameExpression, out var looselyCorrelatedSpan)) + { + return looselyCorrelatedSpan; + } + return base.GetSpanReference(transaction); + } + + protected override void SetSpanReference(ISpan span) + { + if (span is SpanTracer spanTracer) + { + spanTracer.TraceData[nameof(QueryExpression)] = QueryExpression; + return; + } + base.SetSpanReference(span); + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs deleted file mode 100644 index 5f9e853eb6..0000000000 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/QueryCompilerDiagnosticSourceHelper.cs +++ /dev/null @@ -1,18 +0,0 @@ -#if NETSTANDARD2_1_OR_GREATER -using Microsoft.EntityFrameworkCore.Diagnostics; -#endif - -namespace Sentry.Internal.DiagnosticSource; - -internal class QueryCompilerDiagnosticSourceHelper : DiagnosticSourceHelper -{ - internal QueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, spanLocal, diagnosticSourceValue) - { - } - - protected override string Operation => "db.query.compile"; - protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; - - protected override ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); -} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs index 6db7320f44..ee11bc9852 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs @@ -49,13 +49,13 @@ public void OnCompleted() { } public void OnError(Exception error) { } - private QueryCompilerDiagnosticSourceHelper QueryCompilerDiagnosticSourceHelper(object? diagnosticsSourceValue) => + private EFQueryCompilerDiagnosticSourceHelper QueryCompilerDiagnosticSourceHelper(object? diagnosticsSourceValue) => new(_hub, _options, _spansCompilerLocal, diagnosticsSourceValue); - private ConnectionDiagnosticSourceHelper ConnectionDiagnosticSourceHelper(object? diagnosticsSourceValue) => + private EFConnectionDiagnosticSourceHelper ConnectionDiagnosticSourceHelper(object? diagnosticsSourceValue) => new(_hub, _options, _spansConnectionLocal, diagnosticsSourceValue); - private CommandDiagnosticSourceHelper CommandDiagnosticSourceHelper(object? diagnosticsSourceValue) => + private EFCommandDiagnosticSourceHelper CommandDiagnosticSourceHelper(object? diagnosticsSourceValue) => new(_hub, _options, _spansQueryLocal, diagnosticsSourceValue); public void OnNext(KeyValuePair value) diff --git a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj index 19c2f8a321..e0d67dfaeb 100644 --- a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj +++ b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj @@ -13,11 +13,7 @@ - - - - - + diff --git a/src/Sentry/Sentry.csproj b/src/Sentry/Sentry.csproj index d36cee6003..ce310b87d7 100644 --- a/src/Sentry/Sentry.csproj +++ b/src/Sentry/Sentry.csproj @@ -93,35 +93,17 @@ <_OSArchitecture>$([System.Runtime.InteropServices.RuntimeInformation]::OSArchitecture) - - - - - - - + + + + + + + - + diff --git a/src/Sentry/TransactionTracer.cs b/src/Sentry/TransactionTracer.cs index 9906ee5fa0..513716cb85 100644 --- a/src/Sentry/TransactionTracer.cs +++ b/src/Sentry/TransactionTracer.cs @@ -308,27 +308,3 @@ public void Finish(Exception exception) => SpanId, IsSampled); } - -#if NETSTANDARD2_1_OR_GREATER - -internal static class TransactionTracerExtensions -{ - internal static ISpan? SpanFromTraceData(this ITransaction transaction, Func match) - { - return transaction.TryGetSpanFromTraceData(match, out var span) - ? span - : null; - } - - internal static bool TryGetSpanFromTraceData(this ITransaction transaction, Func match, out ISpan? span) - { - span = null; - if (transaction is TransactionTracer transactionTracer) - { - span = transactionTracer.Spans.SingleOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); - } - return span is not null; - } -} - -#endif diff --git a/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs b/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs index 046b7ee416..d82a011d72 100644 --- a/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/DiagnosticSourceHelperTests.cs @@ -12,7 +12,7 @@ public void FilterNewLineValue_StringWithNewLine_SubStringAfterNewLine() var expectedText = "SELECT *...\n FROM ..."; // Act - var value = DiagnosticSourceHelper.FilterNewLineValue(text); + var value = EFDiagnosticSourceHelper.FilterNewLineValue(text); // Assert Assert.Equal(expectedText, value); @@ -22,7 +22,7 @@ public void FilterNewLineValue_StringWithNewLine_SubStringAfterNewLine() public void FilterNewLineValue_NullObject_NullString() { // Act - var value = DiagnosticSourceHelper.FilterNewLineValue(null); + var value = EFDiagnosticSourceHelper.FilterNewLineValue(null); // Assert Assert.Null(value); @@ -36,7 +36,7 @@ public void FilterNewLineValue_OneLineString_OneLineString() var expectedText = "1234"; // Act - var value = DiagnosticSourceHelper.FilterNewLineValue(text); + var value = EFDiagnosticSourceHelper.FilterNewLineValue(text); // Assert Assert.Equal(expectedText, value); @@ -50,7 +50,7 @@ public void FilterNewLineValue_EmptyString_EmptyString() var expectedText = ""; // Act - var value = DiagnosticSourceHelper.FilterNewLineValue(text); + var value = EFDiagnosticSourceHelper.FilterNewLineValue(text); // Assert Assert.Equal(expectedText, value); diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index f51b16ef5b..8d949c1dda 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -1,3 +1,4 @@ +using Microsoft.EntityFrameworkCore.Diagnostics; using Sentry.Internal.DiagnosticSource; using static Sentry.Internal.DiagnosticSource.SentryEFCoreListener; @@ -188,6 +189,26 @@ public void OnNext_ConfigureScopeInvokedOnce(string key) hub.Received(1).ConfigureScope(Arg.Any>()); } + private class FakeDiagnosticEventData + { + public FakeDiagnosticEventData(string value) { _value = value; } + private readonly string _value; + public override string ToString()=> _value; + } + + private class FakeDiagnosticConnectionEventData : FakeDiagnosticEventData + { + public FakeDiagnosticConnectionEventData(string value) : base(value) { } + public Guid ConnectionId { get; set; } = Guid.NewGuid(); + } + + private class FakeDiagnosticCommandEventData : FakeDiagnosticEventData + { + public FakeDiagnosticCommandEventData(string value) : base(value) { } + public Guid ConnectionId { get; set; } = Guid.NewGuid(); + public Guid CommandId { get; set; } = Guid.NewGuid(); + } + [Fact] public void OnNext_HappyPath_IsValid() { @@ -196,14 +217,19 @@ public void OnNext_HappyPath_IsValid() var interceptor = new SentryEFCoreListener(hub, _fixture.Options); var expectedSql = "SELECT * FROM ..."; var efSql = "ef Junk\r\nSELECT * FROM ..."; + var efConn = "db username : password"; + + var queryEventData = new FakeDiagnosticEventData(efSql); + var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); + var commandEventData = new FakeDiagnosticCommandEventData(efSql); // 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)); + interceptor.OnNext(new(EFQueryCompiling, queryEventData)); + interceptor.OnNext(new(EFQueryCompiled, queryEventData)); + interceptor.OnNext(new(EFConnectionOpening, connectionEventData)); + interceptor.OnNext(new(EFCommandExecuting, commandEventData)); + interceptor.OnNext(new(EFCommandExecuted, commandEventData)); + interceptor.OnNext(new(EFConnectionClosed, connectionEventData)); // Assert var compilerSpan = _fixture.Spans.First(s => GetValidator(EFQueryCompiling)(s)); @@ -226,7 +252,7 @@ public void OnNext_HappyPath_IsValid() // 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(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -240,15 +266,20 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() var interceptor = new SentryEFCoreListener(hub, _fixture.Options); var expectedSql = "SELECT * FROM ..."; var efSql = "ef Junk\r\nSELECT * FROM ..."; + var efConn = "db username : password"; + + var queryEventData = new FakeDiagnosticEventData(efSql); + var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); + var commandEventData = new FakeDiagnosticCommandEventData(efSql); // Act var childSpan = _fixture.Tracer.StartChild("Child Span"); - 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)); + interceptor.OnNext(new(EFQueryCompiling, queryEventData)); + interceptor.OnNext(new(EFQueryCompiled, queryEventData)); + interceptor.OnNext(new(EFConnectionOpening, connectionEventData)); + interceptor.OnNext(new(EFCommandExecuting, commandEventData)); + interceptor.OnNext(new(EFCommandExecuted, commandEventData)); + interceptor.OnNext(new(EFConnectionClosed, connectionEventData)); childSpan.Finish(); // Assert @@ -272,7 +303,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() // Check connections between spans. Assert.Equal(childSpan.SpanId, compilerSpan.ParentSpanId); Assert.Equal(childSpan.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(childSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -313,7 +344,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() // 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(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); Assert.Equal(expectedSql, commandSpan.Description); } diff --git a/test/Sentry.NLog.Tests/SentryTargetTests.cs b/test/Sentry.NLog.Tests/SentryTargetTests.cs index b1ee45d29f..946c7b38e4 100644 --- a/test/Sentry.NLog.Tests/SentryTargetTests.cs +++ b/test/Sentry.NLog.Tests/SentryTargetTests.cs @@ -140,7 +140,7 @@ public void Shutdown_DisposesSdk() { _fixture.Options.InitializeSdk = false; var target = _fixture.GetTarget(); - SimpleConfigurator.ConfigureForTargetLogging(target); + LogManager.Setup().LoadConfiguration(c => c.ForLogger().WriteTo(target)); var sut = LogManager.GetCurrentClassLogger(); From 086a8be77f10e9dc39b3edd2ccb4649878a7f0b3 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 1 Jun 2023 19:33:05 +1200 Subject: [PATCH 04/32] Refactored to use Extra instead of TraceData, for consistency with SentrySqlListener --- .../EFCommandDiagnosticSourceHelper.cs | 40 ++++++++++--------- .../EFConnectionDiagnosticSourceHelper.cs | 39 +++++++++--------- .../EFDiagnosticSourceHelper.cs | 40 +++---------------- .../EFQueryCompilerDiagnosticSourceHelper.cs | 37 +++++------------ src/Sentry/SpanTracer.cs | 8 ---- .../SentryEFCoreListenerTests.cs | 17 +++++--- 6 files changed, 69 insertions(+), 112 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index 6eb97bb887..fd148e7e56 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -12,33 +12,35 @@ internal EFCommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncL protected override string Operation => "db.query"; protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; - + private Guid? ConnectionId => DiagnosticSourceValue?.GetGuidProperty("ConnectionId"); private Guid? CommandId => DiagnosticSourceValue?.GetGuidProperty("CommandId"); - // The following would be more restrictive but harder to mock/test - // DiagnosticSourceValue?.GetType().FullName == "Microsoft.EntityFrameworkCore.Diagnostics.CommandEventData" - // ? DiagnosticSourceValue?.GetGuidProperty("CommandId") : - // null; - - private bool CorrelatedSpan(SpanTracer span) => - span.TraceData.ContainsKey(nameof(CommandId)) && - span.TraceData[nameof(CommandId)] is Guid traceCommandId && - CommandId == traceCommandId; - protected override ISpan? GetSpanReference(ITransaction transaction) + private static void SetCommandId(ISpan span, Guid? commandId) { - // Try to return a correlated span if we can find one. - if (TryGetSpanFromTraceData(transaction, CorrelatedSpan, out var correlatedSpan)) - { - return correlatedSpan; - } - return base.GetSpanReference(transaction); + Debug.Assert(commandId != Guid.Empty); + + span.SetExtra(CommandExtraKey, commandId); } + private static Guid? TryGetCommandId(ISpan span) => + span.Extra.TryGetValue(CommandExtraKey, out var key) && key is Guid guid + ? guid + : null; + + protected override ISpan? GetSpanReference(ITransaction transaction) => + CommandId is { } commandId + ? transaction.Spans + .FirstOrDefault(span => + !span.IsFinished && + span.Operation == Operation && + TryGetCommandId(span) == commandId) + : base.GetSpanReference(transaction); + protected override void SetSpanReference(ISpan span) { - if (span is SpanTracer spanTracer) + if (CommandId is { }) { - spanTracer.TraceData[nameof(CommandId)] = CommandId; + SetCommandId(span, CommandId); return; } base.SetSpanReference(span); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 241a10b1a6..d679e2bf3e 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -12,33 +12,34 @@ internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, Asy protected override string Operation => "db.connection"; protected override string Description => null!; - private Guid? ConnectionId => DiagnosticSourceValue?.GetGuidProperty("ConnectionId"); - // The following would be more restrictive but harder to mock/test - // DiagnosticSourceValue?.GetType().FullName == "Microsoft.EntityFrameworkCore.Diagnostics.ConnectionEventData" - // ? DiagnosticSourceValue?.GetGuidProperty("ConnectionId") : - // null; - - private bool CorrelatedSpan(SpanTracer span) => - span.TraceData.ContainsKey(nameof(ConnectionId)) && - span.TraceData[nameof(ConnectionId)] is Guid traceConnectionId && - ConnectionId == traceConnectionId; - protected override ISpan? GetSpanReference(ITransaction transaction) + private static void SetConnectionId(ISpan span, Guid? connectionId) { - // Try to return a correlated span if we can find one. - if (TryGetSpanFromTraceData(transaction, CorrelatedSpan, out var correlatedSpan)) - { - return correlatedSpan; - } - return base.GetSpanReference(transaction); + Debug.Assert(connectionId != Guid.Empty); + + span.SetExtra(ConnectionExtraKey, connectionId); } + private static Guid? TryGetConnectionId(ISpan span) => + span.Extra.TryGetValue(ConnectionExtraKey, out var key) && key is Guid guid + ? guid + : null; + + protected override ISpan? GetSpanReference(ITransaction transaction) => + ConnectionId is { } connectionId + ? transaction.Spans + .FirstOrDefault(span => + !span.IsFinished && + span.Operation == Operation && + TryGetConnectionId(span) == connectionId) + : base.GetSpanReference(transaction); + protected override void SetSpanReference(ISpan span) { - if (span is SpanTracer spanTracer) + if (ConnectionId is { } connectionId) { - spanTracer.TraceData[nameof(ConnectionId)] = ConnectionId; + SetConnectionId(span, connectionId); return; } base.SetSpanReference(span); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 438cfbcba6..c2c4993599 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -5,6 +5,10 @@ namespace Sentry.Internal.DiagnosticSource; // ReSharper disable once InconsistentNaming internal abstract class EFDiagnosticSourceHelper { + internal const string ConnectionExtraKey = "db.connection_id"; + internal const string CommandExtraKey = "db.command_id"; + internal const string CompiledQueryExtraKey = "db.compiled_query"; + private SentryOptions Options { get; } protected object? DiagnosticSourceValue { get; } private ITransaction? Transaction { get; set; } @@ -107,39 +111,7 @@ protected virtual void SetSpanReference(ISpan span) protected virtual ISpan? GetSpanReference(ITransaction transaction) { - Options.LogDebug($"No Span reference found when getting {Operation}. Taking the first unfinished span instead."); - return transaction.Spans - .OrderByDescending(x => x.StartTimestamp) - .FirstOrDefault(s => !s.IsFinished && s.Operation.Equals(Operation)); - } - - protected static bool TryGetSpanFromTraceData(ITransaction transaction, Func match, out ISpan? span) - { - span = null; - if (transaction is TransactionTracer transactionTracer) - { - try - { - span = transactionTracer.Spans.SingleOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); - } - catch (InvalidOperationException) - { - // If SingleOrDefault matches no element or more than one element - return false; - } - } - return span is not null; - } - - protected static bool TryGetFirstSpanFromTraceData(ITransaction transaction, Func match, out ISpan? span) - { - span = null; - if (transaction is TransactionTracer transactionTracer) - { - span = transactionTracer.Spans - .OrderBy(s => s.StartTimestamp) - .FirstOrDefault(s => s is SpanTracer spanTracer && match(spanTracer)); - } - return span is not null; + Options.LogDebug($"No Span reference found when getting {Operation}."); + return null; } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs index 5b972479c0..2460567e83 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs @@ -13,31 +13,16 @@ internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, protected override string Operation => "db.query.compile"; protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; - private string QueryExpression => Description; + /// + /// Unfortunately there's nothing we can use as the the corelation id for compiled query events, so we just return + /// the first unfinished span for this operation. + /// + protected override ISpan? GetSpanReference(ITransaction transaction) => + transaction.Spans .FirstOrDefault(span => !span.IsFinished && span.Operation == Operation); - private bool SameExpression(SpanTracer span) => - span.TraceData.ContainsKey(nameof(QueryExpression)) && - span.TraceData[nameof(QueryExpression)] is string traceQueryExpression && - QueryExpression == traceQueryExpression; - - protected override ISpan? GetSpanReference(ITransaction transaction) - { - // In the case of Query Compilation events, we don't get any correlation id from the diagnostic data. The best - // we can do is to use the query expression. This isn't guaranteed to be unique so we grab the first match. - if (TryGetFirstSpanFromTraceData(transaction, SameExpression, out var looselyCorrelatedSpan)) - { - return looselyCorrelatedSpan; - } - return base.GetSpanReference(transaction); - } - - protected override void SetSpanReference(ISpan span) - { - if (span is SpanTracer spanTracer) - { - spanTracer.TraceData[nameof(QueryExpression)] = QueryExpression; - return; - } - base.SetSpanReference(span); - } + /// + /// We don't have a correlation id for compiled query events. This overload just prevents the base class from + /// logging a debug message. + /// + protected override void SetSpanReference(ISpan span) { } } diff --git a/src/Sentry/SpanTracer.cs b/src/Sentry/SpanTracer.cs index 442b4f2a3b..66d4aa10ae 100644 --- a/src/Sentry/SpanTracer.cs +++ b/src/Sentry/SpanTracer.cs @@ -63,14 +63,6 @@ public void UnsetTag(string key) => /// public void SetExtra(string key, object? value) => _data[key] = value; - /// - /// Can be used to store data for the duration of the Trace. This data is not sent to Sentry. - /// - /// For example, information from a DiagnosticSource event can be stored here and used to correlate - /// with subsequent DiagnosticSource events in order to construct an accurate Span hierarchy. - /// - internal ConcurrentDictionary TraceData = new(); - /// /// Initializes an instance of . /// diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 8d949c1dda..c75a887f3e 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -317,14 +317,19 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() var interceptor = new SentryEFCoreListener(hub, _fixture.Options); var expectedSql = "SELECT * FROM ..."; var efSql = "ef Junk\r\nSELECT * FROM ..."; + var efConn = "db username : password"; + + var queryEventData = new FakeDiagnosticEventData(efSql); + var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); + var commandEventData = new FakeDiagnosticCommandEventData(efSql); // 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)); + interceptor.OnNext(new(EFQueryCompiling, queryEventData)); + interceptor.OnNext(new(EFQueryCompiled, queryEventData)); + interceptor.OnNext(new(EFConnectionOpening, connectionEventData)); + interceptor.OnNext(new(EFCommandExecuting, commandEventData)); + interceptor.OnNext(new(EFCommandFailed, commandEventData)); + interceptor.OnNext(new(EFConnectionClosed, connectionEventData)); // Assert var compilerSpan = _fixture.Spans.First(s => GetValidator(EFQueryCompiling)(s)); From fe73cbf56cdc0366ffec17ac2d6476e12fd27912 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 1 Jun 2023 19:44:33 +1200 Subject: [PATCH 05/32] Update CHANGELOG.md --- CHANGELOG.md | 1 - 1 file changed, 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b9dec15627..07a5f1d552 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,7 +7,6 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) - Fix/db spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) -- - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. - The device architecture (x64, arm64, etc.) is now reported From f1e9785d36ce0707e0d57b9387de0ad2fcb7a4c8 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 1 Jun 2023 20:57:28 +1200 Subject: [PATCH 06/32] Update SqlListenerTests.RecordsEf.Net4_8.verified.txt --- .../SqlListenerTests.RecordsEf.Net4_8.verified.txt | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt index be78366e86..5c2e93bf15 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt @@ -55,7 +55,10 @@ SELECT [Id] FROM [TestEntities] WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();, Status: Ok, - IsSampled: true + IsSampled: true, + Extra: { + db.command_id: Guid_1 + } }, { IsFinished: true, @@ -64,7 +67,10 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();, SELECT [t].[Id], [t].[Property] FROM [TestEntities] AS [t], Status: Ok, - IsSampled: true + IsSampled: true, + Extra: { + db.command_id: Guid_2 + } } ], IsFinished: true From 2ac37af5e96f4d14ef85b2c3f6b699b47c1e8b71 Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Thu, 1 Jun 2023 14:05:34 -0700 Subject: [PATCH 07/32] Undo csproj whitespace --- .../Sentry.DiagnosticSource.csproj | 2 +- src/Sentry/Sentry.csproj | 34 ++++++++++++++----- 2 files changed, 27 insertions(+), 9 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj index e0d67dfaeb..75ccb002d1 100644 --- a/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj +++ b/src/Sentry.DiagnosticSource/Sentry.DiagnosticSource.csproj @@ -16,7 +16,7 @@ - + diff --git a/src/Sentry/Sentry.csproj b/src/Sentry/Sentry.csproj index ce310b87d7..d36cee6003 100644 --- a/src/Sentry/Sentry.csproj +++ b/src/Sentry/Sentry.csproj @@ -93,17 +93,35 @@ <_OSArchitecture>$([System.Runtime.InteropServices.RuntimeInformation]::OSArchitecture) - - - - - - - + + + + + + + - + From 6b731f04ccfacfdd9a6e85d77ec0c63450264127 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 2 Jun 2023 10:43:17 +1200 Subject: [PATCH 08/32] Apply suggestions from code review Co-authored-by: Matt Johnson-Pint --- CHANGELOG.md | 2 +- .../DiagnosticSource/EFCommandDiagnosticSourceHelper.cs | 4 ++-- .../Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs | 6 +++--- .../EFQueryCompilerDiagnosticSourceHelper.cs | 2 +- 4 files changed, 7 insertions(+), 7 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 07a5f1d552..3996a07c22 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,7 +6,7 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) -- Fix/db spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) +- Fix db connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. - The device architecture (x64, arm64, etc.) is now reported diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index fd148e7e56..f9224334f1 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -38,9 +38,9 @@ CommandId is { } commandId protected override void SetSpanReference(ISpan span) { - if (CommandId is { }) + if (CommandId is { } commandId) { - SetCommandId(span, CommandId); + SetCommandId(span, commandId); return; } base.SetSpanReference(span); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index c2c4993599..d031f47890 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -91,15 +91,15 @@ private void LogTransactionSpans() } /// - /// Finds an appropriate parent for EF diagnostic spans. Note that in our implementaion we're "flattening" these. + /// Finds an appropriate parent for EF diagnostic spans. Note that in our implementation we're "flattening" these. /// Spans from and /// will both have the same parent as those of . /// /// We've done this for two reasons: /// 1. We could show these underneath the relevant connection, but each command often gets it's own connection which /// makes the resulting waterfall diagram hard to read. - /// 2. Sentry has a performance to errors feature which detects n + 1 problems on OM frameworks... but this only - /// works if all of the "n" queries have the same parent span in the transaction. Again, since queries ofen run + /// 2. Sentry has a performance to errors feature which detects n + 1 problems on ORM frameworks... but this only + /// works if all of the "n" queries have the same parent span in the transaction. Again, since queries often run /// on their own connection, if we wrap each query in a connection span, it breaks the performance error handling /// private ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs index 2460567e83..8da8441200 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs @@ -14,7 +14,7 @@ internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; /// - /// Unfortunately there's nothing we can use as the the corelation id for compiled query events, so we just return + /// Unfortunately there's nothing we can use as the correlation id for compiled query events, so we just return /// the first unfinished span for this operation. /// protected override ISpan? GetSpanReference(ITransaction transaction) => From 852e16003ca280f929237014be0dbcf1963e320a Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 2 Jun 2023 11:56:59 +1200 Subject: [PATCH 09/32] Refactored SentryEFCoreListener so DiagnosticSourceHelpers are created only once --- .../EFCommandDiagnosticSourceHelper.cs | 33 ++++++----- .../EFConnectionDiagnosticSourceHelper.cs | 30 +++++----- .../EFDiagnosticSourceHelper.cs | 58 ++++++------------- .../EFQueryCompilerDiagnosticSourceHelper.cs | 22 +++---- .../DiagnosticSource/SentryEFCoreListener.cs | 31 ++++------ .../SentryEFCoreListenerTests.cs | 2 +- 6 files changed, 72 insertions(+), 104 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index fd148e7e56..4f30397a87 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -1,19 +1,17 @@ +using Sentry.Extensibility; using Sentry.Internal.Extensions; namespace Sentry.Internal.DiagnosticSource; -// ReSharper disable once InconsistentNaming internal class EFCommandDiagnosticSourceHelper : EFDiagnosticSourceHelper { - internal EFCommandDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, diagnosticSourceValue) + internal EFCommandDiagnosticSourceHelper(IHub hub, SentryOptions options) : base(hub, options) { } protected override string Operation => "db.query"; - protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; - private Guid? ConnectionId => DiagnosticSourceValue?.GetGuidProperty("ConnectionId"); - private Guid? CommandId => DiagnosticSourceValue?.GetGuidProperty("CommandId"); + protected override string Description(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; + private static Guid? GetCommandId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("CommandId"); private static void SetCommandId(ISpan span, Guid? commandId) { @@ -27,22 +25,27 @@ private static void SetCommandId(ISpan span, Guid? commandId) ? guid : null; - protected override ISpan? GetSpanReference(ITransaction transaction) => - CommandId is { } commandId - ? transaction.Spans + protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) + { + if (GetCommandId(diagnosticSourceValue) is { } commandId) + { + return transaction.Spans .FirstOrDefault(span => !span.IsFinished && span.Operation == Operation && - TryGetCommandId(span) == commandId) - : base.GetSpanReference(transaction); + TryGetCommandId(span) == commandId); + } + Options.LogWarning("No correlation id found for {1}.", Operation); + return null; + } - protected override void SetSpanReference(ISpan span) + protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) { - if (CommandId is { }) + if (GetCommandId(diagnosticSourceValue) is { } commandId) { - SetCommandId(span, CommandId); + SetCommandId(span, commandId); return; } - base.SetSpanReference(span); + Options.LogWarning("No correlation id can be set for {1}.", Operation); } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index d679e2bf3e..07a5cd94dc 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -1,18 +1,17 @@ +using Sentry.Extensibility; using Sentry.Internal.Extensions; namespace Sentry.Internal.DiagnosticSource; -// ReSharper disable once InconsistentNaming internal class EFConnectionDiagnosticSourceHelper : EFDiagnosticSourceHelper { - internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, diagnosticSourceValue) + internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : base(hub, options) { } protected override string Operation => "db.connection"; - protected override string Description => null!; - private Guid? ConnectionId => DiagnosticSourceValue?.GetGuidProperty("ConnectionId"); + protected override string Description(object? diagnosticSourceValue) => null!; + private static Guid? GetConnectionId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("ConnectionId"); private static void SetConnectionId(ISpan span, Guid? connectionId) { @@ -26,22 +25,27 @@ private static void SetConnectionId(ISpan span, Guid? connectionId) ? guid : null; - protected override ISpan? GetSpanReference(ITransaction transaction) => - ConnectionId is { } connectionId - ? transaction.Spans + protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) + { + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) + { + return transaction.Spans .FirstOrDefault(span => !span.IsFinished && span.Operation == Operation && - TryGetConnectionId(span) == connectionId) - : base.GetSpanReference(transaction); + TryGetConnectionId(span) == connectionId); + } + Options.LogWarning("No correlation id found for {1}.", Operation); + return null; + } - protected override void SetSpanReference(ISpan span) + protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) { - if (ConnectionId is { } connectionId) + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) { SetConnectionId(span, connectionId); return; } - base.SetSpanReference(span); + Options.LogWarning("No {0} found when adding {1} Span.", "ConnectionId", Operation); } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index c2c4993599..0169e8f3d2 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -2,27 +2,24 @@ namespace Sentry.Internal.DiagnosticSource; -// ReSharper disable once InconsistentNaming internal abstract class EFDiagnosticSourceHelper { internal const string ConnectionExtraKey = "db.connection_id"; internal const string CommandExtraKey = "db.command_id"; - internal const string CompiledQueryExtraKey = "db.compiled_query"; - private SentryOptions Options { get; } - protected object? DiagnosticSourceValue { get; } - private ITransaction? Transaction { get; set; } + protected SentryOptions Options { get; } + //protected object? DiagnosticSourceValue { get; } + private ITransaction? Transaction { get; } protected abstract string Operation { get; } - protected abstract string Description { get; } + protected abstract string Description(object? diagnosticSourceValue); - internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options, object? diagnosticSourceValue) + internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) { Options = options; - DiagnosticSourceValue = diagnosticSourceValue; Transaction = hub.GetTransactionIfSampled(); } - internal void AddSpan() + internal void AddSpan(object? diagnosticSourceValue) { Options.LogDebug($"(Sentry add span {Operation})"); LogTransactionSpans(); @@ -31,13 +28,16 @@ internal void AddSpan() return; } - var parent = GetParentSpan(Transaction); - var child = parent.StartChild(Operation, Description); + // We "flatten" the EF spans so that they all have the same parent span, for two reasons: + // 1. Each command typically gets it's own connection, which makes the resulting waterfall diagram hard to read. + // 2. Sentry's performance errors functionality only works when all queries have the same parent span. + var parent = Transaction.GetDbParentSpan(); + var child = parent.StartChild(Operation, Description(diagnosticSourceValue)); - SetSpanReference(child); + SetSpanReference(child, diagnosticSourceValue); } - internal void FinishSpan(SpanStatus status) + internal void FinishSpan(object? diagnosticSourceValue, SpanStatus status) { if (Transaction == null) { @@ -47,14 +47,13 @@ internal void FinishSpan(SpanStatus status) Options.LogDebug($"(Sentry finish span {Operation})"); LogTransactionSpans(); - var sourceSpan = GetSpanReference(Transaction); + var sourceSpan = GetSpanReference(Transaction, diagnosticSourceValue); if (sourceSpan == null) { - Options.LogWarning("Trying to close a span that was already garbage collected. {0}", Operation); + Options.LogWarning("Tried to close {0} span but no matching span could be found.", Operation); return; } - - sourceSpan.Finish(status); + sourceSpan?.Finish(status); } private void LogTransactionSpans() @@ -90,28 +89,7 @@ private void LogTransactionSpans() return str?[(str.IndexOf('\n') + 1)..]; } - /// - /// Finds an appropriate parent for EF diagnostic spans. Note that in our implementaion we're "flattening" these. - /// Spans from and - /// will both have the same parent as those of . - /// - /// We've done this for two reasons: - /// 1. We could show these underneath the relevant connection, but each command often gets it's own connection which - /// makes the resulting waterfall diagram hard to read. - /// 2. Sentry has a performance to errors feature which detects n + 1 problems on OM frameworks... but this only - /// works if all of the "n" queries have the same parent span in the transaction. Again, since queries ofen run - /// on their own connection, if we wrap each query in a connection span, it breaks the performance error handling - /// - private ISpan GetParentSpan(ITransaction transaction) => transaction.GetDbParentSpan(); - - protected virtual void SetSpanReference(ISpan span) - { - Options.LogDebug($"No Span reference found when adding {Operation} Span."); - } + protected abstract void SetSpanReference(ISpan span, object? diagnosticSourceValue); - protected virtual ISpan? GetSpanReference(ITransaction transaction) - { - Options.LogDebug($"No Span reference found when getting {Operation}."); - return null; - } + protected abstract ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue); } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs index 2460567e83..70045587f3 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs @@ -1,28 +1,22 @@ -using Sentry.Internal.Extensions; - namespace Sentry.Internal.DiagnosticSource; -// ReSharper disable once InconsistentNaming internal class EFQueryCompilerDiagnosticSourceHelper : EFDiagnosticSourceHelper { - internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options, AsyncLocal> spanLocal, object? diagnosticSourceValue) - : base(hub, options, diagnosticSourceValue) + internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options) : base(hub, options) { } protected override string Operation => "db.query.compile"; - protected override string Description => FilterNewLineValue(DiagnosticSourceValue) ?? string.Empty; + protected override string Description(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; /// - /// Unfortunately there's nothing we can use as the the corelation id for compiled query events, so we just return - /// the first unfinished span for this operation. + /// We don't have a correlation id for compiled query events. We just return the first unfinished query compile span. /// - protected override ISpan? GetSpanReference(ITransaction transaction) => + protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) => transaction.Spans .FirstOrDefault(span => !span.IsFinished && span.Operation == Operation); - /// - /// We don't have a correlation id for compiled query events. This overload just prevents the base class from - /// logging a debug message. - /// - protected override void SetSpanReference(ISpan span) { } + protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) + { + // We don't have a correlation id for compiled query events. + } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs index ee11bc9852..1d9f689762 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs @@ -28,10 +28,6 @@ internal class SentryEFCoreListener : IObserver> private readonly IHub _hub; private readonly SentryOptions _options; - private readonly AsyncLocal> _spansCompilerLocal = new(); - private readonly AsyncLocal> _spansQueryLocal = new(); - private readonly AsyncLocal> _spansConnectionLocal = new(); - private bool _logConnectionEnabled = true; private bool _logQueryEnabled = true; @@ -49,50 +45,43 @@ public void OnCompleted() { } public void OnError(Exception error) { } - private EFQueryCompilerDiagnosticSourceHelper QueryCompilerDiagnosticSourceHelper(object? diagnosticsSourceValue) => - new(_hub, _options, _spansCompilerLocal, diagnosticsSourceValue); + private EFQueryCompilerDiagnosticSourceHelper QueryCompilerDiagnosticSourceHelper => new(_hub, _options); - private EFConnectionDiagnosticSourceHelper ConnectionDiagnosticSourceHelper(object? diagnosticsSourceValue) => - new(_hub, _options, _spansConnectionLocal, diagnosticsSourceValue); + private EFConnectionDiagnosticSourceHelper ConnectionDiagnosticSourceHelper => new(_hub, _options); - private EFCommandDiagnosticSourceHelper CommandDiagnosticSourceHelper(object? diagnosticsSourceValue) => - new(_hub, _options, _spansQueryLocal, diagnosticsSourceValue); + private EFCommandDiagnosticSourceHelper CommandDiagnosticSourceHelper => new(_hub, _options); public void OnNext(KeyValuePair value) { try { - // Because we have to support the .NET framework, we can't get at strongly typed diagnostic source events. - // We do know they're objects, that can be converted to strings though... and we can get the correlation - // data we need from there by parsing the string. Not as reliable, but works against all frameworks. - var diagnosticSourceValue = value.Value?.ToString(); switch (value.Key) { // Query compiler span case EFQueryStartCompiling or EFQueryCompiling: - QueryCompilerDiagnosticSourceHelper(value.Value).AddSpan(); + QueryCompilerDiagnosticSourceHelper.AddSpan(value.Value); break; case EFQueryCompiled: - QueryCompilerDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); + QueryCompilerDiagnosticSourceHelper.FinishSpan(value.Value, SpanStatus.Ok); break; // Connection span (A transaction may or may not show a connection with it.) case EFConnectionOpening when _logConnectionEnabled: - ConnectionDiagnosticSourceHelper(value.Value).AddSpan(); + ConnectionDiagnosticSourceHelper.AddSpan(value.Value); break; case EFConnectionClosed when _logConnectionEnabled: - ConnectionDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); + ConnectionDiagnosticSourceHelper.FinishSpan(value.Value, SpanStatus.Ok); break; // Query Execution span case EFCommandExecuting when _logQueryEnabled: - CommandDiagnosticSourceHelper(value.Value).AddSpan(); + CommandDiagnosticSourceHelper.AddSpan(value.Value); break; case EFCommandFailed when _logQueryEnabled: - CommandDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.InternalError); + CommandDiagnosticSourceHelper.FinishSpan(value.Value, SpanStatus.InternalError); break; case EFCommandExecuted when _logQueryEnabled: - CommandDiagnosticSourceHelper(value.Value).FinishSpan(SpanStatus.Ok); + CommandDiagnosticSourceHelper.FinishSpan(value.Value, SpanStatus.Ok); break; } } diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index c75a887f3e..e8b43a9e22 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -415,7 +415,7 @@ public void OnNext_TakeSpanWithoutSpan_ShowsGarbageCollectorError(string operati // Assert _fixture.Options.DiagnosticLogger.Received(1)? - .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), + .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Tried to close {0} span but no matching span could be found."), null, Arg.Any()); } } From 5dc70106ba64b5ab1f70603b3fcc8e28e28fa6c1 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 2 Jun 2023 16:00:15 +1200 Subject: [PATCH 10/32] Implemented fix for DB Connection spans presented poorly #2144 --- .../EFConnectionDiagnosticSourceHelper.cs | 31 +++++++ .../EFDiagnosticSourceHelper.cs | 5 +- .../DiagnosticSource/SentryEFCoreListener.cs | 2 +- src/Sentry/SpanTracer.cs | 10 +++ .../SentryEFCoreListenerTests.cs | 88 +++++++++++++++++++ 5 files changed, 132 insertions(+), 4 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 07a5cd94dc..d0be4229c1 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -48,4 +48,35 @@ protected override void SetSpanReference(ISpan span, object? diagnosticSourceVal } Options.LogWarning("No {0} found when adding {1} Span.", "ConnectionId", Operation); } + + /// + /// EF Connections are often pooled. If we see the same connection multiple times, we reuse the span so that it + /// shows as a single connection in the resulting waterfall chart on Sentry. + /// + /// + internal void AddOrReuseSpan(object? diagnosticSourceValue) + { + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) + { + Options.LogDebug($"Checking for span to reuse for {Operation} with connection id {connectionId}"); + LogTransactionSpans(); + if (Transaction is { } transaction) + { + var spanWithConnectionId = transaction.Spans + .FirstOrDefault(span => + span.Operation == Operation && + TryGetConnectionId(span) == connectionId); + if (spanWithConnectionId is SpanTracer existingSpan) + { + // OK we've seen this connection before... let's reuse it + Options.LogDebug($"Reusing span for {Operation} with connection id {connectionId}"); + existingSpan.Unfinish(); + return; + } + } + } + + // If we can't find a span to reuse then we'll add a new one instead + base.AddSpan(diagnosticSourceValue); + } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 0169e8f3d2..1e0b4a249d 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -8,8 +8,7 @@ internal abstract class EFDiagnosticSourceHelper internal const string CommandExtraKey = "db.command_id"; protected SentryOptions Options { get; } - //protected object? DiagnosticSourceValue { get; } - private ITransaction? Transaction { get; } + protected ITransaction? Transaction { get; } protected abstract string Operation { get; } protected abstract string Description(object? diagnosticSourceValue); @@ -56,7 +55,7 @@ internal void FinishSpan(object? diagnosticSourceValue, SpanStatus status) sourceSpan?.Finish(status); } - private void LogTransactionSpans() + protected void LogTransactionSpans() { if (Transaction == null) { diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs index 1d9f689762..883e97ecc3 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs @@ -67,7 +67,7 @@ public void OnNext(KeyValuePair value) // Connection span (A transaction may or may not show a connection with it.) case EFConnectionOpening when _logConnectionEnabled: - ConnectionDiagnosticSourceHelper.AddSpan(value.Value); + ConnectionDiagnosticSourceHelper.AddOrReuseSpan(value.Value); break; case EFConnectionClosed when _logConnectionEnabled: ConnectionDiagnosticSourceHelper.FinishSpan(value.Value, SpanStatus.Ok); diff --git a/src/Sentry/SpanTracer.cs b/src/Sentry/SpanTracer.cs index 66d4aa10ae..876cc6126a 100644 --- a/src/Sentry/SpanTracer.cs +++ b/src/Sentry/SpanTracer.cs @@ -84,6 +84,16 @@ public SpanTracer( /// public ISpan StartChild(string operation) => Transaction.StartChild(SpanId, operation); + /// + /// Used to mark a span as unfinished when it was previously marked as finished. This allows us to reuse spans for + /// DB Connections that get reused by the underlying connection pool + /// + internal void Unfinish() + { + Status = null; + EndTimestamp = null; + } + /// public void Finish() { diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index e8b43a9e22..a734715dbe 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -378,6 +378,94 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCompiler() Assert.Equal(expectedSql, compilerSpan.Description); } + [Fact] + public void OnNext_Same_Connections_Consolidated() + { + // Arrange + var hub = _fixture.Hub; + var interceptor = new SentryEFCoreListener(hub, _fixture.Options); + var efSql = "ef Junk\r\nSELECT * FROM ..."; + var efConn = "db username : password"; + + // Fake a connection pool with two connections + var connectionA = new FakeDiagnosticConnectionEventData(efConn); + var connectionB = new FakeDiagnosticConnectionEventData(efConn); + var commandA = new FakeDiagnosticCommandEventData(efSql); + var commandB = new FakeDiagnosticCommandEventData(efSql); + var commandC = new FakeDiagnosticCommandEventData(efSql); + + void Pause() => Thread.Sleep(100); + + // Act + interceptor.OnNext(new(EFConnectionOpening, connectionA)); + Pause(); + interceptor.OnNext(new(EFCommandExecuting, commandA)); + interceptor.OnNext(new(EFCommandExecuted, commandA)); + interceptor.OnNext(new(EFConnectionClosed, connectionA)); + + interceptor.OnNext(new(EFConnectionOpening, connectionA)); + + // These are for Connection B... interleaved somewhat + interceptor.OnNext(new(EFConnectionOpening, connectionB)); + Pause(); + interceptor.OnNext(new(EFCommandExecuting, commandB)); + interceptor.OnNext(new(EFCommandExecuted, commandB)); + + interceptor.OnNext(new(EFCommandExecuting, commandC)); + // These are for Connection B... interleaved somewhat + interceptor.OnNext(new(EFConnectionClosed, connectionB)); + + Pause(); // To make sure we can distinguish between when the two connections finish + interceptor.OnNext(new(EFCommandExecuted, commandC)); + interceptor.OnNext(new(EFConnectionClosed, connectionA)); + + // Assert + bool IsDbSpan(ISpan s) => s.Operation == "db.connection"; + bool IsCommandSpan(ISpan s) => s.Operation == "db.query"; + Func forConnection = (s, e) => + s.Extra.ContainsKey(EFDiagnosticSourceHelper.ConnectionExtraKey) + && s.Extra[EFDiagnosticSourceHelper.ConnectionExtraKey] is Guid connectionId + && connectionId == e.ConnectionId; + Func forCommand = (s, e) => + s.Extra.ContainsKey(EFDiagnosticSourceHelper.CommandExtraKey) + && s.Extra[EFDiagnosticSourceHelper.CommandExtraKey] is Guid commandId + && commandId == e.CommandId; + + using (new AssertionScope()) + { + var dbSpans = _fixture.Spans.Where(IsDbSpan).ToArray(); + dbSpans.Count().Should().Be(2); + dbSpans.Should().Contain(s => forConnection(s, connectionA)); + dbSpans.Should().Contain(s => forConnection(s, connectionB)); + + var commandSpans = _fixture.Spans.Where(IsCommandSpan).ToArray(); + commandSpans.Count().Should().Be(3); + commandSpans.Should().Contain(s => forCommand(s, commandA)); + commandSpans.Should().Contain(s => forCommand(s, commandB)); + commandSpans.Should().Contain(s => forCommand(s, commandC)); + + var connectionASpan = dbSpans.Single(s => forConnection(s, connectionA)); + var connectionBSpan = dbSpans.Single(s => forConnection(s, connectionB)); + var commandASpan = commandSpans.Single(s => forCommand(s, commandA)); + var commandBSpan = commandSpans.Single(s => forCommand(s, commandB)); + var commandCSpan = commandSpans.Single(s => forCommand(s, commandC)); + + // Commands for connectionA should take place after it starts and before it finishes + connectionASpan.StartTimestamp.Should().BeBefore(commandASpan.StartTimestamp); + connectionASpan.StartTimestamp.Should().BeBefore(commandCSpan.StartTimestamp); + connectionASpan.EndTimestamp.Should().BeAfter(commandASpan.EndTimestamp ?? DateTimeOffset.MinValue); + connectionASpan.EndTimestamp.Should().BeAfter(commandCSpan.EndTimestamp ?? DateTimeOffset.MinValue); + + // Commands for connectionB should take place after it starts and before it finishes + connectionBSpan.StartTimestamp.Should().BeBefore(commandBSpan.StartTimestamp); + connectionBSpan.EndTimestamp.Should().BeAfter(commandBSpan.EndTimestamp ?? DateTimeOffset.MinValue); + + // Connection B starts after Connection A and finishes before Connection A + connectionBSpan.StartTimestamp.Should().BeAfter(connectionASpan.StartTimestamp); + connectionBSpan.EndTimestamp.Should().BeBefore(connectionASpan.EndTimestamp ?? DateTimeOffset.MinValue); + } + } + [Fact] public void OnNext_ThrowsException_ExceptionIsolated() { From 945393c9f82a69a7f1e64e7594b06a6551006fc4 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 2 Jun 2023 16:05:52 +1200 Subject: [PATCH 11/32] Update CHANGELOG.md --- CHANGELOG.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fd484e6fc4..017524239a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,7 +6,8 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) -- Fix db connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) +- DB connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) +- DB Connection spans presented poorly ([#2409](https://github.com/getsentry/sentry-dotnet/pull/2409)) - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. - The device architecture (x64, arm64, etc.) is now reported From fa21697cef407d94e796107a330623827621a0bd Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 2 Jun 2023 16:51:09 +1200 Subject: [PATCH 12/32] Fixed timing in OnNext_Same_Connections_Consolidated so we can reliably compare TimeStamps --- .../SentryEFCoreListenerTests.cs | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index a734715dbe..7f7c11b909 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -1,5 +1,5 @@ -using Microsoft.EntityFrameworkCore.Diagnostics; using Sentry.Internal.DiagnosticSource; +using Microsoft.EntityFrameworkCore.Diagnostics; using static Sentry.Internal.DiagnosticSource.SentryEFCoreListener; namespace Sentry.DiagnosticSource.Tests; @@ -394,7 +394,7 @@ public void OnNext_Same_Connections_Consolidated() var commandB = new FakeDiagnosticCommandEventData(efSql); var commandC = new FakeDiagnosticCommandEventData(efSql); - void Pause() => Thread.Sleep(100); + void Pause() => Thread.Sleep(200); // Act interceptor.OnNext(new(EFConnectionOpening, connectionA)); @@ -412,11 +412,13 @@ public void OnNext_Same_Connections_Consolidated() interceptor.OnNext(new(EFCommandExecuted, commandB)); interceptor.OnNext(new(EFCommandExecuting, commandC)); + // These are for Connection B... interleaved somewhat + Pause(); interceptor.OnNext(new(EFConnectionClosed, connectionB)); - Pause(); // To make sure we can distinguish between when the two connections finish interceptor.OnNext(new(EFCommandExecuted, commandC)); + Pause(); interceptor.OnNext(new(EFConnectionClosed, connectionA)); // Assert From ec44c6b2081a6ced7df4724bbbcc3008128afe5a Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Tue, 6 Jun 2023 11:30:20 +1200 Subject: [PATCH 13/32] Moved db.query spans back under the associated db.connection --- .../EFCommandDiagnosticSourceHelper.cs | 25 +++++++++++++++++++ .../EFConnectionDiagnosticSourceHelper.cs | 13 ---------- .../EFDiagnosticSourceHelper.cs | 19 +++++++++++++- .../SentryEFCoreListenerTests.cs | 25 +++++++++++++------ 4 files changed, 60 insertions(+), 22 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index 4f30397a87..d52a768c5b 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -25,6 +25,31 @@ private static void SetCommandId(ISpan span, Guid? commandId) ? guid : null; + protected override ISpan GetParentSpan(ITransaction transaction, object? diagnosticSourceValue) + { + ISpan? parentSpan = null; + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) + { + parentSpan = transaction.Spans + .FirstOrDefault(span => + !span.IsFinished && + span.Operation == "db.connection" && + TryGetConnectionId(span) == connectionId); + if (parentSpan is { }) + { + return parentSpan; + } + Options.LogWarning("Unable to locate query parent span. No Span found with db connection id {1}.", connectionId); + return base.GetParentSpan(transaction, diagnosticSourceValue); + } + else + { + Options.LogWarning("Unable to locate query parent span. diagnostic source did not contain a db connection id."); + return base.GetParentSpan(transaction, diagnosticSourceValue); + } + } + + protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { if (GetCommandId(diagnosticSourceValue) is { } commandId) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index d0be4229c1..72cf3b2961 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -11,19 +11,6 @@ internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : b protected override string Operation => "db.connection"; protected override string Description(object? diagnosticSourceValue) => null!; - private static Guid? GetConnectionId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("ConnectionId"); - - private static void SetConnectionId(ISpan span, Guid? connectionId) - { - Debug.Assert(connectionId != Guid.Empty); - - span.SetExtra(ConnectionExtraKey, connectionId); - } - - private static Guid? TryGetConnectionId(ISpan span) => - span.Extra.TryGetValue(ConnectionExtraKey, out var key) && key is Guid guid - ? guid - : null; protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 1e0b4a249d..0571dc7d6b 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -1,4 +1,5 @@ using Sentry.Extensibility; +using Sentry.Internal.Extensions; namespace Sentry.Internal.DiagnosticSource; @@ -18,6 +19,20 @@ internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) Transaction = hub.GetTransactionIfSampled(); } + protected static Guid? TryGetConnectionId(ISpan span) => + span.Extra.TryGetValue(ConnectionExtraKey, out var key) && key is Guid guid + ? guid + : null; + + protected static Guid? GetConnectionId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("ConnectionId"); + + protected static void SetConnectionId(ISpan span, Guid? connectionId) + { + Debug.Assert(connectionId != Guid.Empty); + + span.SetExtra(ConnectionExtraKey, connectionId); + } + internal void AddSpan(object? diagnosticSourceValue) { Options.LogDebug($"(Sentry add span {Operation})"); @@ -30,12 +45,14 @@ internal void AddSpan(object? diagnosticSourceValue) // We "flatten" the EF spans so that they all have the same parent span, for two reasons: // 1. Each command typically gets it's own connection, which makes the resulting waterfall diagram hard to read. // 2. Sentry's performance errors functionality only works when all queries have the same parent span. - var parent = Transaction.GetDbParentSpan(); + var parent = GetParentSpan(Transaction, diagnosticSourceValue); var child = parent.StartChild(Operation, Description(diagnosticSourceValue)); SetSpanReference(child, diagnosticSourceValue); } + protected virtual ISpan GetParentSpan(ITransaction transaction, object? diagnosticSourceValue) => transaction.GetDbParentSpan(); + internal void FinishSpan(object? diagnosticSourceValue, SpanStatus status) { if (Transaction == null) diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 7f7c11b909..349ca27d1a 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -204,8 +204,17 @@ public FakeDiagnosticConnectionEventData(string value) : base(value) { } private class FakeDiagnosticCommandEventData : FakeDiagnosticEventData { - public FakeDiagnosticCommandEventData(string value) : base(value) { } - public Guid ConnectionId { get; set; } = Guid.NewGuid(); + public FakeDiagnosticCommandEventData(string value) : base(value) + { + ConnectionId = new Guid(); + } + + public FakeDiagnosticCommandEventData(Guid connectionId, string value) : base(value) + { + ConnectionId = connectionId; + } + + public Guid ConnectionId { get; set; } public Guid CommandId { get; set; } = Guid.NewGuid(); } @@ -221,7 +230,7 @@ public void OnNext_HappyPath_IsValid() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); // Act interceptor.OnNext(new(EFQueryCompiling, queryEventData)); @@ -252,7 +261,7 @@ public void OnNext_HappyPath_IsValid() // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -270,7 +279,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); // Act var childSpan = _fixture.Tracer.StartChild("Child Span"); @@ -303,7 +312,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() // Check connections between spans. Assert.Equal(childSpan.SpanId, compilerSpan.ParentSpanId); Assert.Equal(childSpan.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(childSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -321,7 +330,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); // Act interceptor.OnNext(new(EFQueryCompiling, queryEventData)); @@ -349,7 +358,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); Assert.Equal(expectedSql, commandSpan.Description); } From fa0f4311f8938e9b8b6091319a9c559df420888e Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Tue, 6 Jun 2023 12:16:35 +1200 Subject: [PATCH 14/32] EFConnectionDiagnosticSourceHelper now uses the "Connection.Database" as a description --- .../EFConnectionDiagnosticSourceHelper.cs | 3 +- .../Internal/Extensions/MiscExtensions.cs | 20 ++++- .../Extensions/MiscExtensionsTests.cs | 74 +++++++++++++++++++ 3 files changed, 94 insertions(+), 3 deletions(-) create mode 100644 test/Sentry.Tests/Internals/Extensions/MiscExtensionsTests.cs diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 72cf3b2961..4dd7223d56 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -10,7 +10,8 @@ internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : b } protected override string Operation => "db.connection"; - protected override string Description(object? diagnosticSourceValue) => null!; + protected override string Description(object? diagnosticSourceValue) => + diagnosticSourceValue?.GetStringProperty("Connection.Database") ?? null!; protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { diff --git a/src/Sentry/Internal/Extensions/MiscExtensions.cs b/src/Sentry/Internal/Extensions/MiscExtensions.cs index 9fe0e44813..15f28dd757 100644 --- a/src/Sentry/Internal/Extensions/MiscExtensions.cs +++ b/src/Sentry/Internal/Extensions/MiscExtensions.cs @@ -74,8 +74,24 @@ public static void CancelAfterSafe(this CancellationTokenSource cts, TimeSpan ti public static Guid? GetGuidProperty(this object obj, string name) => obj.GetProperty(name) as Guid?; - public static string? GetStringProperty(this object obj, string name) => - obj.GetProperty(name) as string; + public static string? GetStringProperty(this object obj, string name) + { + var propertyNames = name.Split('.'); + var currentObj = obj; + + foreach (var propertyName in propertyNames) + { + var property = currentObj?.GetType().GetProperty(propertyName); + if (property == null) + { + return null; + } + + currentObj = property.GetValue(currentObj); + } + + return currentObj as string; + } public static void Add( this ICollection> collection, diff --git a/test/Sentry.Tests/Internals/Extensions/MiscExtensionsTests.cs b/test/Sentry.Tests/Internals/Extensions/MiscExtensionsTests.cs new file mode 100644 index 0000000000..ba8499af66 --- /dev/null +++ b/test/Sentry.Tests/Internals/Extensions/MiscExtensionsTests.cs @@ -0,0 +1,74 @@ +namespace Sentry.Tests.Internals.Extensions; + +public class MiscExtensionsTests +{ + public class MyClass { + public string SomeString { get; set; } + public MySubclass Subclass { get; set; } + } + + public class MySubclass { + public string AnotherString { get; set; } + } + + [Fact] + public void GetStringProperty_ShouldReturnTopLevelProperty() + { + var myClass = new MyClass + { + SomeString = "Hello" + }; + + var result = myClass.GetStringProperty("SomeString"); + + Assert.Equal("Hello", result); + } + + [Fact] + public void GetStringProperty_ShouldReturnNestedProperty() + { + var myClass = new MyClass + { + Subclass = new MySubclass + { + AnotherString = "World" + } + }; + + var result = myClass.GetStringProperty("Subclass.AnotherString"); + + Assert.Equal("World", result); + } + + [Fact] + public void GetStringProperty_ShouldReturnNull_WhenPropertyNotFound() + { + var myClass = new MyClass(); + + var result = myClass.GetStringProperty("NonExistentProperty"); + + Assert.Null(result); + } + + [Fact] + public void GetStringProperty_ShouldReturnNull_WhenIntermediatePropertyIsNull() + { + var myClass = new MyClass(); + + var result = myClass.GetStringProperty("Subclass.AnotherString"); + + Assert.Null(result); + } + + [Fact] + public void GetStringProperty_ShouldReturnNull_WhenNestedPropertyNotString() + { + var myClass = new MyClass(); + myClass.Subclass = new MySubclass(); + myClass.Subclass.AnotherString = "World"; + + var result = myClass.GetStringProperty("Subclass"); + + Assert.Null(result); + } +} From a9010d9532609b3b92195a335bf8593b05986a00 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Tue, 6 Jun 2023 14:43:34 +1200 Subject: [PATCH 15/32] Fixed errors with unit tests --- .../EFCommandDiagnosticSourceHelper.cs | 6 +++++- .../SqlListenerTests.RecordsEf.Net4_8.verified.txt | 8 +++++--- .../SentryEFCoreListenerTests.cs | 11 +++-------- 3 files changed, 13 insertions(+), 12 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index d52a768c5b..a4a9000999 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -39,7 +39,7 @@ protected override ISpan GetParentSpan(ITransaction transaction, object? diagnos { return parentSpan; } - Options.LogWarning("Unable to locate query parent span. No Span found with db connection id {1}.", connectionId); + Options.LogWarning("Unable to locate query parent span. No Span found with db connection id {0}.", connectionId); return base.GetParentSpan(transaction, diagnosticSourceValue); } else @@ -69,6 +69,10 @@ protected override void SetSpanReference(ISpan span, object? diagnosticSourceVal if (GetCommandId(diagnosticSourceValue) is { } commandId) { SetCommandId(span, commandId); + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) + { + SetConnectionId(span, connectionId); + } return; } Options.LogWarning("No correlation id can be set for {1}.", Operation); diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt index 5c2e93bf15..62339c857b 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt @@ -57,7 +57,8 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();, Status: Ok, IsSampled: true, Extra: { - db.command_id: Guid_1 + db.command_id: Guid_1, + db.connection_id: Guid_2 } }, { @@ -69,11 +70,12 @@ FROM [TestEntities] AS [t], Status: Ok, IsSampled: true, Extra: { - db.command_id: Guid_2 + db.command_id: Guid_3, + db.connection_id: Guid_4 } } ], IsFinished: true } } -] \ No newline at end of file +] diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 349ca27d1a..ac39ff8ea4 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -204,11 +204,6 @@ public FakeDiagnosticConnectionEventData(string value) : base(value) { } private class FakeDiagnosticCommandEventData : FakeDiagnosticEventData { - public FakeDiagnosticCommandEventData(string value) : base(value) - { - ConnectionId = new Guid(); - } - public FakeDiagnosticCommandEventData(Guid connectionId, string value) : base(value) { ConnectionId = connectionId; @@ -399,9 +394,9 @@ public void OnNext_Same_Connections_Consolidated() // Fake a connection pool with two connections var connectionA = new FakeDiagnosticConnectionEventData(efConn); var connectionB = new FakeDiagnosticConnectionEventData(efConn); - var commandA = new FakeDiagnosticCommandEventData(efSql); - var commandB = new FakeDiagnosticCommandEventData(efSql); - var commandC = new FakeDiagnosticCommandEventData(efSql); + var commandA = new FakeDiagnosticCommandEventData(connectionA.ConnectionId, efSql); + var commandB = new FakeDiagnosticCommandEventData(connectionB.ConnectionId, efSql); + var commandC = new FakeDiagnosticCommandEventData(connectionA.ConnectionId, efSql); void Pause() => Thread.Sleep(200); From f54f3321c3e3493f983405b4a5f075a32b57553f Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Wed, 7 Jun 2023 15:03:49 -0700 Subject: [PATCH 16/32] Update CHANGELOG.md --- CHANGELOG.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 087003329b..0a62681e4e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,8 +6,6 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) -- DB connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) -- DB Connection spans presented poorly ([#2409](https://github.com/getsentry/sentry-dotnet/pull/2409)) - Fix db connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. @@ -17,6 +15,7 @@ - Reduce debug files uploaded ([#2404](https://github.com/getsentry/sentry-dotnet/pull/2404)) - Fix system frames being marked as "in-app" ([#2408](https://github.com/getsentry/sentry-dotnet/pull/2408)) - NOTE: This important fix corrects a value that is used during issue grouping, so you may receive new alerts for existing issues after deploying this update. +- DB Connection spans presented poorly ([#2409](https://github.com/getsentry/sentry-dotnet/pull/2409)) - Populate scope's Cookies property ([#2411](https://github.com/getsentry/sentry-dotnet/pull/2411)) ### Dependencies From 8448f479300f13ac3d9ec647d49d335b0b008afc Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Wed, 7 Jun 2023 15:18:26 -0700 Subject: [PATCH 17/32] fix merge conflict --- test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs | 2 -- 1 file changed, 2 deletions(-) diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index c9187f8dac..59d90ed09c 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -1,6 +1,4 @@ -using Microsoft.EntityFrameworkCore.Diagnostics; using Sentry.Internal.DiagnosticSource; -using Microsoft.EntityFrameworkCore.Diagnostics; using static Sentry.Internal.DiagnosticSource.SentryEFCoreListener; namespace Sentry.DiagnosticSource.Tests; From 232ceaff72ddc18b9be906a25a8a933a2fe5a3c1 Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Wed, 7 Jun 2023 15:18:39 -0700 Subject: [PATCH 18/32] nits --- .../EFCommandDiagnosticSourceHelper.cs | 11 ++++------- .../EFConnectionDiagnosticSourceHelper.cs | 2 +- .../DiagnosticSource/EFDiagnosticSourceHelper.cs | 3 ++- 3 files changed, 7 insertions(+), 9 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index a4a9000999..80ab8cb29c 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -27,10 +27,9 @@ private static void SetCommandId(ISpan span, Guid? commandId) protected override ISpan GetParentSpan(ITransaction transaction, object? diagnosticSourceValue) { - ISpan? parentSpan = null; if (GetConnectionId(diagnosticSourceValue) is { } connectionId) { - parentSpan = transaction.Spans + var parentSpan = transaction.Spans .FirstOrDefault(span => !span.IsFinished && span.Operation == "db.connection" && @@ -42,11 +41,9 @@ protected override ISpan GetParentSpan(ITransaction transaction, object? diagnos Options.LogWarning("Unable to locate query parent span. No Span found with db connection id {0}.", connectionId); return base.GetParentSpan(transaction, diagnosticSourceValue); } - else - { - Options.LogWarning("Unable to locate query parent span. diagnostic source did not contain a db connection id."); - return base.GetParentSpan(transaction, diagnosticSourceValue); - } + + Options.LogWarning("Unable to locate query parent span. diagnostic source did not contain a db connection id."); + return base.GetParentSpan(transaction, diagnosticSourceValue); } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 4dd7223d56..bb362e244f 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -65,6 +65,6 @@ internal void AddOrReuseSpan(object? diagnosticSourceValue) } // If we can't find a span to reuse then we'll add a new one instead - base.AddSpan(diagnosticSourceValue); + AddSpan(diagnosticSourceValue); } } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 0571dc7d6b..5d762810e1 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -69,7 +69,8 @@ internal void FinishSpan(object? diagnosticSourceValue, SpanStatus status) Options.LogWarning("Tried to close {0} span but no matching span could be found.", Operation); return; } - sourceSpan?.Finish(status); + + sourceSpan.Finish(status); } protected void LogTransactionSpans() From 93dff1bc8aab8947e463ffecb415ef1e5320623b Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Wed, 7 Jun 2023 15:20:55 -0700 Subject: [PATCH 19/32] Update extension method improvements to apply to all property types --- src/Sentry/Internal/Extensions/MiscExtensions.cs | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/src/Sentry/Internal/Extensions/MiscExtensions.cs b/src/Sentry/Internal/Extensions/MiscExtensions.cs index 15f28dd757..25bce31157 100644 --- a/src/Sentry/Internal/Extensions/MiscExtensions.cs +++ b/src/Sentry/Internal/Extensions/MiscExtensions.cs @@ -68,13 +68,7 @@ public static void CancelAfterSafe(this CancellationTokenSource cts, TimeSpan ti /// public static bool IsNull(this object? o) => o is null; - public static object? GetProperty(this object obj, string name) => - obj.GetType().GetProperty(name)?.GetValue(obj); - - public static Guid? GetGuidProperty(this object obj, string name) => - obj.GetProperty(name) as Guid?; - - public static string? GetStringProperty(this object obj, string name) + public static object? GetProperty(this object obj, string name) { var propertyNames = name.Split('.'); var currentObj = obj; @@ -90,9 +84,15 @@ public static void CancelAfterSafe(this CancellationTokenSource cts, TimeSpan ti currentObj = property.GetValue(currentObj); } - return currentObj as string; + return currentObj; } + public static Guid? GetGuidProperty(this object obj, string name) => + obj.GetProperty(name) as Guid?; + + public static string? GetStringProperty(this object obj, string name) => + obj.GetProperty(name) as string; + public static void Add( this ICollection> collection, TKey key, From 551a20b84f72ec3dce389807ffd85c2279af3d4e Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Wed, 7 Jun 2023 15:49:46 -0700 Subject: [PATCH 20/32] Restore test changes (bad merge) --- .../SentryEFCoreListenerTests.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 59d90ed09c..d05cbf51b9 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -255,7 +255,7 @@ public void OnNext_HappyPath_IsValid() // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -306,7 +306,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() // Check connections between spans. Assert.Equal(childSpan.SpanId, compilerSpan.ParentSpanId); Assert.Equal(childSpan.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(childSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -352,7 +352,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); + Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); Assert.Equal(expectedSql, commandSpan.Description); } From 9eec767b757999167400a841e5ab26b6510e7501 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 8 Jun 2023 11:18:47 +1200 Subject: [PATCH 21/32] Fixed whitespace error in Verify tests --- .../SqlListenerTests.RecordsEf.Net4_8.verified.txt | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt index 23eea1df48..62339c857b 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt @@ -18,7 +18,7 @@ Request: {}, Contexts: { trace: { - Operation: + Operation: } }, User: {} From 028c7b6ed80d0aa00d270cd9741b39bd343ecce1 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 8 Jun 2023 16:10:48 +1200 Subject: [PATCH 22/32] Flattened DB Connection and Query spans produced by the Sentry DB Diagnostic listeners --- .../EFCommandDiagnosticSourceHelper.cs | 27 +-------- .../EFConnectionDiagnosticSourceHelper.cs | 19 ++++++- .../EFDiagnosticSourceHelper.cs | 5 +- .../DiagnosticSource/SentrySqlListener.cs | 56 +++++-------------- .../ReadOnlyDictionaryExtensions.cs | 10 ++++ .../SentryEFCoreListenerTests.cs | 40 +++++++++---- .../SentrySqlListenerTests.cs | 17 +++--- .../ReadOnlyDictionaryExtensionsTests.cs | 49 ++++++++++++++++ 8 files changed, 126 insertions(+), 97 deletions(-) create mode 100644 src/Sentry/Internal/Extensions/ReadOnlyDictionaryExtensions.cs create mode 100644 test/Sentry.Tests/Internals/Extensions/ReadOnlyDictionaryExtensionsTests.cs diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index 80ab8cb29c..bf9af7db18 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -20,32 +20,7 @@ private static void SetCommandId(ISpan span, Guid? commandId) span.SetExtra(CommandExtraKey, commandId); } - private static Guid? TryGetCommandId(ISpan span) => - span.Extra.TryGetValue(CommandExtraKey, out var key) && key is Guid guid - ? guid - : null; - - protected override ISpan GetParentSpan(ITransaction transaction, object? diagnosticSourceValue) - { - if (GetConnectionId(diagnosticSourceValue) is { } connectionId) - { - var parentSpan = transaction.Spans - .FirstOrDefault(span => - !span.IsFinished && - span.Operation == "db.connection" && - TryGetConnectionId(span) == connectionId); - if (parentSpan is { }) - { - return parentSpan; - } - Options.LogWarning("Unable to locate query parent span. No Span found with db connection id {0}.", connectionId); - return base.GetParentSpan(transaction, diagnosticSourceValue); - } - - Options.LogWarning("Unable to locate query parent span. diagnostic source did not contain a db connection id."); - return base.GetParentSpan(transaction, diagnosticSourceValue); - } - + private static Guid? TryGetCommandId(ISpan span) => span.Extra.TryGetValue(CommandExtraKey); protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index bb362e244f..8734648c0d 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -5,12 +5,18 @@ namespace Sentry.Internal.DiagnosticSource; internal class EFConnectionDiagnosticSourceHelper : EFDiagnosticSourceHelper { + // These all use the Open Telemetry naming conventions from + // https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md + internal const string DbNameExtraKey = "db.name"; + internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : base(hub, options) { } protected override string Operation => "db.connection"; - protected override string Description(object? diagnosticSourceValue) => + protected override string Description(object? diagnosticSourceValue) => DatabaseName(diagnosticSourceValue); + + private string DatabaseName(object? diagnosticSourceValue) => diagnosticSourceValue?.GetStringProperty("Connection.Database") ?? null!; protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) @@ -29,12 +35,19 @@ protected override string Description(object? diagnosticSourceValue) => protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) { + if (DatabaseName(diagnosticSourceValue) is { } databaseName) + { + span.SetExtra(DbNameExtraKey, databaseName); + } + if (GetConnectionId(diagnosticSourceValue) is { } connectionId) { SetConnectionId(span, connectionId); - return; } - Options.LogWarning("No {0} found when adding {1} Span.", "ConnectionId", Operation); + else + { + Options.LogWarning("No {0} found when adding {1} Span.", "ConnectionId", Operation); + } } /// diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 5d762810e1..fcc121d994 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -19,10 +19,7 @@ internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) Transaction = hub.GetTransactionIfSampled(); } - protected static Guid? TryGetConnectionId(ISpan span) => - span.Extra.TryGetValue(ConnectionExtraKey, out var key) && key is Guid guid - ? guid - : null; + protected static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(ConnectionExtraKey); protected static Guid? GetConnectionId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("ConnectionId"); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index bf63b85224..c50695ee64 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -55,15 +55,8 @@ private static void SetOperationId(ISpan span, Guid? operationId) span.SetExtra(OperationExtraKey, operationId); } - private static Guid? TryGetOperationId(ISpan span) => - span.Extra.TryGetValue(OperationExtraKey, out var key) && key is Guid guid - ? guid - : null; - - private static Guid? TryGetConnectionId(ISpan span) => - span.Extra.TryGetValue(ConnectionExtraKey, out var key) && key is Guid guid - ? guid - : null; + private static Guid? TryGetOperationId(ISpan span) => span.Extra.TryGetValue(OperationExtraKey); + private static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(ConnectionExtraKey); private void AddSpan(SentrySqlSpanType type, string operation, object? value) { @@ -74,25 +67,11 @@ private void AddSpan(SentrySqlSpanType type, string operation, object? value) } var operationId = value?.GetGuidProperty("OperationId"); - - switch (type) - { - case SentrySqlSpanType.Connection when transaction.GetDbParentSpan().StartChild(operation) is - { } connectionSpan: - SetOperationId(connectionSpan, operationId); - break; - - case SentrySqlSpanType.Execution when value?.GetGuidProperty("ConnectionId") is { } connectionId: - var parent = TryGetConnectionSpan(transaction, connectionId) ?? transaction.GetDbParentSpan(); - var span = TryStartChild(parent, operation, null); - if (span != null) - { - SetOperationId(span, operationId); - SetConnectionId(span, connectionId); - } - - break; - } + var connectionId = value?.GetGuidProperty("ConnectionId"); + var parent = transaction.GetDbParentSpan(); + var span = parent.StartChild(operation); + SetOperationId(span, operationId); + SetConnectionId(span, connectionId); } private ISpan? GetSpan(SentrySqlSpanType type, KeyValuePair kvp) @@ -107,24 +86,15 @@ private void AddSpan(SentrySqlSpanType type, string operation, object? value) { case SentrySqlSpanType.Execution: var operationId = kvp.Value?.GetGuidProperty("OperationId"); - if (TryGetQuerySpan(transaction, operationId) is not { } querySpan) - { - _options.LogWarning( - "Trying to get an execution span with operation id {0}, but it was not found.", - operationId); - return null; - } - - if (querySpan.ParentSpanId == transaction.SpanId && - TryGetConnectionId(querySpan) is { } spanConnectionId && - querySpan is SpanTracer executionTracer && - TryGetConnectionSpan(transaction, spanConnectionId) is { } spanConnectionRef) + if (TryGetQuerySpan(transaction, operationId) is { } querySpan) { - // Connection Span exist but wasn't set as the parent of the current Span. - executionTracer.ParentSpanId = spanConnectionRef.SpanId; + return querySpan; } - return querySpan; + _options.LogWarning( + "Trying to get an execution span with operation id {0}, but it was not found.", + operationId); + return null; case SentrySqlSpanType.Connection: var connectionId = kvp.Value?.GetGuidProperty("ConnectionId"); diff --git a/src/Sentry/Internal/Extensions/ReadOnlyDictionaryExtensions.cs b/src/Sentry/Internal/Extensions/ReadOnlyDictionaryExtensions.cs new file mode 100644 index 0000000000..a91ed787f5 --- /dev/null +++ b/src/Sentry/Internal/Extensions/ReadOnlyDictionaryExtensions.cs @@ -0,0 +1,10 @@ +namespace Sentry.Internal.Extensions; + +internal static class ReadOnlyDictionaryExtensions +{ + public static TValue? TryGetValue(this IReadOnlyDictionary dictionary, TKey key) + where TKey : notnull + => dictionary.TryGetValue(key, out var value) && value is TValue typedValue + ? typedValue + : default; +} diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index d05cbf51b9..1bba7a9276 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -9,14 +9,11 @@ private static Func GetValidator(string type) => type switch { EFQueryCompiling or EFQueryCompiled => - span => span.Description != null && - span.Operation == "db.query.compile", + span => span.Operation == "db.query.compile", EFConnectionOpening or EFConnectionClosed => - span => span.Description == null && - span.Operation == "db.connection", + span => span.Operation == "db.connection", EFCommandExecuting or EFCommandExecuting or EFCommandFailed => - span => span.Description != null && - span.Operation == "db.query", + span => span.Operation == "db.query", _ => throw new NotSupportedException() }; @@ -198,7 +195,14 @@ private class FakeDiagnosticEventData private class FakeDiagnosticConnectionEventData : FakeDiagnosticEventData { public FakeDiagnosticConnectionEventData(string value) : base(value) { } - public Guid ConnectionId { get; set; } = Guid.NewGuid(); + public Guid ConnectionId { get; } = Guid.NewGuid(); + + public ConnectionInfo Connection { get; } = new ConnectionInfo(); + + public class ConnectionInfo + { + public string Database { get; } = "rentals"; + } } private class FakeDiagnosticCommandEventData : FakeDiagnosticEventData @@ -221,6 +225,7 @@ public void OnNext_HappyPath_IsValid() var expectedSql = "SELECT * FROM ..."; var efSql = "ef Junk\r\nSELECT * FROM ..."; var efConn = "db username : password"; + var expectedDbName = "rentals"; var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); @@ -248,14 +253,19 @@ public void OnNext_HappyPath_IsValid() }); // Assert span descriptions - Assert.Null(connectionSpan.Description); + Assert.Equal(expectedDbName,connectionSpan.Description); Assert.Equal(expectedSql, compilerSpan.Description); Assert.Equal(expectedSql, commandSpan.Description); + // Check DB Name is stored correctly + var dbName = + connectionSpan.Extra.TryGetValue(EFConnectionDiagnosticSourceHelper.DbNameExtraKey); + Assert.Equal(expectedDbName, dbName); + // 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(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -270,6 +280,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() var expectedSql = "SELECT * FROM ..."; var efSql = "ef Junk\r\nSELECT * FROM ..."; var efConn = "db username : password"; + var expectedDbName = "rentals"; var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); @@ -299,14 +310,19 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() }); // Assert span descriptions - Assert.Null(connectionSpan.Description); + Assert.Equal(expectedDbName, connectionSpan.Description); Assert.Equal(expectedSql, compilerSpan.Description); Assert.Equal(expectedSql, commandSpan.Description); + // Check DB Name is stored correctly + var dbName = + connectionSpan.Extra.TryGetValue(EFConnectionDiagnosticSourceHelper.DbNameExtraKey); + Assert.Equal(expectedDbName, dbName); + // Check connections between spans. Assert.Equal(childSpan.SpanId, compilerSpan.ParentSpanId); Assert.Equal(childSpan.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(childSpan.SpanId, commandSpan.ParentSpanId); _fixture.Options.DiagnosticLogger.DidNotReceive()? .Log(Arg.Is(SentryLevel.Warning), Arg.Is("Trying to close a span that was already garbage collected. {0}"), null, Arg.Any()); @@ -352,7 +368,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() // 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(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); Assert.Equal(expectedSql, commandSpan.Description); } diff --git a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs index a0808c024e..44a0eaedab 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs @@ -225,7 +225,7 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); Assert.Equal(query, commandSpan.Description); } @@ -305,7 +305,7 @@ public void OnNext_HappyPathsInsideChildSpan_IsValid(string connectionOpenKey, s // Check connections between spans. Assert.Equal(childSpan.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(childSpan.SpanId, commandSpan.ParentSpanId); Assert.Equal(query, commandSpan.Description); } @@ -442,7 +442,7 @@ public void OnNext_ExecuteQueryCalledBeforeConnectionId_ExecuteParentIsConnectio // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); Assert.Equal(query, commandSpan.Description); } @@ -542,15 +542,14 @@ void SimulateDbRequest(List connectionOperationIds, List queryOperat Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); }); - // Assert all Query spans have the correct ParentId Set and not the Transaction Id. + // Assert all Query spans have the correct ParentId Set and record the Connection Id. Assert.All(querySpans, querySpan => { Assert.True(querySpan.IsFinished); - var connectionId = (Guid)querySpan.Extra[ConnectionExtraKey]!; - var connectionSpan = connectionSpans.Single(span => span.SpanId == querySpan.ParentSpanId); + Assert.Equal(_fixture.Tracer.SpanId, querySpan.ParentSpanId); - Assert.NotEqual(_fixture.Tracer.SpanId, querySpan.ParentSpanId); - Assert.Equal((Guid)connectionSpan.Extra[ConnectionExtraKey]!, connectionId); + var queryConnectionId = querySpan.Extra.TryGetValue(ConnectionExtraKey); + queryConnectionId.Should().NotBeNull(); }); _fixture.Logger.Entries.Should().BeEmpty(); @@ -624,7 +623,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); - Assert.Equal(connectionSpan.SpanId, commandSpan.ParentSpanId); + Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); Assert.Equal(query, commandSpan.Description); } diff --git a/test/Sentry.Tests/Internals/Extensions/ReadOnlyDictionaryExtensionsTests.cs b/test/Sentry.Tests/Internals/Extensions/ReadOnlyDictionaryExtensionsTests.cs new file mode 100644 index 0000000000..9ca1d5ab86 --- /dev/null +++ b/test/Sentry.Tests/Internals/Extensions/ReadOnlyDictionaryExtensionsTests.cs @@ -0,0 +1,49 @@ +namespace Sentry.Tests.Internals.Extensions; + +public class ReadOnlyDictionaryExtensionsTests +{ + [Fact] + public void TryGetValue_ShouldReturnNull_WhenKeyNotFound() + { + // Arrange + var dictionary = new Dictionary(); // Empty dictionary + + // Act + var result = dictionary.TryGetValue("key"); + + // Assert + result.Should().BeNull(); + } + + [Fact] + public void TryGetValue_ShouldReturnValue_WhenKeyFoundAndTypeMatches() + { + // Arrange + var dictionary = new Dictionary + { + { "key", "value" } + }; + + // Act + var result = dictionary.TryGetValue("key"); + + // Assert + result.Should().Be("value"); + } + + [Fact] + public void TryGetValue_ShouldReturnNull_WhenKeyFoundButTypeDoesNotMatch() + { + // Arrange + var dictionary = new Dictionary + { + { "key", 123 } + }; + + // Act + var result = dictionary.TryGetValue("key"); + + // Assert + result.Should().BeNull(); + } +} From f7decd06404efad4a69dbb950e34a047742a66dd Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 8 Jun 2023 18:35:54 +1200 Subject: [PATCH 23/32] Renamed verify tests to conform with async naming conventions --- ...=> SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt} | 2 ++ ...=> SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt} | 2 ++ ...=> SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt} | 4 +++- ... SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt} | 4 +++- ... SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt} | 4 +++- ... => SqlListenerTests.RecordsEfAsync.Net4_8.verified.txt} | 0 ...ed.txt => SqlListenerTests.RecordsSqlAsync.verified.txt} | 4 +++- .../SqlListenerTests.verify.cs | 6 +++--- 8 files changed, 19 insertions(+), 7 deletions(-) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.Logging.DotNet6_0.verified.txt => SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt} (95%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.Logging.DotNet7_0.verified.txt => SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt} (95%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.RecordsEf.DotNet7_0.verified.txt => SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt} (94%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.RecordsEf.Core3_1.verified.txt => SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt} (94%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.RecordsEf.DotNet6_0.verified.txt => SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt} (94%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.RecordsEf.Net4_8.verified.txt => SqlListenerTests.RecordsEfAsync.Net4_8.verified.txt} (100%) rename test/Sentry.DiagnosticSource.IntegrationTests/{SqlListenerTests.RecordsSql.verified.txt => SqlListenerTests.RecordsSqlAsync.verified.txt} (93%) diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet6_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt similarity index 95% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet6_0.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt index 02bec71325..361d7ff6c2 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet6_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt @@ -67,11 +67,13 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();, { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_LoggingAsync, Status: Ok, IsSampled: true, Extra: { bytes_sent : 510, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_LoggingAsync, db.operation_id: Guid_2, rows_sent: 0 } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet7_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt similarity index 95% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet7_0.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt index 02bec71325..361d7ff6c2 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.Logging.DotNet7_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt @@ -67,11 +67,13 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();, { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_LoggingAsync, Status: Ok, IsSampled: true, Extra: { bytes_sent : 510, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_LoggingAsync, db.operation_id: Guid_2, rows_sent: 0 } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet7_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt similarity index 94% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet7_0.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt index 7b7852c1a8..522bbd4d67 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet7_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt @@ -47,12 +47,14 @@ { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_RecordsEfAsync, Status: Ok, IsSampled: true, Extra: { bytes_received: 304, bytes_sent : 704, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_2, rows_sent: 1 } @@ -100,4 +102,4 @@ FROM [TestEntities] AS [t], IsFinished: true } } -] \ No newline at end of file +] diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Core3_1.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt similarity index 94% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Core3_1.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt index 7b7852c1a8..522bbd4d67 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Core3_1.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt @@ -47,12 +47,14 @@ { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_RecordsEfAsync, Status: Ok, IsSampled: true, Extra: { bytes_received: 304, bytes_sent : 704, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_2, rows_sent: 1 } @@ -100,4 +102,4 @@ FROM [TestEntities] AS [t], IsFinished: true } } -] \ No newline at end of file +] diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet6_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt similarity index 94% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet6_0.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt index 7b7852c1a8..522bbd4d67 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.DotNet6_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt @@ -47,12 +47,14 @@ { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_RecordsEfAsync, Status: Ok, IsSampled: true, Extra: { bytes_received: 304, bytes_sent : 704, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_2, rows_sent: 1 } @@ -100,4 +102,4 @@ FROM [TestEntities] AS [t], IsFinished: true } } -] \ No newline at end of file +] diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Net4_8.verified.txt similarity index 100% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEf.Net4_8.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Net4_8.verified.txt diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSql.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt similarity index 93% rename from test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSql.verified.txt rename to test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt index 253f4058f4..bc32616206 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSql.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt @@ -47,12 +47,14 @@ { IsFinished: true, Operation: db.connection, + Description: SqlListenerTests.verify_RecordsSqlAsync, Status: Ok, IsSampled: true, Extra: { bytes_received: 167, bytes_sent : 536, db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_RecordsSqlAsync, db.operation_id: Guid_2, rows_sent: 1 } @@ -83,4 +85,4 @@ IsFinished: true } } -] \ No newline at end of file +] diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.verify.cs b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.verify.cs index 7b333767f4..2706cb42fe 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.verify.cs +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.verify.cs @@ -14,7 +14,7 @@ public SqlListenerTests(LocalDbFixture fixture, ITestOutputHelper output) #if !NETFRAMEWORK [SkippableFact] - public async Task RecordsSql() + public async Task RecordsSqlAsync() { Skip.If(!RuntimeInformation.IsOSPlatform(OSPlatform.Windows)); var transport = new RecordingTransport(); @@ -57,7 +57,7 @@ public async Task RecordsSql() #if NET6_0_OR_GREATER [SkippableFact] - public async Task Logging() + public async Task LoggingAsync() { Skip.If(!RuntimeInformation.IsOSPlatform(OSPlatform.Windows)); var transport = new RecordingTransport(); @@ -170,7 +170,7 @@ public void ShouldIgnoreAllErrorAndExceptionIds() } [SkippableFact] - public async Task RecordsEf() + public async Task RecordsEfAsync() { Skip.If(!RuntimeInformation.IsOSPlatform(OSPlatform.Windows)); var transport = new RecordingTransport(); From 553e69a5af068da1d100f6e485893740103fe9a9 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Thu, 8 Jun 2023 18:37:36 +1200 Subject: [PATCH 24/32] SqlClient diagnostics now uses the Databasename to describe db.connection spans --- .../DiagnosticSourceConstants.cs | 35 ++++++++++++++ .../EFCommandDiagnosticSourceHelper.cs | 4 +- .../EFConnectionDiagnosticSourceHelper.cs | 6 +-- .../EFDiagnosticSourceHelper.cs | 7 +-- .../DiagnosticSource/SentrySqlListener.cs | 38 ++++++++++----- .../SentryEFCoreListenerTests.cs | 12 ++--- .../SentrySqlListenerTests.cs | 46 ++++++++++++++----- 7 files changed, 106 insertions(+), 42 deletions(-) create mode 100644 src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs new file mode 100644 index 0000000000..cbdcf81845 --- /dev/null +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs @@ -0,0 +1,35 @@ +using System; +using System.Collections.Generic; +using System.Text; + +namespace Sentry.Internal.DiagnosticSource +{ + /// + /// Open Telemetry Keys + /// + /// https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md + /// + internal static class OTKeys + { + internal const string DbName = "db.name"; + } + + /// + /// Keys specific to the SqlClient listener + /// + internal static class SqlKeys + { + internal const string DbConnectionId = "db.connection_id"; + internal const string DbOperationId = "db.operation_id"; + } + + /// + /// Keys specific to the Entity Framework listener + /// + internal static class EFKeys + { + // Entity Framework specific + internal const string DbConnectionId = "db.connection_id"; + internal const string DbCommandId = "db.command_id"; + } +} diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index bf9af7db18..e4c689cfc6 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -17,10 +17,10 @@ private static void SetCommandId(ISpan span, Guid? commandId) { Debug.Assert(commandId != Guid.Empty); - span.SetExtra(CommandExtraKey, commandId); + span.SetExtra(EFKeys.DbCommandId, commandId); } - private static Guid? TryGetCommandId(ISpan span) => span.Extra.TryGetValue(CommandExtraKey); + private static Guid? TryGetCommandId(ISpan span) => span.Extra.TryGetValue(EFKeys.DbCommandId); protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 8734648c0d..6b33dbe32f 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -5,10 +5,6 @@ namespace Sentry.Internal.DiagnosticSource; internal class EFConnectionDiagnosticSourceHelper : EFDiagnosticSourceHelper { - // These all use the Open Telemetry naming conventions from - // https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md - internal const string DbNameExtraKey = "db.name"; - internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : base(hub, options) { } @@ -37,7 +33,7 @@ protected override void SetSpanReference(ISpan span, object? diagnosticSourceVal { if (DatabaseName(diagnosticSourceValue) is { } databaseName) { - span.SetExtra(DbNameExtraKey, databaseName); + span.SetExtra(OTKeys.DbName, databaseName); } if (GetConnectionId(diagnosticSourceValue) is { } connectionId) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index fcc121d994..b8936d1e12 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -5,9 +5,6 @@ namespace Sentry.Internal.DiagnosticSource; internal abstract class EFDiagnosticSourceHelper { - internal const string ConnectionExtraKey = "db.connection_id"; - internal const string CommandExtraKey = "db.command_id"; - protected SentryOptions Options { get; } protected ITransaction? Transaction { get; } protected abstract string Operation { get; } @@ -19,7 +16,7 @@ internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) Transaction = hub.GetTransactionIfSampled(); } - protected static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(ConnectionExtraKey); + protected static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(EFKeys.DbConnectionId); protected static Guid? GetConnectionId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("ConnectionId"); @@ -27,7 +24,7 @@ protected static void SetConnectionId(ISpan span, Guid? connectionId) { Debug.Assert(connectionId != Guid.Empty); - span.SetExtra(ConnectionExtraKey, connectionId); + span.SetExtra(EFKeys.DbConnectionId, connectionId); } internal void AddSpan(object? diagnosticSourceValue) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index c50695ee64..b05f167674 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -11,9 +11,6 @@ private enum SentrySqlSpanType Execution }; - internal const string ConnectionExtraKey = "db.connection_id"; - internal const string OperationExtraKey = "db.operation_id"; - internal const string SqlDataWriteConnectionOpenBeforeCommand = "System.Data.SqlClient.WriteConnectionOpenBefore"; internal const string SqlMicrosoftWriteConnectionOpenBeforeCommand = "Microsoft.Data.SqlClient.WriteConnectionOpenBefore"; @@ -41,22 +38,29 @@ public SentrySqlListener(IHub hub, SentryOptions options) _options = options; } + private static void SetDatabaseName(ISpan span, string databaseName) + { + Debug.Assert(databaseName != string.Empty); + + span.SetExtra(OTKeys.DbName, databaseName); + } + private static void SetConnectionId(ISpan span, Guid? connectionId) { Debug.Assert(connectionId != Guid.Empty); - span.SetExtra(ConnectionExtraKey, connectionId); + span.SetExtra(SqlKeys.DbConnectionId, connectionId); } private static void SetOperationId(ISpan span, Guid? operationId) { Debug.Assert(operationId != Guid.Empty); - span.SetExtra(OperationExtraKey, operationId); + span.SetExtra(SqlKeys.DbOperationId, operationId); } - private static Guid? TryGetOperationId(ISpan span) => span.Extra.TryGetValue(OperationExtraKey); - private static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(ConnectionExtraKey); + private static Guid? TryGetOperationId(ISpan span) => span.Extra.TryGetValue(SqlKeys.DbOperationId); + private static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(SqlKeys.DbConnectionId); private void AddSpan(SentrySqlSpanType type, string operation, object? value) { @@ -143,8 +147,7 @@ private void UpdateConnectionSpan(object? value) } var operationId = value.GetGuidProperty("OperationId"); - var connectionId = value.GetGuidProperty("ConnectionId"); - if (operationId == null || connectionId == null) + if (operationId == null) { return; } @@ -152,7 +155,18 @@ private void UpdateConnectionSpan(object? value) var spans = transaction.Spans.Where(span => span.Operation is "db.connection").ToList(); if (spans.Find(span => !span.IsFinished && TryGetOperationId(span) == operationId) is { } connectionSpan) { - SetConnectionId(connectionSpan, connectionId); + var connectionId = value.GetGuidProperty("ConnectionId"); + if (connectionId.HasValue) + { + SetConnectionId(connectionSpan, connectionId); + } + + var database = value.GetStringProperty("Connection.Database"); + if (database is { } dbName) + { + connectionSpan.Description = dbName; + SetDatabaseName(connectionSpan, dbName); + } } } @@ -172,12 +186,12 @@ public void OnNext(KeyValuePair kvp) return; case SqlMicrosoftAfterExecuteCommand or SqlDataAfterExecuteCommand when GetSpan(SentrySqlSpanType.Execution, kvp) is { } commandSpan: - commandSpan.Description = kvp.Value?.GetProperty("Command")?.GetStringProperty("CommandText"); + commandSpan.Description = kvp.Value?.GetStringProperty("Command.CommandText"); commandSpan.Finish(SpanStatus.Ok); return; case SqlMicrosoftWriteCommandError or SqlDataWriteCommandError when GetSpan(SentrySqlSpanType.Execution, kvp) is { } errorSpan: - errorSpan.Description = kvp.Value?.GetProperty("Command")?.GetStringProperty("CommandText"); + errorSpan.Description = kvp.Value?.GetStringProperty("Command.CommandText"); errorSpan.Finish(SpanStatus.InternalError); return; diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 1bba7a9276..2e7f083f44 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -259,7 +259,7 @@ public void OnNext_HappyPath_IsValid() // Check DB Name is stored correctly var dbName = - connectionSpan.Extra.TryGetValue(EFConnectionDiagnosticSourceHelper.DbNameExtraKey); + connectionSpan.Extra.TryGetValue(OTKeys.DbName); Assert.Equal(expectedDbName, dbName); // Check connections between spans. @@ -316,7 +316,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() // Check DB Name is stored correctly var dbName = - connectionSpan.Extra.TryGetValue(EFConnectionDiagnosticSourceHelper.DbNameExtraKey); + connectionSpan.Extra.TryGetValue(OTKeys.DbName); Assert.Equal(expectedDbName, dbName); // Check connections between spans. @@ -444,12 +444,12 @@ public void OnNext_Same_Connections_Consolidated() bool IsDbSpan(ISpan s) => s.Operation == "db.connection"; bool IsCommandSpan(ISpan s) => s.Operation == "db.query"; Func forConnection = (s, e) => - s.Extra.ContainsKey(EFDiagnosticSourceHelper.ConnectionExtraKey) - && s.Extra[EFDiagnosticSourceHelper.ConnectionExtraKey] is Guid connectionId + s.Extra.ContainsKey(EFKeys.DbConnectionId) + && s.Extra[EFKeys.DbConnectionId] is Guid connectionId && connectionId == e.ConnectionId; Func forCommand = (s, e) => - s.Extra.ContainsKey(EFDiagnosticSourceHelper.CommandExtraKey) - && s.Extra[EFDiagnosticSourceHelper.CommandExtraKey] is Guid commandId + s.Extra.ContainsKey(EFKeys.DbCommandId) + && s.Extra[EFKeys.DbCommandId] is Guid commandId && commandId == e.CommandId; using (new AssertionScope()) diff --git a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs index 44a0eaedab..f0b5c30af3 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs @@ -1,4 +1,6 @@ +using Microsoft.EntityFrameworkCore.Storage; using Sentry.Internal.DiagnosticSource; +using Sentry.Internal.Extensions; using static Sentry.Internal.DiagnosticSource.SentrySqlListener; namespace Sentry.DiagnosticSource.Tests; @@ -14,8 +16,7 @@ SqlMicrosoftWriteConnectionOpenAfterCommand or SqlDataWriteConnectionOpenAfterCommand or SqlMicrosoftWriteConnectionCloseAfterCommand or SqlDataWriteConnectionCloseAfterCommand => - span => span.Description is null && - span.Operation == "db.connection", + span => span.Operation == "db.connection", SqlDataBeforeExecuteCommand or SqlMicrosoftBeforeExecuteCommand or @@ -103,7 +104,7 @@ public void OnNext_KnownKey_GetSpanInvoked(string key, bool addConnectionSpan) var interceptor = new SentrySqlListener(hub, new SentryOptions()); if (addConnectionSpan) { - _fixture.Tracer.StartChild("abc").SetExtra(ConnectionExtraKey, Guid.Empty); + _fixture.Tracer.StartChild("abc").SetExtra(SqlKeys.DbConnectionId, Guid.Empty); } // Act @@ -169,20 +170,29 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio var connectionOperationId = Guid.NewGuid(); var connectionOperationIdClosed = Guid.NewGuid(); var queryOperationId = Guid.NewGuid(); + var dbName = "rentals"; // Act interceptor.OnNext( new(connectionOpenKey, new { - OperationId = connectionOperationId + OperationId = connectionOperationId, + Connection = new + { + Database = dbName + } })); interceptor.OnNext( new(connectionUpdateKey, new { OperationId = connectionOperationId, - ConnectionId = connectionId + ConnectionId = connectionId, + Connection = new + { + Database = dbName + } })); interceptor.OnNext( new(queryStartKey, @@ -207,7 +217,11 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio new { OperationId = connectionOperationIdClosed, - ConnectionId = connectionId + ConnectionId = connectionId, + Connection = new + { + Database = dbName + } })); // Assert @@ -227,7 +241,15 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); Assert.Equal(_fixture.Tracer.SpanId, commandSpan.ParentSpanId); + // Validate descriptions and extra data is set correctly Assert.Equal(query, commandSpan.Description); + Assert.Equal(queryOperationId, commandSpan.Extra.TryGetValue(SqlKeys.DbOperationId)); + Assert.Equal(connectionId, commandSpan.Extra.TryGetValue(SqlKeys.DbConnectionId)); + + Assert.Equal(dbName, connectionSpan.Description); + Assert.Equal(connectionOperationId, connectionSpan.Extra.TryGetValue(SqlKeys.DbOperationId)); + Assert.Equal(connectionId, connectionSpan.Extra.TryGetValue(SqlKeys.DbConnectionId)); + Assert.Equal(dbName, connectionSpan.Extra.TryGetValue(OTKeys.DbName)); } [Theory] @@ -363,7 +385,7 @@ public void OnNext_TwoConnectionSpansWithSameId_FinishBothWithOk(string connecti { Assert.True(span.IsFinished); Assert.Equal(SpanStatus.Ok, span.Status); - Assert.Equal(connectionId, (Guid)span.Extra[ConnectionExtraKey]!); + Assert.Equal(connectionId, (Guid)span.Extra[SqlKeys.DbConnectionId]!); }); } @@ -467,7 +489,7 @@ public void OnNext_ExecuteQueryCalledBeforeConnectionId_ExecuteParentIsConnectio [InlineData(17)] [InlineData(18)] [InlineData(19)] - public async Task OnNext_ParallelExecution_IsValid(int testNumber) + public async Task OnNext_ParallelExecution_IsValidAsync(int testNumber) { _ = testNumber; // Arrange @@ -530,15 +552,15 @@ void SimulateDbRequest(List connectionOperationIds, List queryOperat querySpans.Should().HaveCount(2 * maxItems); // Open Spans should not have any Connection key. - Assert.All(openSpans, span => Assert.False(span.Extra.ContainsKey(ConnectionExtraKey))); + Assert.All(openSpans, span => Assert.False(span.Extra.ContainsKey(SqlKeys.DbConnectionId))); Assert.All(closedSpans, span => Assert.Equal(SpanStatus.Ok, span.Status)); // Assert that all connectionIds is set and ParentId set to Trace. // ReSharper disable once ParameterOnlyUsedForPreconditionCheck.Local Assert.All(closedConnectionSpans, connectionSpan => { - Assert.NotNull(connectionSpan.Extra[ConnectionExtraKey]); - Assert.NotNull(connectionSpan.Extra[OperationExtraKey]); + Assert.NotNull(connectionSpan.Extra[SqlKeys.DbConnectionId]); + Assert.NotNull(connectionSpan.Extra[SqlKeys.DbOperationId]); Assert.Equal(_fixture.Tracer.SpanId, connectionSpan.ParentSpanId); }); @@ -548,7 +570,7 @@ void SimulateDbRequest(List connectionOperationIds, List queryOperat Assert.True(querySpan.IsFinished); Assert.Equal(_fixture.Tracer.SpanId, querySpan.ParentSpanId); - var queryConnectionId = querySpan.Extra.TryGetValue(ConnectionExtraKey); + var queryConnectionId = querySpan.Extra.TryGetValue(SqlKeys.DbConnectionId); queryConnectionId.Should().NotBeNull(); }); From 85255852904deae6eb51e0410af5f4f223b1893b Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Thu, 8 Jun 2023 09:51:31 -0700 Subject: [PATCH 25/32] nits --- .../DiagnosticSourceConstants.cs | 54 +++++++++---------- .../EFCommandDiagnosticSourceHelper.cs | 4 +- .../EFConnectionDiagnosticSourceHelper.cs | 9 ++-- .../EFDiagnosticSourceHelper.cs | 9 ++-- .../EFQueryCompilerDiagnosticSourceHelper.cs | 3 +- .../DiagnosticSource/SentryEFCoreListener.cs | 1 + .../DiagnosticSource/SentrySqlListener.cs | 18 +++---- 7 files changed, 46 insertions(+), 52 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs index cbdcf81845..20c8e70ff0 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/DiagnosticSourceConstants.cs @@ -1,35 +1,29 @@ -using System; -using System.Collections.Generic; -using System.Text; +namespace Sentry.Internal.DiagnosticSource; -namespace Sentry.Internal.DiagnosticSource +/// +/// Open Telemetry Keys +/// https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md +/// +internal static class OTelKeys { - /// - /// Open Telemetry Keys - /// - /// https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/database.md - /// - internal static class OTKeys - { - internal const string DbName = "db.name"; - } + internal const string DbName = "db.name"; +} - /// - /// Keys specific to the SqlClient listener - /// - internal static class SqlKeys - { - internal const string DbConnectionId = "db.connection_id"; - internal const string DbOperationId = "db.operation_id"; - } +/// +/// Keys specific to the SqlClient listener +/// +internal static class SqlKeys +{ + internal const string DbConnectionId = "db.connection_id"; + internal const string DbOperationId = "db.operation_id"; +} - /// - /// Keys specific to the Entity Framework listener - /// - internal static class EFKeys - { - // Entity Framework specific - internal const string DbConnectionId = "db.connection_id"; - internal const string DbCommandId = "db.command_id"; - } +/// +/// Keys specific to the Entity Framework listener +/// +internal static class EFKeys +{ + // Entity Framework specific + internal const string DbConnectionId = "db.connection_id"; + internal const string DbCommandId = "db.command_id"; } diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index e4c689cfc6..1d600b7365 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -10,7 +10,9 @@ internal EFCommandDiagnosticSourceHelper(IHub hub, SentryOptions options) : base } protected override string Operation => "db.query"; - protected override string Description(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; + + protected override string GetDescription(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; + private static Guid? GetCommandId(object? diagnosticSourceValue) => diagnosticSourceValue?.GetGuidProperty("CommandId"); private static void SetCommandId(ISpan span, Guid? commandId) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index 6b33dbe32f..ace59bb1a3 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -10,9 +10,10 @@ internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : b } protected override string Operation => "db.connection"; - protected override string Description(object? diagnosticSourceValue) => DatabaseName(diagnosticSourceValue); - private string DatabaseName(object? diagnosticSourceValue) => + protected override string GetDescription(object? diagnosticSourceValue) => GetDatabaseName(diagnosticSourceValue); + + private static string GetDatabaseName(object? diagnosticSourceValue) => diagnosticSourceValue?.GetStringProperty("Connection.Database") ?? null!; protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) @@ -31,9 +32,9 @@ private string DatabaseName(object? diagnosticSourceValue) => protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) { - if (DatabaseName(diagnosticSourceValue) is { } databaseName) + if (GetDatabaseName(diagnosticSourceValue) is { } databaseName) { - span.SetExtra(OTKeys.DbName, databaseName); + span.SetExtra(OTelKeys.DbName, databaseName); } if (GetConnectionId(diagnosticSourceValue) is { } connectionId) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index b8936d1e12..0bd60943b6 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -8,7 +8,8 @@ internal abstract class EFDiagnosticSourceHelper protected SentryOptions Options { get; } protected ITransaction? Transaction { get; } protected abstract string Operation { get; } - protected abstract string Description(object? diagnosticSourceValue); + + protected abstract string GetDescription(object? diagnosticSourceValue); internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) { @@ -39,14 +40,12 @@ internal void AddSpan(object? diagnosticSourceValue) // We "flatten" the EF spans so that they all have the same parent span, for two reasons: // 1. Each command typically gets it's own connection, which makes the resulting waterfall diagram hard to read. // 2. Sentry's performance errors functionality only works when all queries have the same parent span. - var parent = GetParentSpan(Transaction, diagnosticSourceValue); - var child = parent.StartChild(Operation, Description(diagnosticSourceValue)); + var parent = Transaction.GetDbParentSpan(); + var child = parent.StartChild(Operation, GetDescription(diagnosticSourceValue)); SetSpanReference(child, diagnosticSourceValue); } - protected virtual ISpan GetParentSpan(ITransaction transaction, object? diagnosticSourceValue) => transaction.GetDbParentSpan(); - internal void FinishSpan(object? diagnosticSourceValue, SpanStatus status) { if (Transaction == null) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs index 70045587f3..c056ab0da0 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFQueryCompilerDiagnosticSourceHelper.cs @@ -7,7 +7,8 @@ internal EFQueryCompilerDiagnosticSourceHelper(IHub hub, SentryOptions options) } protected override string Operation => "db.query.compile"; - protected override string Description(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; + + protected override string GetDescription(object? diagnosticSourceValue) => FilterNewLineValue(diagnosticSourceValue) ?? string.Empty; /// /// We don't have a correlation id for compiled query events. We just return the first unfinished query compile span. diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs index 883e97ecc3..626c5a6f7c 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentryEFCoreListener.cs @@ -18,6 +18,7 @@ internal class SentryEFCoreListener : IObserver> /// /// internal const string EFQueryStartCompiling = "Microsoft.EntityFrameworkCore.Query.QueryCompilationStarting"; + /// /// Used for EF Core 2.X and 3.X. /// diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index b05f167674..a83ba965a9 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -42,7 +42,7 @@ private static void SetDatabaseName(ISpan span, string databaseName) { Debug.Assert(databaseName != string.Empty); - span.SetExtra(OTKeys.DbName, databaseName); + span.SetExtra(OTelKeys.DbName, databaseName); } private static void SetConnectionId(ISpan span, Guid? connectionId) @@ -60,9 +60,10 @@ private static void SetOperationId(ISpan span, Guid? operationId) } private static Guid? TryGetOperationId(ISpan span) => span.Extra.TryGetValue(SqlKeys.DbOperationId); + private static Guid? TryGetConnectionId(ISpan span) => span.Extra.TryGetValue(SqlKeys.DbConnectionId); - private void AddSpan(SentrySqlSpanType type, string operation, object? value) + private void AddSpan(string operation, object? value) { var transaction = _hub.GetTransactionIfSampled(); if (transaction == null) @@ -117,9 +118,6 @@ private void AddSpan(SentrySqlSpanType type, string operation, object? value) } } - private static ISpan? TryStartChild(ISpan? parent, string operation, string? description) => - parent?.StartChild(operation, description); - private static ISpan? TryGetConnectionSpan(ITransaction transaction, Guid? connectionId) => connectionId == null ? null @@ -155,14 +153,12 @@ private void UpdateConnectionSpan(object? value) var spans = transaction.Spans.Where(span => span.Operation is "db.connection").ToList(); if (spans.Find(span => !span.IsFinished && TryGetOperationId(span) == operationId) is { } connectionSpan) { - var connectionId = value.GetGuidProperty("ConnectionId"); - if (connectionId.HasValue) + if (value.GetGuidProperty("ConnectionId") is { } connectionId) { SetConnectionId(connectionSpan, connectionId); } - var database = value.GetStringProperty("Connection.Database"); - if (database is { } dbName) + if (value.GetStringProperty("Connection.Database") is { } dbName) { connectionSpan.Description = dbName; SetDatabaseName(connectionSpan, dbName); @@ -182,7 +178,7 @@ public void OnNext(KeyValuePair kvp) { // Query case SqlMicrosoftBeforeExecuteCommand or SqlDataBeforeExecuteCommand: - AddSpan(SentrySqlSpanType.Execution, "db.query", kvp.Value); + AddSpan("db.query", kvp.Value); return; case SqlMicrosoftAfterExecuteCommand or SqlDataAfterExecuteCommand when GetSpan(SentrySqlSpanType.Execution, kvp) is { } commandSpan: @@ -197,7 +193,7 @@ when GetSpan(SentrySqlSpanType.Execution, kvp) is { } errorSpan: // Connection case SqlMicrosoftWriteConnectionOpenBeforeCommand or SqlDataWriteConnectionOpenBeforeCommand: - AddSpan(SentrySqlSpanType.Connection, "db.connection", kvp.Value); + AddSpan("db.connection", kvp.Value); return; case SqlMicrosoftWriteConnectionOpenAfterCommand or SqlDataWriteConnectionOpenAfterCommand: UpdateConnectionSpan(kvp.Value); From 1b100f2b0949e3c3a872bd1fd0f05ed75de01163 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 9 Jun 2023 09:39:12 +1200 Subject: [PATCH 26/32] Fixed typos --- .../SentryEFCoreListenerTests.cs | 4 ++-- test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 2e7f083f44..605ce635b6 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -259,7 +259,7 @@ public void OnNext_HappyPath_IsValid() // Check DB Name is stored correctly var dbName = - connectionSpan.Extra.TryGetValue(OTKeys.DbName); + connectionSpan.Extra.TryGetValue(OTelKeys.DbName); Assert.Equal(expectedDbName, dbName); // Check connections between spans. @@ -316,7 +316,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() // Check DB Name is stored correctly var dbName = - connectionSpan.Extra.TryGetValue(OTKeys.DbName); + connectionSpan.Extra.TryGetValue(OTelKeys.DbName); Assert.Equal(expectedDbName, dbName); // Check connections between spans. diff --git a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs index f0b5c30af3..9b110b475f 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs @@ -249,7 +249,7 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio Assert.Equal(dbName, connectionSpan.Description); Assert.Equal(connectionOperationId, connectionSpan.Extra.TryGetValue(SqlKeys.DbOperationId)); Assert.Equal(connectionId, connectionSpan.Extra.TryGetValue(SqlKeys.DbConnectionId)); - Assert.Equal(dbName, connectionSpan.Extra.TryGetValue(OTKeys.DbName)); + Assert.Equal(dbName, connectionSpan.Extra.TryGetValue(OTelKeys.DbName)); } [Theory] From 518695390a4870acfc529f3f7be876c61c0270b1 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 9 Jun 2023 10:05:43 +1200 Subject: [PATCH 27/32] EFCommand operations now record the db.name in the Span.Extra properties --- .../EFCommandDiagnosticSourceHelper.cs | 5 +++ .../EFConnectionDiagnosticSourceHelper.cs | 5 +-- .../EFDiagnosticSourceHelper.cs | 5 ++- .../SentryEFCoreListenerTests.cs | 36 ++++++++++--------- 4 files changed, 29 insertions(+), 22 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs index 1d600b7365..a710b12767 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFCommandDiagnosticSourceHelper.cs @@ -40,6 +40,11 @@ private static void SetCommandId(ISpan span, Guid? commandId) protected override void SetSpanReference(ISpan span, object? diagnosticSourceValue) { + if (GetDatabaseName(diagnosticSourceValue) is { } databaseName) + { + span.SetExtra(OTelKeys.DbName, databaseName); + } + if (GetCommandId(diagnosticSourceValue) is { } commandId) { SetCommandId(span, commandId); diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs index ace59bb1a3..a62376a1cf 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFConnectionDiagnosticSourceHelper.cs @@ -11,10 +11,7 @@ internal EFConnectionDiagnosticSourceHelper(IHub hub, SentryOptions options) : b protected override string Operation => "db.connection"; - protected override string GetDescription(object? diagnosticSourceValue) => GetDatabaseName(diagnosticSourceValue); - - private static string GetDatabaseName(object? diagnosticSourceValue) => - diagnosticSourceValue?.GetStringProperty("Connection.Database") ?? null!; + protected override string? GetDescription(object? diagnosticSourceValue) => GetDatabaseName(diagnosticSourceValue); protected override ISpan? GetSpanReference(ITransaction transaction, object? diagnosticSourceValue) { diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs index 0bd60943b6..f87e84ccd8 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/EFDiagnosticSourceHelper.cs @@ -9,7 +9,10 @@ internal abstract class EFDiagnosticSourceHelper protected ITransaction? Transaction { get; } protected abstract string Operation { get; } - protected abstract string GetDescription(object? diagnosticSourceValue); + protected abstract string? GetDescription(object? diagnosticSourceValue); + + protected static string? GetDatabaseName(object? diagnosticSourceValue) => + diagnosticSourceValue?.GetStringProperty("Connection.Database"); internal EFDiagnosticSourceHelper(IHub hub, SentryOptions options) { diff --git a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs index 605ce635b6..ccd75ebf5e 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentryEFCoreListenerTests.cs @@ -190,26 +190,25 @@ private class FakeDiagnosticEventData public FakeDiagnosticEventData(string value) { _value = value; } private readonly string _value; public override string ToString()=> _value; + + public class ConnectionInfo + { + public string Database { get; } = "rentals"; + } + public ConnectionInfo Connection { get; } = new(); } private class FakeDiagnosticConnectionEventData : FakeDiagnosticEventData { public FakeDiagnosticConnectionEventData(string value) : base(value) { } public Guid ConnectionId { get; } = Guid.NewGuid(); - - public ConnectionInfo Connection { get; } = new ConnectionInfo(); - - public class ConnectionInfo - { - public string Database { get; } = "rentals"; - } } private class FakeDiagnosticCommandEventData : FakeDiagnosticEventData { - public FakeDiagnosticCommandEventData(Guid connectionId, string value) : base(value) + public FakeDiagnosticCommandEventData(FakeDiagnosticConnectionEventData connection, string value) : base(value) { - ConnectionId = connectionId; + ConnectionId = connection.ConnectionId; } public Guid ConnectionId { get; set; } @@ -229,7 +228,7 @@ public void OnNext_HappyPath_IsValid() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData, efSql); // Act interceptor.OnNext(new(EFQueryCompiling, queryEventData)); @@ -258,9 +257,12 @@ public void OnNext_HappyPath_IsValid() Assert.Equal(expectedSql, commandSpan.Description); // Check DB Name is stored correctly - var dbName = + var connectionDbName = connectionSpan.Extra.TryGetValue(OTelKeys.DbName); - Assert.Equal(expectedDbName, dbName); + Assert.Equal(expectedDbName, connectionDbName); + var commandDbName = + commandSpan.Extra.TryGetValue(OTelKeys.DbName); + Assert.Equal(expectedDbName, commandDbName); // Check connections between spans. Assert.Equal(_fixture.Tracer.SpanId, compilerSpan.ParentSpanId); @@ -284,7 +286,7 @@ public void OnNext_HappyPathInsideChildSpan_IsValid() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData, efSql); // Act var childSpan = _fixture.Tracer.StartChild("Child Span"); @@ -340,7 +342,7 @@ public void OnNext_HappyPathWithError_TransactionWithErroredCommand() var queryEventData = new FakeDiagnosticEventData(efSql); var connectionEventData = new FakeDiagnosticConnectionEventData(efConn); - var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData.ConnectionId, efSql); + var commandEventData = new FakeDiagnosticCommandEventData(connectionEventData, efSql); // Act interceptor.OnNext(new(EFQueryCompiling, queryEventData)); @@ -409,9 +411,9 @@ public void OnNext_Same_Connections_Consolidated() // Fake a connection pool with two connections var connectionA = new FakeDiagnosticConnectionEventData(efConn); var connectionB = new FakeDiagnosticConnectionEventData(efConn); - var commandA = new FakeDiagnosticCommandEventData(connectionA.ConnectionId, efSql); - var commandB = new FakeDiagnosticCommandEventData(connectionB.ConnectionId, efSql); - var commandC = new FakeDiagnosticCommandEventData(connectionA.ConnectionId, efSql); + var commandA = new FakeDiagnosticCommandEventData(connectionA, efSql); + var commandB = new FakeDiagnosticCommandEventData(connectionB, efSql); + var commandC = new FakeDiagnosticCommandEventData(connectionA, efSql); void Pause() => Thread.Sleep(200); From ab02ef957b1d41199bf4685ad71a580b252a0fbd Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 9 Jun 2023 14:39:54 +1200 Subject: [PATCH 28/32] SqlClient diagnostics listeners now record the db.name --- .../Internal/DiagnosticSource/SentrySqlListener.cs | 2 ++ .../SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt | 2 ++ .../SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt | 2 ++ .../SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt | 2 ++ .../SqlListenerTests.RecordsSqlAsync.verified.txt | 2 ++ test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs | 5 +++++ 6 files changed, 15 insertions(+) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index a83ba965a9..cfddfa5655 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -1,3 +1,4 @@ +using System.Xml.Linq; using Sentry.Extensibility; using Sentry.Internal.Extensions; @@ -183,6 +184,7 @@ public void OnNext(KeyValuePair kvp) case SqlMicrosoftAfterExecuteCommand or SqlDataAfterExecuteCommand when GetSpan(SentrySqlSpanType.Execution, kvp) is { } commandSpan: commandSpan.Description = kvp.Value?.GetStringProperty("Command.CommandText"); + SetDatabaseName(commandSpan, kvp.Value?.GetStringProperty("Connection.Database")!); commandSpan.Finish(SpanStatus.Ok); return; case SqlMicrosoftWriteCommandError or SqlDataWriteCommandError diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt index 522bbd4d67..b818474e7b 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt @@ -75,6 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_3 } }, @@ -95,6 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt index 522bbd4d67..b818474e7b 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt @@ -75,6 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_3 } }, @@ -95,6 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt index 522bbd4d67..b818474e7b 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt @@ -75,6 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_3 } }, @@ -95,6 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt index bc32616206..0f240c6767 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt @@ -67,6 +67,7 @@ IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_3 } }, @@ -78,6 +79,7 @@ IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: null, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs index 9b110b475f..9b316ec21c 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs @@ -207,6 +207,10 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio { OperationId = queryOperationId, ConnectionId = connectionId, + Connection = new + { + Database = dbName + }, Command = new { CommandText = query @@ -245,6 +249,7 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio Assert.Equal(query, commandSpan.Description); Assert.Equal(queryOperationId, commandSpan.Extra.TryGetValue(SqlKeys.DbOperationId)); Assert.Equal(connectionId, commandSpan.Extra.TryGetValue(SqlKeys.DbConnectionId)); + Assert.Equal(dbName, commandSpan.Extra.TryGetValue(OTelKeys.DbName)); Assert.Equal(dbName, connectionSpan.Description); Assert.Equal(connectionOperationId, connectionSpan.Extra.TryGetValue(SqlKeys.DbOperationId)); From 44397286d814e349cd56765c9db1a73b89dfe6fd Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 9 Jun 2023 15:41:01 +1200 Subject: [PATCH 29/32] Added db.name to Query spans in the SentrySqlListener --- .../DiagnosticSource/SentrySqlListener.cs | 58 +++++++++++++------ ...rTests.LoggingAsync.DotNet6_0.verified.txt | 1 + ...rTests.LoggingAsync.DotNet7_0.verified.txt | 1 + ...rTests.RecordsEfAsync.Core3_1.verified.txt | 4 +- ...ests.RecordsEfAsync.DotNet6_0.verified.txt | 4 +- ...ests.RecordsEfAsync.DotNet7_0.verified.txt | 4 +- ...ListenerTests.RecordsSqlAsync.verified.txt | 4 +- .../SentrySqlListenerTests.cs | 10 +--- 8 files changed, 51 insertions(+), 35 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index cfddfa5655..ba08998734 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -1,4 +1,3 @@ -using System.Xml.Linq; using Sentry.Extensibility; using Sentry.Internal.Extensions; @@ -72,15 +71,13 @@ private void AddSpan(string operation, object? value) return; } - var operationId = value?.GetGuidProperty("OperationId"); - var connectionId = value?.GetGuidProperty("ConnectionId"); var parent = transaction.GetDbParentSpan(); var span = parent.StartChild(operation); - SetOperationId(span, operationId); - SetConnectionId(span, connectionId); + SetOperationId(span, value?.GetGuidProperty("OperationId")); + SetConnectionId(span, value?.GetGuidProperty("ConnectionId")); } - private ISpan? GetSpan(SentrySqlSpanType type, KeyValuePair kvp) + private ISpan? GetSpan(SentrySqlSpanType type, object? value) { var transaction = _hub.GetTransactionIfSampled(); if (transaction == null) @@ -91,7 +88,7 @@ private void AddSpan(string operation, object? value) switch (type) { case SentrySqlSpanType.Execution: - var operationId = kvp.Value?.GetGuidProperty("OperationId"); + var operationId = value?.GetGuidProperty("OperationId"); if (TryGetQuerySpan(transaction, operationId) is { } querySpan) { return querySpan; @@ -103,7 +100,7 @@ private void AddSpan(string operation, object? value) return null; case SentrySqlSpanType.Connection: - var connectionId = kvp.Value?.GetGuidProperty("ConnectionId"); + var connectionId = value?.GetGuidProperty("ConnectionId"); if (TryGetConnectionSpan(transaction, connectionId) is { } connectionSpan) { return connectionSpan; @@ -167,6 +164,36 @@ private void UpdateConnectionSpan(object? value) } } + private void FinishCommandSpan(object? value, SpanStatus spanStatus) + { + if (value == null) + { + return; + } + + + if (GetSpan(SentrySqlSpanType.Execution, value) is not { } commandSpan) + { + return; + } + + // Try to lookup the associated connection span so that we can store the db.name in + // the command span as well. This will be easier for users to read/identify than the + // ConnectionId (which is a Guid) + var connectionId = value?.GetGuidProperty("ConnectionId"); + var transaction = _hub.GetTransactionIfSampled(); + if (TryGetConnectionSpan(transaction!, connectionId) is { } connectionSpan) + { + if (connectionSpan.Extra.TryGetValue(OTelKeys.DbName) is { } dbName) + { + SetDatabaseName(commandSpan, dbName); + } + } + + commandSpan.Description = value?.GetStringProperty("Command.CommandText"); + commandSpan.Finish(spanStatus); + } + public void OnCompleted() { } public void OnError(Exception error) { } @@ -181,16 +208,11 @@ public void OnNext(KeyValuePair kvp) case SqlMicrosoftBeforeExecuteCommand or SqlDataBeforeExecuteCommand: AddSpan("db.query", kvp.Value); return; - case SqlMicrosoftAfterExecuteCommand or SqlDataAfterExecuteCommand - when GetSpan(SentrySqlSpanType.Execution, kvp) is { } commandSpan: - commandSpan.Description = kvp.Value?.GetStringProperty("Command.CommandText"); - SetDatabaseName(commandSpan, kvp.Value?.GetStringProperty("Connection.Database")!); - commandSpan.Finish(SpanStatus.Ok); + case SqlMicrosoftAfterExecuteCommand or SqlDataAfterExecuteCommand: + FinishCommandSpan(kvp.Value, SpanStatus.Ok); return; - case SqlMicrosoftWriteCommandError or SqlDataWriteCommandError - when GetSpan(SentrySqlSpanType.Execution, kvp) is { } errorSpan: - errorSpan.Description = kvp.Value?.GetStringProperty("Command.CommandText"); - errorSpan.Finish(SpanStatus.InternalError); + case SqlMicrosoftWriteCommandError or SqlDataWriteCommandError: + FinishCommandSpan(kvp.Value, SpanStatus.InternalError); return; // Connection @@ -201,7 +223,7 @@ when GetSpan(SentrySqlSpanType.Execution, kvp) is { } errorSpan: UpdateConnectionSpan(kvp.Value); return; case SqlMicrosoftWriteConnectionCloseAfterCommand or SqlDataWriteConnectionCloseAfterCommand - when GetSpan(SentrySqlSpanType.Connection, kvp) is { } closeSpan: + when GetSpan(SentrySqlSpanType.Connection, kvp.Value) is { } closeSpan: TrySetConnectionStatistics(closeSpan, kvp.Value); closeSpan.Finish(SpanStatus.Ok); return; diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt index 361d7ff6c2..976514b4d6 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet6_0.verified.txt @@ -94,6 +94,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_LoggingAsync, db.operation_id: Guid_3 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt index 361d7ff6c2..976514b4d6 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.LoggingAsync.DotNet7_0.verified.txt @@ -94,6 +94,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, + db.name: SqlListenerTests.verify_LoggingAsync, db.operation_id: Guid_3 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt index b818474e7b..fe0379b158 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.Core3_1.verified.txt @@ -75,7 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_3 } }, @@ -96,7 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt index b818474e7b..fe0379b158 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet6_0.verified.txt @@ -75,7 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_3 } }, @@ -96,7 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt index b818474e7b..fe0379b158 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsEfAsync.DotNet7_0.verified.txt @@ -75,7 +75,7 @@ WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity(); IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_3 } }, @@ -96,7 +96,7 @@ FROM [TestEntities] AS [t], IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsEfAsync, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt index 0f240c6767..cd64fd0e6d 100644 --- a/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt +++ b/test/Sentry.DiagnosticSource.IntegrationTests/SqlListenerTests.RecordsSqlAsync.verified.txt @@ -67,7 +67,7 @@ IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsSqlAsync, db.operation_id: Guid_3 } }, @@ -79,7 +79,7 @@ IsSampled: true, Extra: { db.connection_id: Guid_1, - db.name: null, + db.name: SqlListenerTests.verify_RecordsSqlAsync, db.operation_id: Guid_4 } } diff --git a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs index 9b316ec21c..32bcc61b36 100644 --- a/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs +++ b/test/Sentry.DiagnosticSource.Tests/SentrySqlListenerTests.cs @@ -207,10 +207,6 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio { OperationId = queryOperationId, ConnectionId = connectionId, - Connection = new - { - Database = dbName - }, Command = new { CommandText = query @@ -221,11 +217,7 @@ public void OnNext_HappyPaths_IsValid(string connectionOpenKey, string connectio new { OperationId = connectionOperationIdClosed, - ConnectionId = connectionId, - Connection = new - { - Database = dbName - } + ConnectionId = connectionId })); // Assert From b8a24ae7f0b0bf75dc656ce1a917e0ca1fa42d52 Mon Sep 17 00:00:00 2001 From: James Crosswell Date: Fri, 9 Jun 2023 15:48:47 +1200 Subject: [PATCH 30/32] Update CHANGELOG.md --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 95cef3fd90..fbc7dd69fd 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,7 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) - Fix db connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) +- Fix sql client db name ([#2418](https://github.com/getsentry/sentry-dotnet/pull/2418)) - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. - The device architecture (x64, arm64, etc.) is now reported From 21af27cb6481436103ec8d8fdb137474f800a4f7 Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Mon, 12 Jun 2023 09:06:54 -0700 Subject: [PATCH 31/32] nits --- .../Internal/DiagnosticSource/SentrySqlListener.cs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs index ba08998734..326d60a509 100644 --- a/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs +++ b/src/Sentry.DiagnosticSource/Internal/DiagnosticSource/SentrySqlListener.cs @@ -177,10 +177,10 @@ private void FinishCommandSpan(object? value, SpanStatus spanStatus) return; } - // Try to lookup the associated connection span so that we can store the db.name in + // Try to lookup the associated connection span so that we can store the db.name in // the command span as well. This will be easier for users to read/identify than the // ConnectionId (which is a Guid) - var connectionId = value?.GetGuidProperty("ConnectionId"); + var connectionId = value.GetGuidProperty("ConnectionId"); var transaction = _hub.GetTransactionIfSampled(); if (TryGetConnectionSpan(transaction!, connectionId) is { } connectionSpan) { @@ -190,7 +190,7 @@ private void FinishCommandSpan(object? value, SpanStatus spanStatus) } } - commandSpan.Description = value?.GetStringProperty("Command.CommandText"); + commandSpan.Description = value.GetStringProperty("Command.CommandText"); commandSpan.Finish(spanStatus); } From 006c404502f1ef7a8a602a7eb68c6960c9f96adc Mon Sep 17 00:00:00 2001 From: Matt Johnson-Pint Date: Mon, 12 Jun 2023 09:08:14 -0700 Subject: [PATCH 32/32] Update CHANGELOG.md --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fbc7dd69fd..b3294b7a23 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,7 +7,6 @@ - SentryHttpMessageHandler added when AddHttpClient is before UseSentry ([#2390](https://github.com/getsentry/sentry-dotnet/pull/2390)) - Set the native sdk name for Android ([#2389](https://github.com/getsentry/sentry-dotnet/pull/2389)) - Fix db connection spans not finishing ([#2398](https://github.com/getsentry/sentry-dotnet/pull/2398)) -- Fix sql client db name ([#2418](https://github.com/getsentry/sentry-dotnet/pull/2418)) - Various .NET MAUI fixes / improvements ([#2403](https://github.com/getsentry/sentry-dotnet/pull/2403)) - The battery level was being reported incorrectly due to percentage multiplier. - The device architecture (x64, arm64, etc.) is now reported @@ -19,6 +18,7 @@ - DB Connection spans presented poorly ([#2409](https://github.com/getsentry/sentry-dotnet/pull/2409)) - Populate scope's Cookies property ([#2411](https://github.com/getsentry/sentry-dotnet/pull/2411)) - Fix UWP GateKeeper errors ([#2415](https://github.com/getsentry/sentry-dotnet/pull/2415)) +- Fix sql client db name ([#2418](https://github.com/getsentry/sentry-dotnet/pull/2418)) ### Dependencies