diff --git a/src/MongoDB.Driver/Core/Connections/BinaryConnection.cs b/src/MongoDB.Driver/Core/Connections/BinaryConnection.cs index 43a5723dab1..3afd74bfc53 100644 --- a/src/MongoDB.Driver/Core/Connections/BinaryConnection.cs +++ b/src/MongoDB.Driver/Core/Connections/BinaryConnection.cs @@ -155,7 +155,11 @@ private void ConnectionFailed(Exception exception) { _failedEventHasBeenRaised = true; _eventLogger.LogAndPublish(new ConnectionFailedEvent(_connectionId, exception)); - _commandEventHelper.ConnectionFailed(_connectionId, _description?.ServiceId, exception, IsInitializing); + + if (_commandEventHelper.ShouldCallConnectionFailed) + { + _commandEventHelper.ConnectionFailed(_connectionId, _description?.ServiceId, exception, IsInitializing); + } } } diff --git a/src/MongoDB.Driver/Core/Connections/CommandEventHelper.cs b/src/MongoDB.Driver/Core/Connections/CommandEventHelper.cs index 049d5630bd8..f24ec0e3060 100644 --- a/src/MongoDB.Driver/Core/Connections/CommandEventHelper.cs +++ b/src/MongoDB.Driver/Core/Connections/CommandEventHelper.cs @@ -34,14 +34,14 @@ namespace MongoDB.Driver.Core.Connections internal class CommandEventHelper { private readonly EventLogger _eventLogger; - private readonly ConcurrentDictionary _state; + private ConcurrentDictionary _state; - private readonly bool _shouldProcessRequestMessages; + private readonly bool _eventsNeedBeforeSending; private readonly bool _shouldTrackStarted; - private readonly bool _shouldTrackState; + private readonly bool _eventsNeedState; private readonly bool _shouldTrackFailed; private readonly bool _shouldTrackSucceeded; - private readonly bool _shouldTrace; + private readonly bool _tracingDisabled; private readonly int _queryTextMaxLength; private Activity _currentCommandActivity; @@ -54,13 +54,13 @@ public CommandEventHelper(EventLogger eventLogger, Tracin _shouldTrackFailed = _eventLogger.IsEventTracked(); _shouldTrackStarted = _eventLogger.IsEventTracked(); - _shouldTrace = tracingOptions?.Disabled != true && MongoTelemetry.ActivitySource.HasListeners(); + _tracingDisabled = tracingOptions?.Disabled == true; _queryTextMaxLength = tracingOptions?.QueryTextMaxLength ?? 0; - _shouldTrackState = _shouldTrackSucceeded || _shouldTrackFailed || _shouldTrace; - _shouldProcessRequestMessages = _shouldTrackStarted || _shouldTrackState; + _eventsNeedState = _shouldTrackSucceeded || _shouldTrackFailed; + _eventsNeedBeforeSending = _shouldTrackStarted || _eventsNeedState; - if (_shouldTrackState) + if (_eventsNeedState) { // we only need to track state if we have to raise // a succeeded or failed event or for tracing @@ -68,30 +68,20 @@ public CommandEventHelper(EventLogger eventLogger, Tracin } } - public bool ShouldCallBeforeSending - { - get { return _shouldProcessRequestMessages; } - } + public bool ShouldCallBeforeSending => _eventsNeedBeforeSending || ShouldTraceWithActivityListener(); - public bool ShouldCallAfterSending - { - get { return _shouldTrackState; } - } + public bool ShouldCallAfterSending => _eventsNeedState || ShouldTraceWithActivityListener(); - public bool ShouldCallErrorSending - { - get { return _shouldTrackState; } - } + public bool ShouldCallErrorSending => _eventsNeedState || ShouldTraceWithActivityListener(); - public bool ShouldCallAfterReceiving - { - get { return _shouldTrackState; } - } + public bool ShouldCallAfterReceiving => _eventsNeedState || ShouldTraceWithActivityListener(); - public bool ShouldCallErrorReceiving - { - get { return _shouldTrackState; } - } + public bool ShouldCallErrorReceiving => _eventsNeedState || ShouldTraceWithActivityListener(); + + public bool ShouldCallConnectionFailed => (_shouldTrackFailed || ShouldTraceWithActivityListener()) && _state != null; + + private bool ShouldTraceWithActivityListener() + => !_tracingDisabled && MongoTelemetry.ActivitySource.HasListeners(); public void CompleteFailedCommandActivity(Exception exception) { @@ -129,8 +119,12 @@ public void BeforeSending( public void AfterSending(RequestMessage message, ConnectionId connectionId, ObjectId? serviceId, bool skipLogging) { - CommandState state; - if (_state.TryGetValue(message.RequestId, out state) && + if (_state == null) + { + return; + } + + if (_state.TryGetValue(message.RequestId, out var state) && state.ExpectedResponseType == ExpectedResponseType.None) { state.Stopwatch.Stop(); @@ -157,12 +151,16 @@ public void AfterSending(RequestMessage message, ConnectionId connectionId, Obje public void ErrorSending(RequestMessage message, ConnectionId connectionId, ObjectId? serviceId, Exception exception, bool skipLogging) { - CommandState state; - if (_state.TryRemove(message.RequestId, out state)) + if (_state == null) { - state.Stopwatch.Stop(); + return; + } + + CompleteFailedCommandActivity(exception); - CompleteCommandActivityWithException(exception); + if (_state.TryRemove(message.RequestId, out var state)) + { + state.Stopwatch.Stop(); _eventLogger.LogAndPublish(new CommandFailedEvent( state.CommandName, @@ -179,8 +177,12 @@ public void ErrorSending(RequestMessage message, ConnectionId connectionId, Obje public void AfterReceiving(ResponseMessage message, IByteBuffer buffer, ConnectionId connectionId, ObjectId? serviceId, MessageEncoderSettings encoderSettings, bool skipLogging) { - CommandState state; - if (!_state.TryRemove(message.ResponseTo, out state)) + if (_state == null) + { + return; + } + + if (!_state.TryRemove(message.ResponseTo, out var state)) { // this indicates a bug in the sending portion... return; @@ -198,8 +200,14 @@ public void AfterReceiving(ResponseMessage message, IByteBuffer buffer, Connecti public void ErrorReceiving(int responseTo, ConnectionId connectionId, ObjectId? serviceId, Exception exception, bool skipLogging) { - CommandState state; - if (!_state.TryRemove(responseTo, out state)) + if (_state == null) + { + return; + } + + CompleteFailedCommandActivity(exception); + + if (!_state.TryRemove(responseTo, out var state)) { // this indicates a bug in the sending portion... return; @@ -207,8 +215,6 @@ public void ErrorReceiving(int responseTo, ConnectionId connectionId, ObjectId? state.Stopwatch.Stop(); - CompleteCommandActivityWithException(exception); - _eventLogger.LogAndPublish(new CommandFailedEvent( state.CommandName, state.QueryNamespace.DatabaseNamespace, @@ -223,12 +229,7 @@ public void ErrorReceiving(int responseTo, ConnectionId connectionId, ObjectId? public void ConnectionFailed(ConnectionId connectionId, ObjectId? serviceId, Exception exception, bool skipLogging) { - if (!_shouldTrackFailed && !_shouldTrace) - { - return; - } - - CompleteCommandActivityWithException(exception); + CompleteFailedCommandActivity(exception); var requestIds = _state.Keys; foreach (var requestId in requestIds) @@ -731,11 +732,15 @@ private void TrackCommandState( BsonDocument sessionId, long? transactionNumber) { - if (!_shouldTrackState) + var shouldTraceCommand = ShouldTraceWithActivityListener() && !shouldRedactCommand && !skipLogging; + + if (!_eventsNeedState && !shouldTraceCommand) { return; } + _state ??= new ConcurrentDictionary(); + var commandState = new CommandState { CommandName = commandName, @@ -746,7 +751,7 @@ private void TrackCommandState( ShouldRedactReply = shouldRedactCommand }; - if (_shouldTrace && !shouldRedactCommand && !skipLogging) + if (shouldTraceCommand) { _currentCommandActivity = MongoTelemetry.StartCommandActivity( commandName, @@ -770,16 +775,6 @@ private void CompleteCommandActivityWithSuccess(BsonDocument reply = null) } } - private void CompleteCommandActivityWithException(Exception exception) - { - if (_currentCommandActivity is not null) - { - MongoTelemetry.RecordException(_currentCommandActivity, exception); - _currentCommandActivity.Dispose(); - _currentCommandActivity = null; - } - } - private void HandleCommandFailure( CommandState state, BsonDocument reply, diff --git a/tests/MongoDB.Driver.Tests/Core/Connections/CommandEventHelperTests.cs b/tests/MongoDB.Driver.Tests/Core/Connections/CommandEventHelperTests.cs index ded46b101af..720c258f0f2 100644 --- a/tests/MongoDB.Driver.Tests/Core/Connections/CommandEventHelperTests.cs +++ b/tests/MongoDB.Driver.Tests/Core/Connections/CommandEventHelperTests.cs @@ -58,8 +58,7 @@ public void ShouldRedactCommand_should_return_expected_result(string commandJson public void ShouldTrackState_should_be_correct( [Values(false, true)] bool logCommands, [Values(false, true)] bool captureCommandSucceeded, - [Values(false, true)] bool captureCommandFailed, - [Values(false, true)] bool traceCommands) + [Values(false, true)] bool captureCommandFailed) { var mockLogger = new Mock>(); mockLogger.Setup(m => m.IsEnabled(LogLevel.Debug)).Returns(logCommands); @@ -76,16 +75,16 @@ public void ShouldTrackState_should_be_correct( } var eventLogger = new EventLogger(eventCapturer, mockLogger.Object); - var tracingOptions = traceCommands ? new TracingOptions() : new TracingOptions { Disabled = true }; + var tracingOptions = new TracingOptions { Disabled = true }; var commandHelper = new CommandEventHelper(eventLogger, tracingOptions); - // No ActivityListener, so tracing doesn't contribute to _shouldTrackState - commandHelper._shouldTrackState().Should().Be(logCommands || captureCommandSucceeded || captureCommandFailed); + // No ActivityListener, so tracing doesn't contribute to _eventsNeedState + commandHelper._eventsNeedState().Should().Be(logCommands || captureCommandSucceeded || captureCommandFailed); } [Theory] [ParameterAttributeData] - public void ShouldTrackState_should_be_correct_with_activity_listener( + public void Callbacks_turn_on_when_listener_is_added_even_if_no_events( [Values(false, true)] bool logCommands, [Values(false, true)] bool captureCommandSucceeded, [Values(false, true)] bool captureCommandFailed, @@ -94,13 +93,6 @@ public void ShouldTrackState_should_be_correct_with_activity_listener( ActivityListener listener = null; try { - listener = new ActivityListener - { - ShouldListenTo = source => source.Name == "MongoDB.Driver", - Sample = (ref ActivityCreationOptions _) => ActivitySamplingResult.AllData - }; - ActivitySource.AddActivityListener(listener); - var mockLogger = new Mock>(); mockLogger.Setup(m => m.IsEnabled(LogLevel.Debug)).Returns(logCommands); @@ -119,7 +111,27 @@ public void ShouldTrackState_should_be_correct_with_activity_listener( var tracingOptions = traceCommands ? new TracingOptions() : new TracingOptions { Disabled = true }; var commandHelper = new CommandEventHelper(eventLogger, tracingOptions); - commandHelper._shouldTrackState().Should().Be(logCommands || captureCommandSucceeded || captureCommandFailed || traceCommands); + // When there are no listeners, these only return true if logging is enabled or an event is registered, + // regardless of whether tracing is enabled. + commandHelper.ShouldCallBeforeSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands); + commandHelper.ShouldCallAfterSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands); + commandHelper.ShouldCallErrorSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands); + commandHelper.ShouldCallAfterReceiving.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands); + commandHelper.ShouldCallErrorReceiving.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands); + + listener = new ActivityListener + { + ShouldListenTo = source => source.Name == "MongoDB.Driver", + Sample = (ref ActivityCreationOptions _) => ActivitySamplingResult.AllData + }; + ActivitySource.AddActivityListener(listener); + + // With listeners registered, these always return true unless everything is disabled. + commandHelper.ShouldCallBeforeSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands || traceCommands); + commandHelper.ShouldCallAfterSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands || traceCommands); + commandHelper.ShouldCallErrorSending.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands || traceCommands); + commandHelper.ShouldCallAfterReceiving.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands || traceCommands); + commandHelper.ShouldCallErrorReceiving.Should().Be(captureCommandSucceeded || captureCommandFailed || logCommands || traceCommands); } finally { @@ -130,8 +142,8 @@ public void ShouldTrackState_should_be_correct_with_activity_listener( internal static class CommandEventHelperReflector { - public static bool _shouldTrackState(this CommandEventHelper commandEventHelper) => - (bool)Reflector.GetFieldValue(commandEventHelper, nameof(_shouldTrackState)); + public static bool _eventsNeedState(this CommandEventHelper commandEventHelper) => + (bool)Reflector.GetFieldValue(commandEventHelper, nameof(_eventsNeedState)); public static bool ShouldRedactCommand(BsonDocument command) => diff --git a/tests/SmokeTests/MongoDB.Driver.SmokeTests.Sdk/OpenTelemetryTests.cs b/tests/SmokeTests/MongoDB.Driver.SmokeTests.Sdk/OpenTelemetryTests.cs index b69d08d7650..a0d99c5fc63 100644 --- a/tests/SmokeTests/MongoDB.Driver.SmokeTests.Sdk/OpenTelemetryTests.cs +++ b/tests/SmokeTests/MongoDB.Driver.SmokeTests.Sdk/OpenTelemetryTests.cs @@ -26,7 +26,6 @@ namespace MongoDB.Driver.SmokeTests.Sdk [Trait("Category", "Integration")] public sealed class OpenTelemetryTests { - [Fact] public void MongoClient_should_create_activities_when_tracing_enabled() { @@ -84,7 +83,7 @@ public void MongoClient_should_not_create_activities_when_tracing_disabled() capturedActivities.Should().BeEmpty(); } - private static ActivityListener CreateActivityListener(out List capturedActivities) + private static ActivityListener CreateActivityListener(out IReadOnlyCollection capturedActivities) { var activities = new List(); var listener = new ActivityListener