diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_customizing_metric_tags.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_customizing_metric_tags.cs new file mode 100644 index 00000000000..e964f5faf57 --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_customizing_metric_tags.cs @@ -0,0 +1,110 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Metrics; + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Threading.Tasks; +using EndpointTemplates; +using NServiceBus; +using AcceptanceTesting; +using NServiceBus.Pipeline; +using NUnit.Framework; +using global::OpenTelemetry; +using global::OpenTelemetry.Metrics; + +public class When_customizing_metric_tags : OpenTelemetryAcceptanceTest +{ + const string TotalFetched = "nservicebus.messaging.fetches"; + const string MessageDeserializeTime = "nservicebus.messaging.deserialize_time"; + const string EndpointDiscriminatorTag = "nservicebus.discriminator"; + const string EnclosedMessageTypesTag = "nservicebus.enclosed_message_types"; + const string TenantTag = "acceptance.tenant_id"; + const string FriendlyMessageTypeName = "Order placed (friendly name)"; + + [Test] + public async Task Should_allow_adding_removing_and_overriding_tags_per_instrument() + { + using var metricsListener = TestingMetricListener.SetupNServiceBusMetricsListener(); + + List exportedMetrics = []; + using var meterProvider = Sdk.CreateMeterProviderBuilder() + .AddMeter("NServiceBus.Core.Pipeline.Incoming") + .AddView(TotalFetched, new MetricStreamConfiguration + { + TagKeys = ["nservicebus.queue", "nservicebus.message_type", TenantTag] + }) + .AddReader(new BaseExportingMetricReader(new CapturingExporter(exportedMetrics))) + .Build(); + + await Scenario.Define() + .WithEndpoint(b => b.CustomConfig(c => c.MakeInstanceUniquelyAddressable("disc")) + .When(async session => + { + var sendOptions = new SendOptions(); + sendOptions.RouteToThisEndpoint(); + sendOptions.SetHeader(TenantTag, "acme-corp"); + await session.Send(new MyMessage(), sendOptions); + })) + .Run(); + + meterProvider.ForceFlush(); + + metricsListener.AssertTags(TotalFetched, new Dictionary { [TenantTag] = "acme-corp" }); + + metricsListener.AssertTagKeyExists(TotalFetched, EndpointDiscriminatorTag); + + var overriddenValue = metricsListener.AssertTagKeyExists(MessageDeserializeTime, EnclosedMessageTypesTag); + Assert.That(overriddenValue, Is.EqualTo(FriendlyMessageTypeName)); + } + + public class Context : ScenarioContext; + + public class EndpointWithCustomTags : EndpointConfigurationBuilder + { + public EndpointWithCustomTags() => + EndpointSetup(c => c.Pipeline.Register( + new CustomizeMetricTagsBehavior(), "Adds a tenant tag from a header and overrides the enclosed message type tag")); + + [Handler] + public class MyHandler(Context testContext) : IHandleMessages + { + public Task Handle(MyMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + class CustomizeMetricTagsBehavior : Behavior + { + public override Task Invoke(IIncomingPhysicalMessageContext context, Func next) + { + var tags = context.MetricTags; + + if (context.Message.Headers.TryGetValue(TenantTag, out var tenantId)) + { + tags.AddOrOverride(TenantTag, tenantId, TotalFetched); + } + + tags.AddOrOverride(EnclosedMessageTypesTag, FriendlyMessageTypeName, MessageDeserializeTime); + + return next(); + } + } + + class CapturingExporter(List exportedMetrics) : BaseExporter + { + public override ExportResult Export(in Batch batch) + { + foreach (var metric in batch) + { + exportedMetrics.Add(metric); + } + + return ExportResult.Success; + } + } + + public class MyMessage : IMessage; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_envelope_handler_succeeds.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_envelope_handler_succeeds.cs index 16c7d1da43b..faca6eed9bb 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_envelope_handler_succeeds.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_envelope_handler_succeeds.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.Linq; using System.Threading.Tasks; +using Microsoft.ApplicationInsights.Extensibility; using NServiceBus; using NServiceBus.AcceptanceTesting; using NServiceBus.AcceptanceTests.Core.OpenTelemetry; diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_message_processing_fails.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_message_processing_fails.cs index 15a7172bde4..9c1aadacc89 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_message_processing_fails.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_message_processing_fails.cs @@ -51,7 +51,7 @@ public async Task Should_report_failing_message_metrics() ["nservicebus.discriminator"] = "disc", ["nservicebus.message_type"] = typeof(FailingMessage).FullName, ["execution.result"] = "failure", - ["error.type"] = typeof(SimulatedException).FullName, + ["error.type"] = typeof(SimulatedException).FullName }); } diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_messages_are_processed_concurrently.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_messages_are_processed_concurrently.cs new file mode 100644 index 00000000000..da6b3382f0e --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Metrics/When_messages_are_processed_concurrently.cs @@ -0,0 +1,72 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Metrics; + +using System.Collections.Generic; +using System.Threading; +using System.Threading.Tasks; +using EndpointTemplates; +using NServiceBus; +using AcceptanceTesting; +using NUnit.Framework; +using Conventions = AcceptanceTesting.Customization.Conventions; + +public class When_messages_are_processed_concurrently : OpenTelemetryAcceptanceTest +{ + const string ActiveMessagesMetric = "nservicebus.messaging.active_messages"; + const int numberOfMessages = 5; + + [Test] + public async Task Should_report_active_messages_gauge_that_balances_once_idle() + { + using var metricsListener = TestingMetricListener.SetupNServiceBusMetricsListener(); + + _ = await Scenario.Define() + .WithEndpoint(b => b.CustomConfig(c => + { + c.MakeInstanceUniquelyAddressable("instanceId"); + c.LimitMessageProcessingConcurrencyTo(10); + }).When(async (session, ctx) => + { + for (var x = 0; x < numberOfMessages; x++) + { + await session.SendLocal(new OutgoingMessage()); + } + })) + .Run(); + + Assert.That(metricsListener.ReportedMeters.TryGetValue(ActiveMessagesMetric, out var net), Is.True, + $"'{ActiveMessagesMetric}' gauge should be reported"); + Assert.That(net, Is.EqualTo(0), + "increments and decrements should balance once all messages have been processed"); + + metricsListener.AssertTags(ActiveMessagesMetric, + new Dictionary + { + ["nservicebus.queue"] = Conventions.EndpointNamingConvention(typeof(EndpointWithMetrics)), + ["nservicebus.discriminator"] = "instanceId", + ["nservicebus.enclosed_message_types"] = typeof(OutgoingMessage).AssemblyQualifiedName + }); + } + + public class Context : ScenarioContext + { + public int OutgoingMessagesReceived; + } + + public class EndpointWithMetrics : EndpointConfigurationBuilder + { + public EndpointWithMetrics() => EndpointSetup(); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(OutgoingMessage message, IMessageHandlerContext context) + { + var messagesHandled = Interlocked.Increment(ref testContext.OutgoingMessagesReceived); + testContext.MarkAsCompleted(messagesHandled == numberOfMessages); + return Task.CompletedTask; + } + } + } + + public class OutgoingMessage : IMessage; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/OpenTelemetryAcceptanceTest.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/OpenTelemetryAcceptanceTest.cs index 99b8b43ab54..a2748753077 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/OpenTelemetryAcceptanceTest.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/OpenTelemetryAcceptanceTest.cs @@ -9,7 +9,7 @@ public abstract class OpenTelemetryAcceptanceTest : NServiceBusAcceptanceTest protected TestingActivityListener NServiceBusActivityListener { get; private set; } [SetUp] - public void Setup() => NServiceBusActivityListener = TestingActivityListener.SetupDiagnosticListener("NServiceBus.Core"); + public void Setup() => NServiceBusActivityListener = TestingActivityListener.SetupDiagnosticListener("NServiceBus.Core", "NServiceBus.Core.Recoverability"); [TearDown] public void Cleanup() diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/TestingActivityListener.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/TestingActivityListener.cs index a5fdb5ce06a..38dc6113d83 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/TestingActivityListener.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/TestingActivityListener.cs @@ -11,19 +11,19 @@ public class TestingActivityListener : IDisposable { readonly ActivityListener activityListener; - public static TestingActivityListener SetupDiagnosticListener(string sourceName) + public static TestingActivityListener SetupDiagnosticListener(params string[] sourceNames) { - var testingListener = new TestingActivityListener(sourceName); + var testingListener = new TestingActivityListener(sourceNames); ActivitySource.AddActivityListener(testingListener.activityListener); return testingListener; } - TestingActivityListener(string sourceName = null) + TestingActivityListener(params string[] sourceNames) { activityListener = new ActivityListener { - ShouldListenTo = source => string.IsNullOrEmpty(sourceName) || source.Name == sourceName, + ShouldListenTo = source => sourceNames.Length == 0 || sourceNames.Contains(source.Name), Sample = (ref ActivityCreationOptions _) => ActivitySamplingResult.AllData, SampleUsingParentId = (ref ActivityCreationOptions options) => ActivitySamplingResult.AllData }; @@ -62,4 +62,5 @@ public static List GetReceiveMessageActivities(this ConcurrentQueue GetSendMessageActivities(this ConcurrentQueue activities) => activities.Where(a => a.OperationName == "NServiceBus.Diagnostics.SendMessage").ToList(); public static List GetPublishEventActivities(this ConcurrentQueue activities) => activities.Where(a => a.OperationName == "NServiceBus.Diagnostics.PublishMessage").ToList(); public static List GetInvokedHandlerActivities(this ConcurrentQueue activities) => activities.Where(a => a.OperationName == "NServiceBus.Diagnostics.InvokeHandler").ToList(); + public static List GetRecoverabilityActivities(this ConcurrentQueue activities) => activities.Where(a => a.OperationName == "NServiceBus.Diagnostics.Recoverability").ToList(); } diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_ambient_trace_in_message_session.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_ambient_trace_in_message_session.cs index 51ae62b9a41..6c3f58c65e5 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_ambient_trace_in_message_session.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_ambient_trace_in_message_session.cs @@ -15,7 +15,7 @@ public async Task Should_attach_to_ambient_trace() using var externalActivitySource = new ActivitySource("external trace source"); using var _ = TestingActivityListener.SetupDiagnosticListener(externalActivitySource.Name); // need to have a registered listener for activities to be created - const string wrapperActivityTraceState = "test trace state"; + const string wrapperActivityTraceState = "tracekey=traceValue"; var context = await Scenario.Define() .WithEndpoint(b => b diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_incoming_message_has_baggage_header.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_incoming_message_has_baggage_header.cs index 29acf036898..ffcc39fd5a1 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_incoming_message_has_baggage_header.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_incoming_message_has_baggage_header.cs @@ -17,7 +17,7 @@ public async Task Should_propagate_baggage_to_activity() { var sendOptions = new SendOptions(); sendOptions.RouteToThisEndpoint(); - sendOptions.SetHeader(Headers.DiagnosticsBaggage, "key1=value1,key2=value2,key3="); + sendOptions.SetHeader(Headers.DiagnosticsBaggage, "key1=value1,key2=value2,key3=value3"); await session.Send(new SomeMessage(), sendOptions); }) ) @@ -29,7 +29,7 @@ public async Task Should_propagate_baggage_to_activity() VerifyBaggageItem("key1", "value1"); VerifyBaggageItem("key2", "value2"); - VerifyBaggageItem("key3", ""); + VerifyBaggageItem("key3", "value3"); return; void VerifyBaggageItem(string key, string expectedValue) diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_outgoing_activity_has_baggage.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_outgoing_activity_has_baggage.cs index 93ff05bcfbf..b6a2310ad25 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_outgoing_activity_has_baggage.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_outgoing_activity_has_baggage.cs @@ -33,6 +33,9 @@ public async Task Should_propagate_baggage_to_headers() ) .Run(); + // Default (backwards-compatible) propagation produces the legacy comma-separated, percent-encoded format. + // The W3C OWS format ("key3 = , key2 = value2, key1 = value1") is produced only when the + // NServiceBus.Core.OpenTelemetry.UseDistributedContextPropagator AppContext switch is enabled (default in v11). Assert.That(context.BaggageHeader, Is.EqualTo("key3=,key2=value2,key1=value1")); } diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails.cs index a752b82ef29..52ab5ba660e 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails.cs @@ -44,6 +44,13 @@ public async Task Should_mark_span_as_failed() handlerActivityTags.VerifyTag("otel.status_code", "ERROR"); handlerActivityTags.VerifyTag("otel.status_description", ErrorMessage); + using (Assert.EnterMultipleScope()) + { + Assert.That(failedHandlerActivity.Events, Has.Exactly(1).Items, + "the innermost span (the handler invocation) should record the exception details"); + Assert.That(failedPipelineActivity.Events, Is.Empty, + "the outer span should not duplicate the exception details already recorded on the inner span"); + } } public class Context : ScenarioContext; diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails_with_exception_logs_opt_in.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails_with_exception_logs_opt_in.cs new file mode 100644 index 00000000000..c5d6b664333 --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_fails_with_exception_logs_opt_in.cs @@ -0,0 +1,59 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; + +using System.Linq; +using System.Threading.Tasks; +using AcceptanceTesting; +using Configuration.AdvancedExtensibility; +using EndpointTemplates; +using NServiceBus; +using NUnit.Framework; + +// The OTEL_SEMCONV_EXCEPTION_SIGNAL_OPT_IN override is applied while the OpenTelemetryFeature defaults +// run, which is AFTER the endpoint's activity factory has already been built from the instrumentation +// options. The opt-in only takes effect when the activity factory and the settings share a single +// InstrumentationOptions instance. +public class When_processing_fails_with_exception_logs_opt_in : OpenTelemetryAcceptanceTest +{ + [Test] + public async Task Should_record_the_exception_as_a_log_instead_of_a_span_event() + { + var context = await Scenario.Define() + .WithEndpoint(e => e + .DoNotFailOnErrorMessages() + .When(s => s.SendLocal(new FailingMessage()))) + .Run(); + + Assert.That(context.FailedMessages, Has.Count.EqualTo(1), "the message should have failed"); + + var handlerActivity = NServiceBusActivityListener.CompletedActivities.GetInvokedHandlerActivities().Single(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(handlerActivity.Events, Is.Empty, "the exception should not be recorded as a span event when the endpoint opted in to exceptions as logs"); + Assert.That(context.Logs.Any(l => l.LoggerName == "NServiceBus.ActivityFactory" && l.Level == Logging.LogLevel.Error && l.Message.Contains(ErrorMessage)), Is.True, "the exception should be recorded as an error log instead"); + } + } + + public class Context : ScenarioContext; + + public class FailingEndpoint : EndpointConfigurationBuilder + { + // Does not call endpointConfiguration.Tracing(): the instrumentation options only come into existence while the endpoint is being created. + public FailingEndpoint() => EndpointSetup(c => c.GetSettings().Set($"ACCEPTANCETEST_ENV:{OptInEnvironmentVariable}", "logs")); + + [Handler] + public class FailingMessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(FailingMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + throw new SimulatedException(ErrorMessage); + } + } + } + + public class FailingMessage : IMessage; + + const string OptInEnvironmentVariable = "OTEL_SEMCONV_EXCEPTION_SIGNAL_OPT_IN"; + const string ErrorMessage = "boom!"; +} \ No newline at end of file diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_incoming_message.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_incoming_message.cs index 99fecbaf11c..d386a9906d2 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_incoming_message.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_incoming_message.cs @@ -80,5 +80,37 @@ public Task Handle(IncomingMessage message, IMessageHandlerContext context) } } + [Test] + public async Task Should_use_receive_address_in_span_name_when_opted_in() + { + await Scenario.Define() + .WithEndpoint(e => e + .When(s => s.SendLocal(new IncomingMessage()))) + .Run(); + + var incomingMessageActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + Assert.That(incomingMessageActivities, Has.Count.EqualTo(1)); + + var incomingActivity = incomingMessageActivities.Single(); + Assert.That(incomingActivity.DisplayName, Does.StartWith("process ")); + Assert.That(incomingActivity.DisplayName, Is.Not.EqualTo("process message")); + } + + public class ReceivingEndpointWithDestinationNaming : EndpointConfigurationBuilder + { + public ReceivingEndpointWithDestinationNaming() => + EndpointSetup(b => b.Tracing().UseMessageDestinationInSpanNames = true); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(IncomingMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + public class IncomingMessage : IMessage; } \ No newline at end of file diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_message_with_default_activity_sources.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_message_with_default_activity_sources.cs new file mode 100644 index 00000000000..a233aa178b1 --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_processing_message_with_default_activity_sources.cs @@ -0,0 +1,48 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; + +using System.Linq; +using System.Threading.Tasks; +using EndpointTemplates; +using NServiceBus.AcceptanceTesting; +using NUnit.Framework; + +public class When_processing_message_with_default_activity_sources : OpenTelemetryAcceptanceTest +{ + // Until v11, handler spans are emitted from the "NServiceBus.Core" ActivitySource by default + // for backwards compatibility. The dedicated "NServiceBus.Core.Handler" source is opt-in via + // the NServiceBus.Core.OpenTelemetry.UseHandlerActivitySource AppContext switch (default in v11). + [Test] + public async Task Should_emit_handler_span_from_main_source() + { + await Scenario.Define() + .WithEndpoint(b => + b.When(session => session.SendLocal(new SomeMessage())) + ) + .Run(); + + var invokedHandlerActivities = NServiceBusActivityListener.CompletedActivities.GetInvokedHandlerActivities(); + + Assert.That(invokedHandlerActivities, Has.Count.EqualTo(1)); + Assert.That(invokedHandlerActivities.Single().Source.Name, Is.EqualTo("NServiceBus.Core"), + "without the opt-in switch, handler spans must keep coming from the main source so existing OpenTelemetry configurations keep seeing them"); + } + + public class Context : ScenarioContext; + + public class ReceivingEndpoint : EndpointConfigurationBuilder + { + public ReceivingEndpoint() => EndpointSetup(); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(SomeMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + public class SomeMessage : IMessage; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_publishing_messages.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_publishing_messages.cs index 8c402afb504..7aed06a30a8 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_publishing_messages.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_publishing_messages.cs @@ -179,5 +179,188 @@ public Task Handle(ThisIsAnEvent @event, IMessageHandlerContext context) } } + [Test] + public async Task Should_use_event_type_in_span_name_when_opted_in() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(ctx => ctx.SomeEventSubscribed, s => s.Publish())) + .WithEndpoint(b => b.When((session, ctx) => + { + if (ctx.HasNativePubSubSupport) + { + ctx.SomeEventSubscribed = true; + } + + return Task.CompletedTask; + })) + .Run(); + + var outgoingEventActivities = NServiceBusActivityListener.CompletedActivities.GetPublishEventActivities(); + Assert.That(outgoingEventActivities, Has.Count.EqualTo(1)); + + var publishedMessage = outgoingEventActivities.Single(); + Assert.That(publishedMessage.DisplayName, Is.EqualTo("publish ThisIsAnEvent")); + } + + public class PublisherWithDestinationNaming : EndpointConfigurationBuilder + { + public PublisherWithDestinationNaming() => + EndpointSetup(b => + { + b.Tracing().UseMessageDestinationInSpanNames = true; + b.OnEndpointSubscribed((s, context) => + { + if (s.SubscriberEndpoint.Contains(Conventions.EndpointNamingConvention(typeof(SubscriberForPublisherWithDestinationNaming)))) + { + if (s.MessageType == typeof(ThisIsAnEvent).AssemblyQualifiedName) + { + context.SomeEventSubscribed = true; + } + } + }); + }); + } + + public class SubscriberForPublisherWithDestinationNaming : EndpointConfigurationBuilder + { + public SubscriberForPublisherWithDestinationNaming() => + EndpointSetup(c => { }, + metadata => + { + metadata.RegisterPublisherFor(); + }); + + [Handler] + public class ThisHandlesSomethingHandler(Context testContext) : IHandleMessages + { + public Task Handle(ThisIsAnEvent @event, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + [Test] + public async Task Should_create_child_on_receive_when_endpoint_defaults_to_child_span() + { + var context = await Scenario.Define() + .WithEndpoint(b => b + .When(ctx => ctx.SomeEventSubscribed, s => s.Publish(new ThisIsAnEvent()))) + .WithEndpoint(b => b.When((session, ctx) => + { + if (ctx.HasNativePubSubSupport) + { + ctx.SomeEventSubscribed = true; + } + + return Task.CompletedTask; + })) + .Run(); + + var publishMessageActivities = NServiceBusActivityListener.CompletedActivities.GetPublishEventActivities(); + var receiveMessageActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + using (Assert.EnterMultipleScope()) + { + Assert.That(publishMessageActivities, Has.Count.EqualTo(1), "1 message is published as part of this test"); + Assert.That(receiveMessageActivities, Has.Count.EqualTo(1), "1 message is received as part of this test"); + } + + var publishRequest = publishMessageActivities[0]; + var receiveRequest = receiveMessageActivities[0]; + + using (Assert.EnterMultipleScope()) + { + Assert.That(receiveRequest.RootId, Is.EqualTo(publishRequest.RootId), "publish and receive operations are part the same root activity"); + Assert.That(receiveRequest.ParentId, Is.Not.Null, "incoming message does have a parent"); + } + + Assert.That(receiveRequest.Links, Is.Empty, "receive does not have links"); + } + + [Test] + public async Task Should_create_new_linked_trace_on_receive_when_option_overrides_endpoint_connector() + { + var context = await Scenario.Define() + .WithEndpoint(b => b + .When(ctx => ctx.SomeEventSubscribed, s => + { + var publishOptions = new PublishOptions(); + publishOptions.StartNewTraceOnReceive(); + return s.Publish(new ThisIsAnEvent(), publishOptions); + })) + .WithEndpoint(b => b.When((session, ctx) => + { + if (ctx.HasNativePubSubSupport) + { + ctx.SomeEventSubscribed = true; + } + + return Task.CompletedTask; + })) + .Run(); + + var publishMessageActivities = NServiceBusActivityListener.CompletedActivities.GetPublishEventActivities(); + var receiveMessageActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + using (Assert.EnterMultipleScope()) + { + Assert.That(publishMessageActivities, Has.Count.EqualTo(1), "1 message is published as part of this test"); + Assert.That(receiveMessageActivities, Has.Count.EqualTo(1), "1 message is received as part of this test"); + } + + var publishRequest = publishMessageActivities[0]; + var receiveRequest = receiveMessageActivities[0]; + + using (Assert.EnterMultipleScope()) + { + Assert.That(receiveRequest.RootId, Is.Not.EqualTo(publishRequest.RootId), "publish and receive operations are part of different root activities"); + Assert.That(receiveRequest.ParentId, Is.Null, "incoming message does not have a parent, it's a root"); + } + + ActivityLink link = receiveRequest.Links.FirstOrDefault(); + Assert.That(link, Is.Not.EqualTo(default(ActivityLink)), "Receive has a link"); + Assert.That(link.Context.TraceId, Is.EqualTo(publishRequest.TraceId), "receive is linked to publish operation"); + } + + public class PublisherWithChildSpanConnector : EndpointConfigurationBuilder + { + public PublisherWithChildSpanConnector() => + EndpointSetup(b => + { + b.Tracing().PublishTraceMode = TraceMode.ContinueExisting; + b.OnEndpointSubscribed((s, context) => + { + if (s.SubscriberEndpoint.Contains(Conventions.EndpointNamingConvention(typeof(SubscriberForPublisherWithChildSpanConnector)))) + { + if (s.MessageType == typeof(ThisIsAnEvent).AssemblyQualifiedName) + { + context.SomeEventSubscribed = true; + } + } + }); + }); + } + + public class SubscriberForPublisherWithChildSpanConnector : EndpointConfigurationBuilder + { + public SubscriberForPublisherWithChildSpanConnector() => + EndpointSetup(c => { }, + metadata => + { + metadata.RegisterPublisherFor(); + }); + + [Handler] + public class ThisHandlesSomethingHandler(Context testContext) : IHandleMessages + { + public Task Handle(ThisIsAnEvent @event, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + public class ThisIsAnEvent : IEvent; } \ No newline at end of file diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_recoverability_action_occurs.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_recoverability_action_occurs.cs new file mode 100644 index 00000000000..ec458ed6ba7 --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_recoverability_action_occurs.cs @@ -0,0 +1,112 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; + +using System; +using System.Linq; +using System.Threading.Tasks; +using AcceptanceTesting; +using AcceptanceTesting.Customization; +using EndpointTemplates; +using NUnit.Framework; + +public class When_recoverability_action_occurs : OpenTelemetryAcceptanceTest +{ + [Test] + public async Task Should_create_spans_for_all_recoverability_actions() + { + await Scenario.Define() + .WithEndpoint(b => b + .CustomConfig(c => c.Recoverability() + .Immediate(i => i.NumberOfRetries(1)) + .Delayed(i => i.NumberOfRetries(1).TimeIncrease(TimeSpan.FromMilliseconds(1))) + .CustomPolicy((cfg, errorContext) => + errorContext.Headers[Headers.EnclosedMessageTypes].Contains(nameof(DiscardMessage)) + ? RecoverabilityAction.Discard("test discard reason") + : DefaultRecoverabilityPolicy.Invoke(cfg, errorContext))) + .DoNotFailOnErrorMessages() + .When(async s => + { + await s.SendLocal(new FailingMessage()); + await s.SendLocal(new DiscardMessage()); + })) + .Done(_ => ActionTags().Contains("move_to_error") && ActionTags().Contains("discard")) + .Run(); + + var activities = NServiceBusActivityListener.CompletedActivities.GetRecoverabilityActivities(); + + var immediateRetry = activities.FirstOrDefault(a => (string)a.GetTagItem(ActivityTagName) == "immediate_retry"); + var delayedRetry = activities.FirstOrDefault(a => (string)a.GetTagItem(ActivityTagName) == "delayed_retry"); + var moveToError = activities.Single(a => (string)a.GetTagItem(ActivityTagName) == "move_to_error"); + var discard = activities.Single(a => (string)a.GetTagItem(ActivityTagName) == "discard"); + + using (Assert.EnterMultipleScope()) + { + Assert.That(immediateRetry, Is.Not.Null, "expected at least one immediate retry span"); + Assert.That(immediateRetry.DisplayName, Is.EqualTo("immediate retry")); + + Assert.That(delayedRetry, Is.Not.Null, "expected at least one delayed retry span"); + Assert.That(delayedRetry.DisplayName, Is.EqualTo("delayed retry")); + + Assert.That(moveToError.DisplayName, Does.StartWith("move to ")); + Assert.That(discard.DisplayName, Is.EqualTo("discard")); + } + } + + [Test] + public async Task Should_include_destination_in_display_name_when_opted_in() + { + await Scenario.Define() + .WithEndpoint(b => b + .CustomConfig(c => + { + c.Recoverability().Immediate(i => i.NumberOfRetries(1)).Delayed(i => i.NumberOfRetries(0)); + c.Tracing().UseMessageDestinationInSpanNames = true; + }) + .DoNotFailOnErrorMessages() + .When(s => s.SendLocal(new FailingMessage()))) + .Done(_ => ActionTags().Contains("move_to_error")) + .Run(); + + var immediateRetry = NServiceBusActivityListener.CompletedActivities.GetRecoverabilityActivities() + .First(a => (string)a.GetTagItem(ActivityTagName) == "immediate_retry"); + + var endpointName = Conventions.EndpointNamingConvention(typeof(RecoverabilityEndpoint)); + Assert.That(immediateRetry.DisplayName, Is.EqualTo($"immediate retry {endpointName}")); + } + + string[] ActionTags() => + NServiceBusActivityListener.CompletedActivities.GetRecoverabilityActivities() + .Select(a => (string)a.GetTagItem(ActivityTagName)) + .ToArray(); + + const string ActivityTagName = "nservicebus.recoverability_action"; + + public class Context : ScenarioContext; + + public class RecoverabilityEndpoint : EndpointConfigurationBuilder + { + public RecoverabilityEndpoint() + { + var template = new DefaultServer + { + TransportConfiguration = new ConfigureEndpointAcceptanceTestingTransport(false, true) + }; + EndpointSetup(template, (c, _) => { }, metadata => { }); + } + + [Handler] + public class FailingMessageHandler : IHandleMessages + { + public Task Handle(FailingMessage message, IMessageHandlerContext context) => throw new SimulatedException("always fails"); + } + + [Handler] + public class DiscardMessageHandler : IHandleMessages + { + public Task Handle(DiscardMessage message, IMessageHandlerContext context) => throw new SimulatedException("always fails"); + } + } + + public class FailingMessage : IMessage; + + public class DiscardMessage : IMessage; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_retrying_messages.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_retrying_messages.cs index b0f02c3c4b5..76f76a5f3e9 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_retrying_messages.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_retrying_messages.cs @@ -1,10 +1,11 @@ namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; using System; +using System.Diagnostics; using System.Linq; using System.Threading.Tasks; using EndpointTemplates; -using NServiceBus.AcceptanceTesting; +using AcceptanceTesting; using NUnit.Framework; public class When_retrying_messages : OpenTelemetryAcceptanceTest @@ -37,10 +38,8 @@ await Scenario.Define() } [Test] - public async Task Should_correlate_delayed_retry_with_send() + public async Task Should_start_new_trace_on_receive_by_default() { - Requires.DelayedDelivery(); - await Scenario.Define() .WithEndpoint(e => e .CustomConfig(c => c.Recoverability().Delayed(i => i.NumberOfRetries(1).TimeIncrease(TimeSpan.FromMilliseconds(1)))) @@ -48,21 +47,58 @@ await Scenario.Define() .When(s => s.SendLocal(new FailingMessage()))) .Run(); - var receiveActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); - var sendActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + var (sendRequest, firstAttempt, retryAttempt) = GetDelayedRetryActivities(); using (Assert.EnterMultipleScope()) { - Assert.That(sendActivities, Has.Count.EqualTo(1)); - Assert.That(receiveActivities, Has.Count.EqualTo(2), "the message should be processed twice due to one immediate retry"); + Assert.That(firstAttempt.TraceId, Is.EqualTo(sendRequest.TraceId), "the first attempt is part of the original send's trace"); + Assert.That(firstAttempt.ParentId, Is.EqualTo(sendRequest.Id)); + + Assert.That(retryAttempt.TraceId, Is.Not.EqualTo(sendRequest.TraceId), "a delayed retry should start a new trace on receive by default (backward compatible)"); + Assert.That(retryAttempt.ParentId, Is.Null, "the retry attempt should be a new root"); } + + var link = retryAttempt.Links.FirstOrDefault(); + Assert.That(link, Is.Not.Default, "the retry attempt should be linked back to the original send operation"); + Assert.That(link.Context.TraceId, Is.EqualTo(sendRequest.TraceId)); + } + + [Test] + public async Task Should_continue_existing_trace_on_receive_when_configured() + { + await Scenario.Define() + .WithEndpoint(e => e + .CustomConfig(c => + { + c.Recoverability().Delayed(i => i.NumberOfRetries(1).TimeIncrease(TimeSpan.FromMilliseconds(1))); + c.Tracing().Recoverability.DelayedRetryTraceMode = TraceMode.ContinueExisting; + }) + .DoNotFailOnErrorMessages() + .When(s => s.SendLocal(new FailingMessage()))) + .Run(); + + var (sendRequest, _, retryAttempt) = GetDelayedRetryActivities(); + using (Assert.EnterMultipleScope()) { - Assert.That(receiveActivities[0].ParentId, Is.EqualTo(sendActivities[0].Id), "should not change parent span"); - Assert.That(receiveActivities[1].ParentId, Is.EqualTo(sendActivities[0].Id), "should not change parent span"); + Assert.That(retryAttempt.TraceId, Is.EqualTo(sendRequest.TraceId), "a delayed retry should continue the existing trace when DelayedRetryTraceMode is set to ContinueExisting"); + Assert.That(retryAttempt.ParentId, Is.EqualTo(sendRequest.Id)); + Assert.That(retryAttempt.Links, Is.Empty); + } + } - Assert.That(sendActivities.Concat(receiveActivities).All(a => a.TraceId == sendActivities[0].TraceId), Is.True, "all activities should be part of the same trace"); + (Activity SendRequest, Activity FirstAttempt, Activity RetryAttempt) GetDelayedRetryActivities() + { + var receiveActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + var sendActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(sendActivities, Has.Count.EqualTo(1)); + Assert.That(receiveActivities, Has.Count.EqualTo(2), "the message should be processed twice due to one delayed retry"); } + + return (sendActivities[0], receiveActivities[0], receiveActivities[1]); } public class Context : ScenarioContext @@ -72,7 +108,11 @@ public class Context : ScenarioContext public class RetryingEndpoint : EndpointConfigurationBuilder { - public RetryingEndpoint() => EndpointSetup(); + public RetryingEndpoint() => + EndpointSetup(new DefaultServer + { + TransportConfiguration = new ConfigureEndpointAcceptanceTestingTransport(false, true) + }, (c, _) => { }, _ => { }); [Handler] public class Handler(Context testContext) : IHandleMessages diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_saga_requests_a_timeout.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_saga_requests_a_timeout.cs new file mode 100644 index 00000000000..d0dfc71b143 --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_saga_requests_a_timeout.cs @@ -0,0 +1,115 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; + +using System; +using System.Diagnostics; +using System.Linq; +using System.Threading.Tasks; +using AcceptanceTesting; +using EndpointTemplates; +using NUnit.Framework; + +public class When_saga_requests_a_timeout : OpenTelemetryAcceptanceTest +{ + [Test] + public async Task Should_start_new_trace_on_receive_by_default() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => s.SendLocal(new StartSagaMessage { SomeId = Guid.NewGuid().ToString() }))) + .Run(); + + var (timeoutSend, timeoutReceive) = GetTimeoutActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(timeoutReceive.TraceId, Is.Not.EqualTo(timeoutSend.TraceId), "a saga timeout should start a new trace on receive by default (backward compatible)"); + Assert.That(timeoutReceive.ParentId, Is.Null, "timeout receive should be a new root"); + } + + var link = timeoutReceive.Links.FirstOrDefault(); + Assert.That(link, Is.Not.Default, "timeout receive should be linked back to the timeout send operation"); + Assert.That(link.Context.TraceId, Is.EqualTo(timeoutSend.TraceId)); + } + + [Test] + public async Task Should_continue_existing_trace_on_receive_when_configured() + { + await Scenario.Define() + .WithEndpoint(b => b.CustomConfig(c => + { + c.Tracing().DelayedDelivery.SagaTimeoutTraceMode = TraceMode.ContinueExisting; + }) + .When(s => s.SendLocal(new StartSagaMessage { SomeId = Guid.NewGuid().ToString() }))) + .Run(); + + var (timeoutSend, timeoutReceive) = GetTimeoutActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(timeoutReceive.TraceId, Is.EqualTo(timeoutSend.TraceId), "a saga timeout should continue the existing trace when SagaTimeoutTraceMode is set to ContinueExisting"); + Assert.That(timeoutReceive.ParentId, Is.EqualTo(timeoutSend.Id)); + Assert.That(timeoutReceive.Links, Is.Empty); + } + } + + (Activity TimeoutSend, Activity TimeoutReceive) GetTimeoutActivities() + { + var sendActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + var receiveActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(sendActivities, Has.Count.EqualTo(2), "start-saga send and timeout send"); + Assert.That(receiveActivities, Has.Count.EqualTo(2), "start-saga receive and timeout receive"); + } + + return (sendActivities[1], receiveActivities[1]); + } + + public class Context : ScenarioContext + { + public bool SagaMarkedComplete { get; set; } + } + + public class SagaEndpoint : EndpointConfigurationBuilder + { + public SagaEndpoint() => + EndpointSetup(new DefaultServer + { + TransportConfiguration = new ConfigureEndpointAcceptanceTestingTransport(false, true) + }, (c, _) => { }, _ => { }); + + [Saga] + public class TimeoutSaga(Context testContext) : Saga, IAmStartedByMessages, IHandleTimeouts + { + protected override void ConfigureHowToFindSaga(SagaPropertyMapper mapper) => + mapper.MapSaga(s => s.SomeId).ToMessage(m => m.SomeId); + + public Task Handle(StartSagaMessage message, IMessageHandlerContext context) + { + Data.SomeId = message.SomeId; + return RequestTimeout(context, DateTimeOffset.UtcNow.AddMilliseconds(2)); + } + + public Task Timeout(SagaTimeout state, IMessageHandlerContext context) + { + MarkAsComplete(); + testContext.SagaMarkedComplete = true; + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + public class TimeoutSagaData : ContainSagaData + { + public virtual string SomeId { get; set; } + } + + public class StartSagaMessage : IMessage + { + public string SomeId { get; set; } + } + + public class SagaTimeout; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_a_delayed_message.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_a_delayed_message.cs new file mode 100644 index 00000000000..1e0e72e17cc --- /dev/null +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_a_delayed_message.cs @@ -0,0 +1,124 @@ +namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Traces; + +using System; +using System.Linq; +using System.Threading.Tasks; +using AcceptanceTesting; +using EndpointTemplates; +using NUnit.Framework; + +public class When_sending_a_delayed_message : OpenTelemetryAcceptanceTest +{ + [Test] + public async Task Should_start_new_trace_on_receive_by_default() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => s.Send(new DelayedMessage(), DelayedSend()))) + .Run(); + + var (send, receive) = GetActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(receive.TraceId, Is.Not.EqualTo(send.TraceId), "a delayed send should start a new trace on receive by default (backward compatible)"); + Assert.That(receive.ParentId, Is.Null, "receive should be a new root"); + } + + var link = receive.Links.FirstOrDefault(); + Assert.That(link, Is.Not.Default, "receive should be linked back to the send operation"); + Assert.That(link.Context.TraceId, Is.EqualTo(send.TraceId)); + } + + [Test] + public async Task Should_continue_existing_trace_on_receive_when_configured() + { + await Scenario.Define() + .WithEndpoint(b => b.CustomConfig(c => + { + c.Tracing().DelayedDelivery.SendOperationTraceMode = TraceMode.ContinueExisting; + }) + .When(s => s.Send(new DelayedMessage(), DelayedSend()))) + .Run(); + + var (send, receive) = GetActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(receive.TraceId, Is.EqualTo(send.TraceId), "a delayed send should continue the existing trace when SendOperationTraceMode is set to ContinueExisting"); + Assert.That(receive.ParentId, Is.EqualTo(send.Id)); + Assert.That(receive.Links, Is.Empty); + } + } + + [Test] + public async Task Should_start_new_trace_by_default_no_matter_per_message_option() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => + { + var sendOptions = DelayedSend(); + sendOptions.ContinueExistingTraceOnReceive(); + return s.Send(new DelayedMessage(), sendOptions); + })) + .Run(); + + var (send, receive) = GetActivities(); + + Assert.That(receive.TraceId, Is.Not.EqualTo(send.TraceId), + "a per-message request to continue the existing trace must not defeat the backward-compatible default for delayed sends"); + } + + static SendOptions DelayedSend() + { + var sendOptions = new SendOptions(); + sendOptions.RouteToThisEndpoint(); + sendOptions.DelayDeliveryWith(TimeSpan.FromMilliseconds(1)); + return sendOptions; + } + + (System.Diagnostics.Activity Send, System.Diagnostics.Activity Receive) GetActivities() + { + var sendActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + var receiveActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(sendActivities, Has.Count.EqualTo(1), "1 message is sent as part of this test"); + Assert.That(receiveActivities, Has.Count.EqualTo(1), "1 message is received as part of this test"); + } + + return (sendActivities[0], receiveActivities[0]); + } + + public class Context : ScenarioContext + { + public bool DelayedMessageReceived { get; set; } + } + + public class TestEndpoint : EndpointConfigurationBuilder + { + public TestEndpoint() + { + var template = new DefaultServer + { + TransportConfiguration = new ConfigureEndpointAcceptanceTestingTransport(false, true) + }; + EndpointSetup(template, (c, _) => { }, metadata => { }); + } + + [Handler] + public class DelayedMessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(DelayedMessage message, IMessageHandlerContext context) + { + testContext.DelayedMessageReceived = true; + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + public class DelayedMessage : IMessage; +} diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_messages.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_messages.cs index af0751530d7..c08e660e883 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_messages.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_messages.cs @@ -131,5 +131,117 @@ public Task Handle(OutgoingMessage message, IMessageHandlerContext context) } } + [Test] + public async Task Should_use_destination_in_send_span_name_when_opted_in() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => s.SendLocal(new OutgoingMessage()))) + .Run(); + + var outgoingMessageActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + Assert.That(outgoingMessageActivities, Has.Count.EqualTo(1)); + + var sentMessage = outgoingMessageActivities.Single(); + Assert.That(sentMessage.DisplayName, Does.StartWith("send ")); + Assert.That(sentMessage.DisplayName, Is.Not.EqualTo("send message")); + } + + public class TestEndpointWithDestinationNaming : EndpointConfigurationBuilder + { + public TestEndpointWithDestinationNaming() => + EndpointSetup(b => b.Tracing().UseMessageDestinationInSpanNames = true); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(OutgoingMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + + [Test] + public async Task Should_create_new_linked_trace_on_receive_when_endpoint_defaults_to_span_link() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => s.SendLocal(new OutgoingMessage()))) + .Run(); + + var sendMessageActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + var receiveMessageActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + using (Assert.EnterMultipleScope()) + { + Assert.That(sendMessageActivities, Has.Count.EqualTo(1), "1 message is sent as part of this test"); + Assert.That(receiveMessageActivities, Has.Count.EqualTo(1), "1 message is received as part of this test"); + } + + var sendRequest = sendMessageActivities[0]; + var receiveRequest = receiveMessageActivities[0]; + + using (Assert.EnterMultipleScope()) + { + Assert.That(receiveRequest.RootId, Is.Not.EqualTo(sendRequest.RootId), "send and receive operations are part of different root activities"); + Assert.That(receiveRequest.ParentId, Is.Null, "incoming message does not have a parent, it's a root"); + } + + ActivityLink link = receiveRequest.Links.FirstOrDefault(); + Assert.That(link, Is.Not.EqualTo(default(ActivityLink)), "Receive has a link"); + Assert.That(link.Context.TraceId, Is.EqualTo(sendRequest.TraceId), "receive is linked to send operation"); + } + + [Test] + public async Task Should_create_child_on_receive_when_option_overrides_endpoint_connector() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => + { + var sendOptions = new SendOptions(); + sendOptions.RouteToThisEndpoint(); + sendOptions.ContinueExistingTraceOnReceive(); + return s.Send(new OutgoingMessage(), sendOptions); + })) + .Run(); + + var sendMessageActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + var receiveMessageActivities = NServiceBusActivityListener.CompletedActivities.GetReceiveMessageActivities(); + using (Assert.EnterMultipleScope()) + { + Assert.That(sendMessageActivities, Has.Count.EqualTo(1), "1 message is sent as part of this test"); + Assert.That(receiveMessageActivities, Has.Count.EqualTo(1), "1 message is received as part of this test"); + } + + var sendRequest = sendMessageActivities[0]; + var receiveRequest = receiveMessageActivities[0]; + + using (Assert.EnterMultipleScope()) + { + Assert.That(receiveRequest.RootId, Is.EqualTo(sendRequest.RootId), "send and receive operations are part of the same root activity"); + Assert.That(receiveRequest.ParentId, Is.Not.Null, "incoming message does have a parent"); + } + + Assert.That(receiveRequest.Links, Is.Empty, "receive does not have links"); + } + + public class TestEndpointWithSpanLinkConnector : EndpointConfigurationBuilder + { + public TestEndpointWithSpanLinkConnector() => + EndpointSetup(b => b.Tracing().SendTraceMode = TraceMode.StartNew); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages + { + public Task Handle(OutgoingMessage message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + public class OutgoingMessage : IMessage; } \ No newline at end of file diff --git a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_replies.cs b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_replies.cs index e6299389c51..c6c505d9236 100644 --- a/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_replies.cs +++ b/src/NServiceBus.AcceptanceTests/Core/OpenTelemetry/Traces/When_sending_replies.cs @@ -55,6 +55,40 @@ public Task Handle(OutgoingReply message, IMessageHandlerContext context) } } + [Test] + public async Task Should_use_destination_in_reply_span_name_when_opted_in() + { + await Scenario.Define() + .WithEndpoint(b => b + .When(s => s.SendLocal(new IncomingMessage()))) + .Run(); + + var outgoingMessageActivities = NServiceBusActivityListener.CompletedActivities.GetSendMessageActivities(); + Assert.That(outgoingMessageActivities, Has.Count.EqualTo(2), "2 messages are being sent"); + var replyMessage = outgoingMessageActivities[1]; + + Assert.That(replyMessage.DisplayName, Does.StartWith("reply ")); + } + + public class TestEndpointWithDestinationNaming : EndpointConfigurationBuilder + { + public TestEndpointWithDestinationNaming() => + EndpointSetup(b => b.Tracing().UseMessageDestinationInSpanNames = true); + + [Handler] + public class MessageHandler(Context testContext) : IHandleMessages, + IHandleMessages + { + public Task Handle(IncomingMessage message, IMessageHandlerContext context) => context.Reply(new OutgoingReply()); + + public Task Handle(OutgoingReply message, IMessageHandlerContext context) + { + testContext.MarkAsCompleted(); + return Task.CompletedTask; + } + } + } + public class IncomingMessage : IMessage; public class OutgoingReply : IMessage; diff --git a/src/NServiceBus.AcceptanceTests/NServiceBus.AcceptanceTests.csproj b/src/NServiceBus.AcceptanceTests/NServiceBus.AcceptanceTests.csproj index ea546b1c257..1af349bf801 100644 --- a/src/NServiceBus.AcceptanceTests/NServiceBus.AcceptanceTests.csproj +++ b/src/NServiceBus.AcceptanceTests/NServiceBus.AcceptanceTests.csproj @@ -14,6 +14,7 @@ + diff --git a/src/NServiceBus.Core.Tests/ApprovalFiles/APIApprovals.ApproveNServiceBus.approved.txt b/src/NServiceBus.Core.Tests/ApprovalFiles/APIApprovals.ApproveNServiceBus.approved.txt index acbacb5d5ae..c7302ebe466 100644 --- a/src/NServiceBus.Core.Tests/ApprovalFiles/APIApprovals.ApproveNServiceBus.approved.txt +++ b/src/NServiceBus.Core.Tests/ApprovalFiles/APIApprovals.ApproveNServiceBus.approved.txt @@ -214,6 +214,12 @@ namespace NServiceBus public int MaxNumberOfRetries { get; } public System.TimeSpan TimeIncrease { get; } } + public class DelayedDeliveryInstrumentationOptions + { + public DelayedDeliveryInstrumentationOptions() { } + public NServiceBus.TraceMode SagaTimeoutTraceMode { get; set; } + public NServiceBus.TraceMode SendOperationTraceMode { get; set; } + } public static class DelayedDeliveryOptionExtensions { public static void DelayDeliveryWith(this NServiceBus.SendOptions options, System.TimeSpan delay) { } @@ -325,6 +331,11 @@ namespace NServiceBus public bool TryGetExplicitlyConfiguredErrorQueueAddress([System.Diagnostics.CodeAnalysis.NotNullWhen(true)] out string? errorQueue) { } } } + public enum ExceptionRecordingMode + { + Logs = 0, + SpanAndLogs = 1, + } public class FailedConfig { public FailedConfig(string errorQueue, System.Collections.Generic.HashSet unrecoverableExceptionTypes) { } @@ -543,6 +554,10 @@ namespace NServiceBus System.Threading.Tasks.Task Subscribe(System.Type eventType, NServiceBus.SubscribeOptions subscribeOptions, System.Threading.CancellationToken cancellationToken = default); System.Threading.Tasks.Task Unsubscribe(System.Type eventType, NServiceBus.UnsubscribeOptions unsubscribeOptions, System.Threading.CancellationToken cancellationToken = default); } + public interface IMetricsTags + { + void AddOrOverride(string tagKey, object value, string instrumentName); + } public interface INeedInitialization { void Customize(NServiceBus.EndpointConfiguration configuration); @@ -607,13 +622,6 @@ namespace NServiceBus public override NServiceBus.Transport.ErrorHandleResult ErrorHandleResult { get; } public override System.Collections.Generic.IReadOnlyCollection GetRoutingContexts(NServiceBus.Pipeline.IRecoverabilityActionContext context) { } } - public sealed class IncomingPipelineMetricTags - { - public IncomingPipelineMetricTags() { } - public void Add(string tagKey, object value) { } - public void ApplyTag(ref System.Diagnostics.TagList tagList, string tagKey) { } - public void ApplyTags(ref System.Diagnostics.TagList tagList, System.ReadOnlySpan tagKeys) { } - } public static class InstallConfigExtensions { public static void AddInstaller<[System.Diagnostics.CodeAnalysis.DynamicallyAccessedMembers(System.Diagnostics.CodeAnalysis.DynamicallyAccessedMemberTypes.None | System.Diagnostics.CodeAnalysis.DynamicallyAccessedMemberTypes.PublicParameterlessConstructor | System.Diagnostics.CodeAnalysis.DynamicallyAccessedMemberTypes.PublicConstructors | System.Diagnostics.CodeAnalysis.DynamicallyAccessedMemberTypes.PublicMethods | System.Diagnostics.CodeAnalysis.DynamicallyAccessedMemberTypes.Interfaces)] TInstaller>(this NServiceBus.EndpointConfiguration config) @@ -632,6 +640,18 @@ namespace NServiceBus StopApplication = 0, Continue = 1, } + public class InstrumentationOptions + { + public InstrumentationOptions() { } + public NServiceBus.DelayedDeliveryInstrumentationOptions DelayedDelivery { get; } + public bool EmitMessageDispatchingEvents { get; set; } + public NServiceBus.ExceptionRecordingMode ExceptionRecordingMode { get; set; } + public NServiceBus.MetersOptions Meters { get; } + public NServiceBus.TraceMode PublishTraceMode { get; set; } + public NServiceBus.RecoverabilityInstrumentationOptions Recoverability { get; } + public NServiceBus.TraceMode SendTraceMode { get; set; } + public bool UseMessageDestinationInSpanNames { get; set; } + } public sealed class KeyedServiceKey { public const string Any = "______________"; @@ -746,6 +766,21 @@ namespace NServiceBus public static System.Threading.Tasks.Task Unsubscribe(this NServiceBus.IMessageSession session, System.Type messageType, System.Threading.CancellationToken cancellationToken = default) { } public static System.Threading.Tasks.Task Unsubscribe(this NServiceBus.IMessageSession session, System.Threading.CancellationToken cancellationToken = default) { } } + public class MetersOptions + { + public MetersOptions() { } + public bool EmitExecutionResultTags { get; set; } + } + public static class MetricTagsExtensions + { + extension(NServiceBus.Pipeline.IBehaviorContext context) + { + public NServiceBus.IMetricsTags MetricTags { get; } + } + extension(NServiceBus.Transport.MessageContext context) + { + } + } public class MoveToError : NServiceBus.RecoverabilityAction { protected MoveToError(string errorQueue) { } @@ -771,7 +806,10 @@ namespace NServiceBus public static class OpenTelemetryExtensions { public static void ContinueExistingTraceOnReceive(this NServiceBus.PublishOptions publishOptions) { } + public static void ContinueExistingTraceOnReceive(this NServiceBus.SendOptions sendOptions) { } + public static void StartNewTraceOnReceive(this NServiceBus.PublishOptions publishOptions) { } public static void StartNewTraceOnReceive(this NServiceBus.SendOptions sendOptions) { } + public static NServiceBus.InstrumentationOptions Tracing(this NServiceBus.EndpointConfiguration config) { } } public static class OutboxConfigExtensions { @@ -889,6 +927,11 @@ namespace NServiceBus { public static NServiceBus.RecoverabilitySettings Recoverability(this NServiceBus.EndpointConfiguration configuration) { } } + public class RecoverabilityInstrumentationOptions + { + public RecoverabilityInstrumentationOptions() { } + public NServiceBus.TraceMode DelayedRetryTraceMode { get; set; } + } public class RecoverabilitySettings : NServiceBus.Configuration.AdvancedExtensibility.ExposeSettings { public NServiceBus.RecoverabilitySettings AddUnrecoverableException(System.Type exceptionType) { } @@ -1167,6 +1210,11 @@ namespace NServiceBus public ToSagaExpression(NServiceBus.IConfigureHowToFindSagaWithMessage sagaMessageFindingConfiguration, System.Linq.Expressions.Expression> messageProperty) { } public void ToSaga(System.Linq.Expressions.Expression> sagaEntityProperty) { } } + public enum TraceMode + { + ContinueExisting = 0, + StartNew = 1, + } public static class TransportConfig { extension(NServiceBus.EndpointConfiguration endpointConfiguration) diff --git a/src/NServiceBus.Core.Tests/ApprovalFiles/ActivityTagsTests.Verify_ActivityTags.approved.txt b/src/NServiceBus.Core.Tests/ApprovalFiles/ActivityTagsTests.Verify_ActivityTags.approved.txt index 27d7bc2fc19..c012daa39d0 100644 --- a/src/NServiceBus.Core.Tests/ApprovalFiles/ActivityTagsTests.Verify_ActivityTags.approved.txt +++ b/src/NServiceBus.Core.Tests/ApprovalFiles/ActivityTagsTests.Verify_ActivityTags.approved.txt @@ -1,6 +1,5 @@ { "Note": "Changes to activity tags should result in ActivitySource version updates", - "ActivitySourceVersion": "0.1.0", "Tags": [ "SagaId => nservicebus.saga.saga_id", "MessageId => nservicebus.message_id", @@ -38,6 +37,22 @@ "HandlerType => nservicebus.handler.handler_type", "HandlerSagaId => nservicebus.handler.saga_id", "EventTypes => nservicebus.event_types", - "CancelledTask => nservicebus.cancelled" + "CancelledTask => nservicebus.cancelled", + "ErrorType => error.type", + "RecoverabilityAction => nservicebus.recoverability_action" + ], + "ActivitySourceVersions": [ + { + "Name": "Main", + "Version": "0.1.0" + }, + { + "Name": "Handler", + "Version": "0.1.0" + }, + { + "Name": "Recoverability", + "Version": "0.1.0" + } ] } \ No newline at end of file diff --git a/src/NServiceBus.Core.Tests/ApprovalFiles/MeterTests.Verify_MeterAPI.approved.txt b/src/NServiceBus.Core.Tests/ApprovalFiles/MeterTests.Verify_MeterAPI.approved.txt index a572d43098f..b632b411cce 100644 --- a/src/NServiceBus.Core.Tests/ApprovalFiles/MeterTests.Verify_MeterAPI.approved.txt +++ b/src/NServiceBus.Core.Tests/ApprovalFiles/MeterTests.Verify_MeterAPI.approved.txt @@ -1,27 +1,37 @@ { "Note": "Changes to metrics API should result in an update to NServiceBusMeter version.", "MetricsSourceName": "NServiceBus.Core.Pipeline.Incoming", - "MetricsSourceVersion": "0.2.0", + "MetricsSourceVersion": "0.4.0", "Tags": [ "error.type", "execution.result", "nservicebus.discriminator", + "nservicebus.enclosed_message_types", "nservicebus.envelope.unwrapper_type", "nservicebus.message_handler_type", "nservicebus.message_handler_types", "nservicebus.message_type", - "nservicebus.queue" + "nservicebus.queue", + "nservicebus.saga_type" ], "Metrics": [ "nservicebus.envelope.unwrapped => Counter", + "nservicebus.messaging.active_messages => UpDownCounter", "nservicebus.messaging.critical_time => Histogram, Unit: s", + "nservicebus.messaging.deserialize_time => Histogram, Unit: s", "nservicebus.messaging.failures => Counter", "nservicebus.messaging.fetches => Counter", "nservicebus.messaging.handler_time => Histogram, Unit: s", "nservicebus.messaging.processing_time => Histogram, Unit: s", + "nservicebus.messaging.serialize_time => Histogram, Unit: s", "nservicebus.messaging.successes => Counter", + "nservicebus.outbox.duplicates => Counter", + "nservicebus.outbox.fetch_time => Histogram, Unit: s", + "nservicebus.outbox.store_time => Histogram, Unit: s", + "nservicebus.persistence.commit_time => Histogram, Unit: s", "nservicebus.recoverability.delayed => Counter", "nservicebus.recoverability.error => Counter", - "nservicebus.recoverability.immediate => Counter" + "nservicebus.recoverability.immediate => Counter", + "nservicebus.sagas.fetch_time => Histogram, Unit: s" ] } \ No newline at end of file diff --git a/src/NServiceBus.Core.Tests/Envelopes/EnvelopeUnwrapperTests.cs b/src/NServiceBus.Core.Tests/Envelopes/EnvelopeUnwrapperTests.cs index 1f2460a8b9c..2b52437cca8 100644 --- a/src/NServiceBus.Core.Tests/Envelopes/EnvelopeUnwrapperTests.cs +++ b/src/NServiceBus.Core.Tests/Envelopes/EnvelopeUnwrapperTests.cs @@ -4,12 +4,10 @@ namespace NServiceBus.Core.Tests.Envelopes; using System; using System.Buffers; using System.Collections.Generic; -using System.Text; using Extensibility; using NUnit.Framework; using Transport; - public class EnvelopeUnwrapperTests { string nativeId; @@ -31,7 +29,7 @@ public void Setup() originalBody = "payload"u8.ToArray().AsMemory(); messageContext = new MessageContext(nativeId, originalHeaders, originalBody, new TransportTransaction(), "receiveAddress", new ContextBag()); meterFactory = new TestMeterFactory(); - incomingPipelineMetrics = new IncomingPipelineMetrics(meterFactory, "queue", "disc"); + incomingPipelineMetrics = new IncomingPipelineMetrics(meterFactory, "queue", "disc", new MetersOptions()); } [TearDown] diff --git a/src/NServiceBus.Core.Tests/NServiceBus.Core.Tests.csproj b/src/NServiceBus.Core.Tests/NServiceBus.Core.Tests.csproj index 52ccab6f296..9d3ef87ddac 100644 --- a/src/NServiceBus.Core.Tests/NServiceBus.Core.Tests.csproj +++ b/src/NServiceBus.Core.Tests/NServiceBus.Core.Tests.csproj @@ -4,7 +4,6 @@ net10.0 true ..\NServiceBusTests.snk - 13.0 diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityFactoryTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityFactoryTests.cs index 6c22b89bb7b..500740cc6ba 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityFactoryTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityFactoryTests.cs @@ -17,7 +17,7 @@ namespace NServiceBus.Core.Tests.OpenTelemetry; [TestFixture] public class ActivityFactoryTests { - readonly ActivityFactory activityFactory = new(); + readonly ActivityFactory activityFactory = new(new InstrumentationOptions()); TestingActivityListener nsbActivityListener; @@ -29,7 +29,7 @@ public class ActivityFactoryTests class NoDiagnosticListeners { - readonly ActivityFactory activityFactory = new(); + readonly ActivityFactory activityFactory = new(new InstrumentationOptions()); [Test] public void Should_return_null_incoming_activity_when_no_listeners() diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityTagsTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityTagsTests.cs index 5503c58bbef..a8adbd49f86 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityTagsTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/ActivityTagsTests.cs @@ -14,14 +14,18 @@ public void Verify_ActivityTags() var activityTags = typeof(ActivityTags) .GetFields(BindingFlags.Public | BindingFlags.Static) .Where(fi => fi.IsLiteral && !fi.IsInitOnly) - .Select(x => $"{x.Name} => {x.GetRawConstantValue()}") - .ToList(); + .Select(x => $"{x.Name} => {x.GetRawConstantValue()}"); Approver.Verify(new { Note = "Changes to activity tags should result in ActivitySource version updates", - ActivitySourceVersion = ActivitySources.Main.Version, - Tags = activityTags + Tags = activityTags, + ActivitySourceVersions = new[] + { + new { Name = nameof(ActivitySources.Main), ActivitySources.Main.Version }, + new { Name = nameof(ActivitySources.Handler), ActivitySources.Handler.Version }, + new { Name = nameof(ActivitySources.Recoverability), ActivitySources.Recoverability.Version } + } }); } } \ No newline at end of file diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationCompatibilityTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationCompatibilityTests.cs new file mode 100644 index 00000000000..3dee5e145f4 --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationCompatibilityTests.cs @@ -0,0 +1,115 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using NUnit.Framework; + +[TestFixture] +public class ContextPropagationCompatibilityTests +{ + [SetUp] + public void EnableDistributedContextPropagator() + { + AppContext.SetSwitch(LegacyContextPropagation.UseDistributedContextPropagatorSwitchName, true); + LegacyContextPropagation.ResetUseDistributedContextPropagator(); + } + + [TearDown] + public void ResetDistributedContextPropagator() + { + AppContext.SetSwitch(LegacyContextPropagation.UseDistributedContextPropagatorSwitchName, false); + LegacyContextPropagation.ResetUseDistributedContextPropagator(); + } + + delegate void Writer(Activity activity, Dictionary headers); + delegate void Reader(Activity activity, IDictionary headers); + + static readonly Writer LegacyWrite = LegacyContextPropagation.PropagateContextToHeaders; + static readonly Reader LegacyRead = LegacyContextPropagation.PropagateContextFromHeaders; + static readonly Writer NewWrite = ContextPropagation.PropagateContextToHeaders; + static readonly Reader NewRead = ContextPropagation.PropagateContextFromHeaders; + + // A value exercising every class of special character: structural baggage delimiters + // (',' ';' '='), the escape char '%', quotes, brackets, slashes, ampersand, Unicode and + // an emoji, plus interior spaces. Deliberately has NO leading/trailing whitespace, so this + // value isolates "what happens to special characters" from the separate edge-whitespace + // issue covered by New_propagation_loses_leading_whitespace_in_a_value. + // This already includes property-like syntax (the ';' and '=' delimiters), so a value such as + // "zone=eu;sensitive" is just a subset and needs no separate case here. + const string AllSpecialCharacters = "a b,c;d=e&f'g\"h\\i(j)k{l}m[n]o%p/q?r:s@t~u|vx é ü 😀 z"; + + static Dictionary Send(string value, Writer write) + { + using var sender = new Activity(ActivityNames.OutgoingMessageActivityName); + sender.SetIdFormat(ActivityIdFormat.W3C); + sender.Start(); + sender.AddBaggage("key", value); + + var headers = new Dictionary(); + write(sender, headers); + sender.Stop(); + return headers; + } + + static string Receive(Dictionary headers, Reader read) + { + using var receiver = new Activity(ActivityNames.IncomingMessageActivityName); + receiver.SetIdFormat(ActivityIdFormat.W3C); + receiver.Start(); + read(receiver, headers); + return receiver.GetBaggageItem("key"); + } + + static string Transmit(string value, Writer write, Reader read) => Receive(Send(value, write), read); + + [Test] + public void Legacy_sender_to_new_receiver_preserves_the_value() + { + var received = Transmit(AllSpecialCharacters, LegacyWrite, NewRead); + Assert.That(received, Is.EqualTo(AllSpecialCharacters)); + } + + [Test] + public void New_sender_to_legacy_receiver_prepends_a_leading_space_but_keeps_the_special_characters() + { + var received = Transmit(AllSpecialCharacters, NewWrite, LegacyRead); + + Assert.That(received, Is.EqualTo(" " + AllSpecialCharacters), + "ignoring the leading space, every special character round-trips correctly"); + } + + [Test] + public void New_propagation_loses_leading_whitespace_in_a_value() + { + const string valueWithLeadingSpace = " hasLeadingSpace"; + + var legacyRoundTrip = Transmit(valueWithLeadingSpace, LegacyWrite, LegacyRead); + var newRoundTrip = Transmit(valueWithLeadingSpace, NewWrite, NewRead); + + using (Assert.EnterMultipleScope()) + { + Assert.That(legacyRoundTrip, Is.EqualTo(valueWithLeadingSpace), + "legacy propagation preserves leading whitespace via percent-encoding"); + Assert.That(newRoundTrip, Is.EqualTo("hasLeadingSpace"), + "new propagation strips the leading whitespace from the value"); + } + } + + [TestCase(null, "", "")] + [TestCase("", "", "")] + [TestCase(" ", "", " ")] + [TestCase(" x ", "x", " x ")] + [TestCase(" x x ", "x x", " x x ")] + public void ValidateThatLegacyPropagatorPreservesLeadingAndTrailingWhitespaceInBaggageValues(string input, string expectedNew, string expectedLegacy) + { + var outputNew = Transmit(input, NewWrite, NewRead); + var outputLegacy = Transmit(input, LegacyWrite, LegacyRead); + + using (Assert.EnterMultipleScope()) + { + Assert.That(expectedNew, Is.EqualTo(outputNew), "Native propagator isn't trimming all leading and trailing whitespaces"); + Assert.That(expectedLegacy, Is.EqualTo(outputLegacy), "Legacy propagator isn't preserving leading and trailing whitespace for backwards compatibility"); + } + } +} \ No newline at end of file diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationDefaultBehaviorTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationDefaultBehaviorTests.cs new file mode 100644 index 00000000000..0984daf14fd --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationDefaultBehaviorTests.cs @@ -0,0 +1,71 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using NUnit.Framework; + +[TestFixture] +public class ContextPropagationDefaultBehaviorTests +{ + // Without the opt-in switch, the endpoint default must remain the backwards-compatible + // legacy propagator (percent-encoded, comma-separated, whitespace preserved). + [SetUp] + public void EnsureDefault() + { + AppContext.SetSwitch(LegacyContextPropagation.UseDistributedContextPropagatorSwitchName, false); + LegacyContextPropagation.ResetUseDistributedContextPropagator(); + } + + [Test] + public void Default_uses_legacy_percent_encoded_baggage_format() + { + using var activity = new Activity(ActivityNames.OutgoingMessageActivityName); + activity.SetIdFormat(ActivityIdFormat.W3C); + activity.Start(); + activity.AddBaggage("serverNode", "DF 28"); + + var headers = new Dictionary(); + ContextPropagation.PropagateContextToHeaders(activity, headers); + + Assert.That(headers[Headers.DiagnosticsBaggage], Is.EqualTo("serverNode=DF%2028")); + } + + [Test] + public void Default_does_not_throw_when_baggage_value_is_null() + { + // Reproduces https://github.com/Particular/NServiceBus/issues/6983 on the legacy propagator. + // A null baggage value must not make the legacy propagator call Uri.EscapeDataString(null). + // Calls LegacyContextPropagation directly so the assertion is independent of the AppContext switch. + using var activity = new Activity(ActivityNames.OutgoingMessageActivityName); + activity.SetIdFormat(ActivityIdFormat.W3C); + activity.Start(); + activity.AddBaggage("test", null); + + var headers = new Dictionary(); + + Assert.DoesNotThrow(() => LegacyContextPropagation.PropagateContextToHeaders(activity, headers)); + Assert.That(headers[Headers.DiagnosticsBaggage], Is.EqualTo("test=")); + } + + [Test] + public void Default_round_trip_preserves_value_whitespace() + { + using var outgoing = new Activity(ActivityNames.OutgoingMessageActivityName); + outgoing.SetIdFormat(ActivityIdFormat.W3C); + outgoing.Start(); + outgoing.AddBaggage("key1", " leading-and-trailing "); + + var headers = new Dictionary(); + ContextPropagation.PropagateContextToHeaders(outgoing, headers); + + using var incoming = new Activity(ActivityNames.IncomingMessageActivityName); + incoming.SetIdFormat(ActivityIdFormat.W3C); + incoming.Start(); + ContextPropagation.PropagateContextFromHeaders(incoming, headers); + + // Legacy propagation preserves leading/trailing whitespace via percent-encoding; + // the DistributedContextPropagator (opt-in) would trim it. + Assert.That(incoming.GetBaggageItem("key1"), Is.EqualTo(" leading-and-trailing ")); + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/HandlerActivitySourceTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/HandlerActivitySourceTests.cs new file mode 100644 index 00000000000..8af728a9c8a --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/HandlerActivitySourceTests.cs @@ -0,0 +1,95 @@ +#nullable enable + +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System; +using System.Collections.Immutable; +using System.Diagnostics; +using System.Linq; +using Helpers; +using NServiceBus.Pipeline; +using NUnit.Framework; + +[TestFixture] +public class HandlerActivitySourceTests +{ + readonly ActivityFactory activityFactory = new(new InstrumentationOptions()); + + TestingActivityListener mainListener; + + [SetUp] + public void SetUp() => mainListener = TestingActivityListener.SetupNServiceBusDiagnosticListener(); + + [TearDown] + public void TearDown() + { + mainListener.Dispose(); + AppContext.SetSwitch(HandlerActivitySourceSwitch.UseHandlerActivitySourceSwitchName, false); + HandlerActivitySourceSwitch.ResetUseHandlerActivitySource(); + } + + static void OptIn() + { + AppContext.SetSwitch(HandlerActivitySourceSwitch.UseHandlerActivitySourceSwitchName, true); + HandlerActivitySourceSwitch.ResetUseHandlerActivitySource(); + } + + [Test] + public void Default_emits_handler_activity_from_main_source() + { + using var ambientActivity = new Activity("ambient activity"); + ambientActivity.Start(); + + var activity = activityFactory.StartHandlerActivity(new MessageHandler { HandlerType = typeof(HandlerActivitySourceTests) }); + + Assert.That(activity, Is.Not.Null); + Assert.That(activity!.Source.Name, Is.EqualTo("NServiceBus.Core")); + } + + [Test] + public void Opt_in_emits_handler_activity_from_handler_source() + { + OptIn(); + using var handlerListener = TestingActivityListener.SetupDiagnosticListener("NServiceBus.Core.Handler"); + + using var ambientActivity = new Activity("ambient activity"); + ambientActivity.Start(); + + var activity = activityFactory.StartHandlerActivity(new MessageHandler { HandlerType = typeof(HandlerActivitySourceTests) }); + + Assert.That(activity, Is.Not.Null); + Assert.That(activity!.Source.Name, Is.EqualTo("NServiceBus.Core.Handler")); + } + + [Test] + public void Opt_in_preserves_display_name_and_handler_type_tag() + { + OptIn(); + using var handlerListener = TestingActivityListener.SetupDiagnosticListener("NServiceBus.Core.Handler"); + + using var ambientActivity = new Activity("ambient activity"); + ambientActivity.Start(); + + Type handlerType = typeof(HandlerActivitySourceTests); + var activity = activityFactory.StartHandlerActivity(new MessageHandler { HandlerType = handlerType }); + + Assert.That(activity, Is.Not.Null); + Assert.That(activity!.DisplayName, Is.EqualTo(handlerType.Name)); + var tags = activity.Tags.ToImmutableDictionary(); + Assert.That(tags[ActivityTags.HandlerType], Is.EqualTo(handlerType.FullName)); + } + + [Test] + public void Opt_in_without_handler_source_listener_does_not_create_handler_activity() + { + OptIn(); + + using var ambientActivity = new Activity("ambient activity"); + ambientActivity.Start(); + + var activity = activityFactory.StartHandlerActivity(new MessageHandler { HandlerType = typeof(HandlerActivitySourceTests) }); + + Assert.That(activity, Is.Null, "handler activity must not be created when the dedicated source has no listeners"); + Assert.That(Activity.Current, Is.SameAs(ambientActivity), "user tags must land on the parent (process message) activity"); + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/Helpers/TestingMetricListener.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/Helpers/TestingMetricListener.cs index cbae1435e61..f288d4f4476 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/Helpers/TestingMetricListener.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/Helpers/TestingMetricListener.cs @@ -10,7 +10,6 @@ namespace NServiceBus.AcceptanceTests.Core.OpenTelemetry.Metrics; class TestingMetricListener : IDisposable { readonly MeterListener meterListener; - readonly ConcurrentDictionary subscribedInstruments = new(StringComparer.Ordinal); public readonly List metrics = []; public string version = ""; public string metricsSourceName = ""; @@ -26,12 +25,6 @@ class TestingMetricListener : IDisposable return; } - var instrumentKey = $"{instrument.Meter.Name}|{instrument.Name}|{instrument.GetType().FullName}"; - if (!subscribedInstruments.TryAdd(instrumentKey, 0)) - { - return; - } - TestContext.Out.WriteLine($"Subscribing to {instrument.Meter.Name}\\{instrument.Name}"); listener.EnableMeasurementEvents(instrument); metrics.Add(instrument); diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/InstrumentationOptionsTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/InstrumentationOptionsTests.cs new file mode 100644 index 00000000000..ded2e6a41c2 --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/InstrumentationOptionsTests.cs @@ -0,0 +1,19 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using NUnit.Framework; + +[TestFixture] +public class InstrumentationOptionsTests +{ + [Test] + public void Should_default_trace_connectors_to_current_behavior() + { + var options = new InstrumentationOptions(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(options.SendTraceMode, Is.EqualTo(TraceMode.ContinueExisting), "sends continue the trace by default"); + Assert.That(options.PublishTraceMode, Is.EqualTo(TraceMode.StartNew), "publishes start a new linked trace by default"); + } + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/LegacyContextPropagationTests.cs similarity index 70% rename from src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationTests.cs rename to src/NServiceBus.Core.Tests/OpenTelemetry/LegacyContextPropagationTests.cs index 6de0d1ade7a..4e90b6b3e1b 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/ContextPropagationTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/LegacyContextPropagationTests.cs @@ -5,11 +5,10 @@ using System.Collections.Generic; using System.Diagnostics; using System.Linq; -using Extensibility; using NUnit.Framework; [TestFixture] -public class ContextPropagationTests +public class LegacyContextPropagationTests { [Test] public void Propagate_activity_id_to_header() @@ -20,7 +19,7 @@ public void Propagate_activity_id_to_header() var headers = new Dictionary(); - ContextPropagation.PropagateContextToHeaders(activity, headers, new ContextBag()); + ContextPropagation.PropagateContextToHeaders(activity, headers); Assert.That(activity.Id, Is.EqualTo(headers[Headers.DiagnosticsTraceParent])); } @@ -30,56 +29,42 @@ public void Should_not_set_header_without_activity() { var headers = new Dictionary(); - ContextPropagation.PropagateContextToHeaders(null, headers, new ContextBag()); + ContextPropagation.PropagateContextToHeaders(null, headers); Assert.That(headers, Is.Empty); } [Test] - public void Should_set_start_new_trace_header_when_adding_trace_parent_header() + public void Overwrites_existing_propagation_header() { using var activity = new Activity("test"); activity.SetIdFormat(ActivityIdFormat.W3C); activity.Start(); - var headers = new Dictionary(); - var contextBag = new ContextBag(); - contextBag.Set(Headers.StartNewTrace, bool.TrueString); - ContextPropagation.PropagateContextToHeaders(activity, headers, contextBag); - - using (Assert.EnterMultipleScope()) + var headers = new Dictionary() { - Assert.That(headers.ContainsKey(Headers.StartNewTrace), Is.True, bool.TrueString); - Assert.That(bool.TrueString, Is.EqualTo(headers[Headers.StartNewTrace])); - } - } + { Headers.DiagnosticsTraceParent, "some existing id" } + }; - [Test] - public void Should_not_set_start_new_trace_header_when_no_trace_parent_header_is_added() - { - var headers = new Dictionary(); - var contextBag = new ContextBag(); - contextBag.Set(Headers.StartNewTrace, bool.TrueString); - ContextPropagation.PropagateContextToHeaders(null, headers, contextBag); + ContextPropagation.PropagateContextToHeaders(activity, headers); - Assert.That(headers.ContainsKey(Headers.StartNewTrace), Is.False); + Assert.That(activity.Id, Is.EqualTo(headers[Headers.DiagnosticsTraceParent])); } [Test] - public void Overwrites_existing_propagation_header() + public void Should_not_throw_when_baggage_value_is_null() { - using var activity = new Activity("test"); + // Reproduces https://github.com/Particular/NServiceBus/issues/6983 + // A baggage item with a null value used to make the hand-written propagator call + // Uri.EscapeDataString(null), throwing ArgumentNullException while sending a message. + using var activity = new Activity(ActivityNames.OutgoingMessageActivityName); activity.SetIdFormat(ActivityIdFormat.W3C); activity.Start(); + activity.AddBaggage("test", null); - var headers = new Dictionary() - { - { Headers.DiagnosticsTraceParent, "some existing id" } - }; - - ContextPropagation.PropagateContextToHeaders(activity, headers, new ContextBag()); + var headers = new Dictionary(); - Assert.That(activity.Id, Is.EqualTo(headers[Headers.DiagnosticsTraceParent])); + Assert.DoesNotThrow(() => ContextPropagation.PropagateContextToHeaders(activity, headers)); } [TestCaseSource(nameof(TestCases))] @@ -94,7 +79,9 @@ public void Can_propagate_baggage_from_header_to_activity(ContextPropagationTest headers[Headers.DiagnosticsBaggage] = testCase.BaggageHeaderValue; } - var activity = new Activity(ActivityNames.IncomingMessageActivityName); + using var activity = new Activity(ActivityNames.IncomingMessageActivityName); + activity.SetIdFormat(ActivityIdFormat.W3C); + activity.Start(); ContextPropagation.PropagateContextFromHeaders(activity, headers); @@ -114,14 +101,16 @@ public void Can_propagate_baggage_from_activity_to_header(ContextPropagationTest var headers = new Dictionary(); - var activity = new Activity(ActivityNames.OutgoingMessageActivityName); + using var activity = new Activity(ActivityNames.OutgoingMessageActivityName); + activity.SetIdFormat(ActivityIdFormat.W3C); + activity.Start(); foreach (var baggageItem in testCase.ExpectedBaggageItems.Reverse()) { activity.AddBaggage(baggageItem.Key, baggageItem.Value); } - ContextPropagation.PropagateContextToHeaders(activity, headers, new ContextBag()); + ContextPropagation.PropagateContextToHeaders(activity, headers); var baggageHeaderSet = headers.TryGetValue(Headers.DiagnosticsBaggage, out var baggageValue); @@ -131,7 +120,7 @@ public void Can_propagate_baggage_from_activity_to_header(ContextPropagationTest { Assert.That(baggageHeaderSet, Is.True, "Should have a baggage header if there is baggage"); - Assert.That(baggageValue, Is.EqualTo(testCase.BaggageHeaderValueWithoutOptionalWhitespace), "baggage header is set but is not correct"); + Assert.That(baggageValue, Is.EqualTo(testCase.BaggageHeaderValue), "baggage header is set but is not correct"); } } else @@ -146,18 +135,22 @@ public void Can_roundtrip_baggage(ContextPropagationTestCase testCase) TestContext.Out.WriteLine($"Baggage header: {testCase.BaggageHeaderValue}"); var outgoingHeaders = new Dictionary(); - var outgoingActivity = new Activity(ActivityNames.OutgoingMessageActivityName); + using var outgoingActivity = new Activity(ActivityNames.OutgoingMessageActivityName); + outgoingActivity.SetIdFormat(ActivityIdFormat.W3C); + outgoingActivity.Start(); foreach (var baggageItem in testCase.ExpectedBaggageItems.Reverse()) { outgoingActivity.AddBaggage(baggageItem.Key, baggageItem.Value); } - ContextPropagation.PropagateContextToHeaders(outgoingActivity, outgoingHeaders, new ContextBag()); + ContextPropagation.PropagateContextToHeaders(outgoingActivity, outgoingHeaders); // Simulate wire transfer var incomingHeaders = outgoingHeaders; - var incomingActivity = new Activity(ActivityNames.IncomingMessageActivityName); + using var incomingActivity = new Activity(ActivityNames.IncomingMessageActivityName); + incomingActivity.SetIdFormat(ActivityIdFormat.W3C); + incomingActivity.Start(); ContextPropagation.PropagateContextFromHeaders(incomingActivity, incomingHeaders); @@ -176,49 +169,48 @@ public void Can_roundtrip_baggage(ContextPropagationTestCase testCase) new ContextPropagationTestCase("without any baggage"), new ContextPropagationTestCase("with a single key") - .WithBaggage("key1", "value1"), + .WithBaggage("key1", "value1") + .WithHeaderValue("key1=value1"), new ContextPropagationTestCase("with multiple keys") .WithBaggage("key1", "value1") - .WithBaggage("key2", "value2"), - - new ContextPropagationTestCase("with whitespace") - .WithBaggage("key1 ", " value1") - .WithBaggage(" key2", "value2 ") - .WithBaggage(" key3 ", " value3 "), + .WithBaggage("key2", "value2") + .WithHeaderValue("key1=value1,key2=value2"), new ContextPropagationTestCase("with properties that do not have keys") - .WithBaggage("key1", "value1;property1;property2"), + .WithBaggage("key1", "value1;property1;property2") + .WithHeaderValue("key1=value1%3Bproperty1%3Bproperty2"), new ContextPropagationTestCase("with properties that have keys") - .WithBaggage("key3", "value3; propertyKey=propertyValue"), + .WithBaggage("key3", "value3; propertyKey=propertyValue") + .WithHeaderValue("key3=value3%3B%20propertyKey%3DpropertyValue"), new ContextPropagationTestCase("with values containing whitespace") - .WithBaggage("serverNode", "DF 28"), + .WithBaggage("serverNode", "DF 28") + .WithHeaderValue("serverNode=DF%2028"), new ContextPropagationTestCase("with values containing unicode") .WithBaggage("userId", "Amélie") + .WithHeaderValue("userId=Am%C3%A9lie") }; - public class ContextPropagationTestCase + public class ContextPropagationTestCase(string caseName) { - string caseName; - Dictionary baggageItems = []; + readonly Dictionary baggageItems = []; - public ContextPropagationTestCase(string caseName) + public ContextPropagationTestCase WithBaggage(string key, string value) { - this.caseName = caseName; + baggageItems.Add(key, value); + return this; } - public ContextPropagationTestCase WithBaggage(string key, string value) + public ContextPropagationTestCase WithHeaderValue(string headerValue) { - baggageItems.Add(key, value); + BaggageHeaderValue = headerValue; return this; } - public string BaggageHeaderValue => string.Join(",", from kvp in baggageItems select $"{kvp.Key}={Uri.EscapeDataString(kvp.Value)}"); - public string BaggageHeaderValueWithoutOptionalWhitespace - => string.Join(",", from kvp in baggageItems select $"{kvp.Key.Trim()}={Uri.EscapeDataString(kvp.Value)}"); + public string BaggageHeaderValue { get; private set; } public IEnumerable> ExpectedBaggageItems => from kvp in baggageItems select new KeyValuePair( kvp.Key.Trim(), diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/MeterTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/MeterTests.cs index b59ee8b556e..83b1e16e1d3 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/MeterTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/MeterTests.cs @@ -20,9 +20,9 @@ public void Verify_MeterAPI() .ToList(); using var meterFactory = new TestMeterFactory(); - //The IncomingPipelineMetrics constructor creates the meters, therefore a new instance before collecting the metrics. + //The IncomingPipelineMeter constructor creates the meters, therefore a new instance before collecting the metrics. #pragma warning disable CA1806 - new IncomingPipelineMetrics(meterFactory, "queue", "disc"); + new IncomingPipelineMetrics(meterFactory, "queue", "disc", new MetersOptions()); #pragma warning restore CA1806 using var metricsListener = TestingMetricListener.SetupNServiceBusMetricsListener(); diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryExtensionsTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryExtensionsTests.cs new file mode 100644 index 00000000000..7428d6e660f --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryExtensionsTests.cs @@ -0,0 +1,139 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System.Collections.Generic; +using NUnit.Framework; +using Settings; + +[TestFixture] +public class OpenTelemetryExtensionsTests +{ + [Test] + public void StartNewTraceOnReceive_should_set_span_link_override_on_send_options() + { + var options = new SendOptions(); + + options.StartNewTraceOnReceive(); + + Assert.That(options.Context.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode connector), Is.True); + Assert.That(connector, Is.EqualTo(TraceMode.StartNew)); + } + + [Test] + public void ContinueExistingTraceOnReceive_should_set_child_span_override_on_send_options() + { + var options = new SendOptions(); + + options.ContinueExistingTraceOnReceive(); + + Assert.That(options.Context.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode connector), Is.True); + Assert.That(connector, Is.EqualTo(TraceMode.ContinueExisting)); + } + + [Test] + public void StartNewTraceOnReceive_should_set_span_link_override_on_publish_options() + { + var options = new PublishOptions(); + + options.StartNewTraceOnReceive(); + + Assert.That(options.Context.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode connector), Is.True); + Assert.That(connector, Is.EqualTo(TraceMode.StartNew)); + } + + [Test] + public void ContinueExistingTraceOnReceive_should_set_child_span_override_on_publish_options() + { + var options = new PublishOptions(); + + options.ContinueExistingTraceOnReceive(); + + Assert.That(options.Context.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode connector), Is.True); + Assert.That(connector, Is.EqualTo(TraceMode.ContinueExisting)); + } + + [Test] + public void Last_override_call_wins() + { + var options = new PublishOptions(); + + options.ContinueExistingTraceOnReceive(); + options.StartNewTraceOnReceive(); + + Assert.That(options.Context.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode connector), Is.True); + Assert.That(connector, Is.EqualTo(TraceMode.StartNew)); + } + + [Test] + public void Defaults_to_span_and_logs_when_opt_in_environment_variable_is_not_set() + { + var settingsHolder = new SettingsHolder(); + settingsHolder.Set(new FakeEnvironment { ValueToReturn = [] }); + + InstrumentationOptions.SetExceptionRecordingModeDefault(settingsHolder); + + Assert.That(settingsHolder.Get().ExceptionRecordingMode, Is.EqualTo(ExceptionRecordingMode.SpanAndLogs)); + } + + [Test] + public void Uses_logs_only_when_opt_in_environment_variable_is_logs() + { + var settingsHolder = new SettingsHolder(); + settingsHolder.Set(new FakeEnvironment + { + ValueToReturn = new Dictionary { { InstrumentationOptions.ExceptionSignalOptInEnvironmentVariableKey, "logs" } } + }); + + InstrumentationOptions.SetExceptionRecordingModeDefault(settingsHolder); + + Assert.That(settingsHolder.Get().ExceptionRecordingMode, Is.EqualTo(ExceptionRecordingMode.Logs)); + } + + [Test] + public void Uses_span_and_logs_when_opt_in_environment_variable_is_logs_dup() + { + var settingsHolder = new SettingsHolder(); + settingsHolder.Set(new FakeEnvironment + { + ValueToReturn = new Dictionary { { InstrumentationOptions.ExceptionSignalOptInEnvironmentVariableKey, "logs/dup" } } + }); + + InstrumentationOptions.SetExceptionRecordingModeDefault(settingsHolder); + + Assert.That(settingsHolder.Get().ExceptionRecordingMode, Is.EqualTo(ExceptionRecordingMode.SpanAndLogs)); + } + + [Test] + public void Environment_variable_takes_precedence_over_explicit_configuration() + { + var settingsHolder = new SettingsHolder(); + settingsHolder.Set(new FakeEnvironment + { + ValueToReturn = new Dictionary { { InstrumentationOptions.ExceptionSignalOptInEnvironmentVariableKey, "logs" } } + }); + + // explicitly configured to something other than what the environment variable resolves to + settingsHolder.Set(new InstrumentationOptions { ExceptionRecordingMode = ExceptionRecordingMode.SpanAndLogs }); + InstrumentationOptions.SetExceptionRecordingModeDefault(settingsHolder); + + Assert.That(settingsHolder.Get().ExceptionRecordingMode, Is.EqualTo(ExceptionRecordingMode.Logs)); + } + + [Test] + public void Explicit_configuration_is_preserved_when_environment_variable_is_not_set() + { + var settingsHolder = new SettingsHolder(); + settingsHolder.Set(new FakeEnvironment { ValueToReturn = [] }); + + settingsHolder.Set(new InstrumentationOptions { ExceptionRecordingMode = ExceptionRecordingMode.Logs }); + InstrumentationOptions.SetExceptionRecordingModeDefault(settingsHolder); + + Assert.That(settingsHolder.Get().ExceptionRecordingMode, Is.EqualTo(ExceptionRecordingMode.Logs)); + } + + class FakeEnvironment : SystemEnvironment + { + public Dictionary ValueToReturn { get; set; } + + public override string GetEnvironmentVariable(string variable) => ValueToReturn.GetValueOrDefault(variable); + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryPublishBehaviorTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryPublishBehaviorTests.cs new file mode 100644 index 00000000000..3cc9e44ee06 --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetryPublishBehaviorTests.cs @@ -0,0 +1,55 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System.Threading.Tasks; +using NUnit.Framework; +using Testing; + +[TestFixture] +public class OpenTelemetryPublishBehaviorTests +{ + [Test] + public async Task Should_start_new_trace_on_receive_by_default() + { + var behavior = new OpenTelemetryPublishBehavior(new InstrumentationOptions()); + var context = new TestableOutgoingPublishContext(); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.TrueString)); + } + + [Test] + public async Task Should_continue_trace_on_receive_when_endpoint_connector_is_child_span() + { + var behavior = new OpenTelemetryPublishBehavior(new InstrumentationOptions { PublishTraceMode = TraceMode.ContinueExisting }); + var context = new TestableOutgoingPublishContext(); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.FalseString)); + } + + [Test] + public async Task Should_prefer_child_span_option_over_endpoint_connector() + { + var behavior = new OpenTelemetryPublishBehavior(new InstrumentationOptions { PublishTraceMode = TraceMode.StartNew }); + var context = new TestableOutgoingPublishContext(); + context.Extensions.Set(OpenTelemetryExtensions.TraceConnectorOverrideKey, TraceMode.ContinueExisting); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.FalseString)); + } + + [Test] + public async Task Should_prefer_span_link_option_over_endpoint_connector() + { + var behavior = new OpenTelemetryPublishBehavior(new InstrumentationOptions { PublishTraceMode = TraceMode.ContinueExisting }); + var context = new TestableOutgoingPublishContext(); + context.Extensions.Set(OpenTelemetryExtensions.TraceConnectorOverrideKey, TraceMode.StartNew); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.TrueString)); + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetrySendBehaviorTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetrySendBehaviorTests.cs new file mode 100644 index 00000000000..8e26d213544 --- /dev/null +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/OpenTelemetrySendBehaviorTests.cs @@ -0,0 +1,55 @@ +namespace NServiceBus.Core.Tests.OpenTelemetry; + +using System.Threading.Tasks; +using NUnit.Framework; +using Testing; + +[TestFixture] +public class OpenTelemetrySendBehaviorTests +{ + [Test] + public async Task Should_continue_trace_on_receive_by_default() + { + var behavior = new OpenTelemetrySendBehavior(new InstrumentationOptions()); + var context = new TestableOutgoingSendContext(); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.FalseString)); + } + + [Test] + public async Task Should_start_new_trace_on_receive_when_endpoint_connector_is_span_link() + { + var behavior = new OpenTelemetrySendBehavior(new InstrumentationOptions { SendTraceMode = TraceMode.StartNew }); + var context = new TestableOutgoingSendContext(); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.TrueString)); + } + + [Test] + public async Task Should_prefer_span_link_option_over_endpoint_connector() + { + var behavior = new OpenTelemetrySendBehavior(new InstrumentationOptions { SendTraceMode = TraceMode.ContinueExisting }); + var context = new TestableOutgoingSendContext(); + context.Extensions.Set(OpenTelemetryExtensions.TraceConnectorOverrideKey, TraceMode.StartNew); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.TrueString)); + } + + [Test] + public async Task Should_prefer_child_span_option_over_endpoint_connector() + { + var behavior = new OpenTelemetrySendBehavior(new InstrumentationOptions { SendTraceMode = TraceMode.StartNew }); + var context = new TestableOutgoingSendContext(); + context.Extensions.Set(OpenTelemetryExtensions.TraceConnectorOverrideKey, TraceMode.ContinueExisting); + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Headers[Headers.StartNewTrace], Is.EqualTo(bool.FalseString)); + } +} diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/PopulateRecoverabilityTraceMetadataBehaviorTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/PopulateRecoverabilityTraceMetadataBehaviorTests.cs index cee304d848d..cb8e2d5823b 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/PopulateRecoverabilityTraceMetadataBehaviorTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/PopulateRecoverabilityTraceMetadataBehaviorTests.cs @@ -12,7 +12,7 @@ public class PopulateRecoverabilityTraceMetadataBehaviorTests [Test] public async Task Should_not_write_metadata_when_trace_not_present() { - var behavior = new PopulateRecoverabilityTraceMetadataBehavior(); + var behavior = new PopulateRecoverabilityTraceMetadataBehavior(new InstrumentationOptions()); var context = new TestableRecoverabilityContext(); await behavior.Invoke(context, _ => Task.CompletedTask); @@ -25,10 +25,10 @@ public async Task Should_not_write_metadata_when_trace_not_present() } [Test] - [TestCaseSource(nameof(Actions))] + [TestCaseSource(nameof(ActionsThatWriteMetadata))] public async Task Should_write_metadata_when_trace_present(RecoverabilityAction recoverabilityAction) { - var behavior = new PopulateRecoverabilityTraceMetadataBehavior(); + var behavior = new PopulateRecoverabilityTraceMetadataBehavior(new InstrumentationOptions()); var context = new TestableRecoverabilityContext { @@ -45,9 +45,63 @@ public async Task Should_write_metadata_when_trace_present(RecoverabilityAction } } - static IEnumerable Actions() + [Test] + public async Task Should_not_write_metadata_for_immediate_retry() + { + var behavior = new PopulateRecoverabilityTraceMetadataBehavior(new InstrumentationOptions()); + + var context = new TestableRecoverabilityContext + { + Headers = { { Headers.DiagnosticsTraceParent, "traceparent" } }, + RecoverabilityAction = new ImmediateRetry() + }; + + await behavior.Invoke(context, _ => Task.CompletedTask); + + using (Assert.EnterMultipleScope()) + { + Assert.That(context.Headers, Does.Not.ContainKey(Headers.StartNewTrace)); + Assert.That(context.Metadata, Does.Not.ContainKey(Headers.StartNewTrace)); + } + } + + [Test] + public async Task Should_always_start_new_trace_for_move_to_error() + { + var behavior = new PopulateRecoverabilityTraceMetadataBehavior(new InstrumentationOptions()); + + var context = new TestableRecoverabilityContext + { + Headers = { { Headers.DiagnosticsTraceParent, "traceparent" } }, + RecoverabilityAction = new MoveToError("errorqueue") + }; + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Metadata[Headers.StartNewTrace], Is.EqualTo(bool.TrueString)); + } + + [Test] + public async Task Should_honor_delayed_retry_trace_mode() + { + var behavior = new PopulateRecoverabilityTraceMetadataBehavior(new InstrumentationOptions + { + Recoverability = { DelayedRetryTraceMode = TraceMode.ContinueExisting } + }); + + var context = new TestableRecoverabilityContext + { + Headers = { { Headers.DiagnosticsTraceParent, "traceparent" } }, + RecoverabilityAction = new DelayedRetry(TimeSpan.FromSeconds(10)) + }; + + await behavior.Invoke(context, _ => Task.CompletedTask); + + Assert.That(context.Metadata[Headers.StartNewTrace], Is.EqualTo(bool.FalseString)); + } + + static IEnumerable ActionsThatWriteMetadata() { - yield return new ImmediateRetry(); yield return new DelayedRetry(TimeSpan.FromSeconds(10)); yield return new MoveToError("errorqueue"); } diff --git a/src/NServiceBus.Core.Tests/OpenTelemetry/TracingExtensionsTests.cs b/src/NServiceBus.Core.Tests/OpenTelemetry/TracingExtensionsTests.cs index 64c1947dbf5..4b6473de6f5 100644 --- a/src/NServiceBus.Core.Tests/OpenTelemetry/TracingExtensionsTests.cs +++ b/src/NServiceBus.Core.Tests/OpenTelemetry/TracingExtensionsTests.cs @@ -21,7 +21,7 @@ public async Task Invoke_should_invoke_pipeline_when_activity_null() return Task.CompletedTask; }); - await pipeline.Invoke(new FakeRootContext(), null); + await pipeline.Invoke(new FakeRootContext(), null, new ActivityFactory(new InstrumentationOptions())); Assert.That(invokedPipeline, Is.True); } @@ -33,7 +33,7 @@ public async Task Invoke_should_set_success_status_when_no_exception() using var activity = new Activity("test activity"); activity.Start(); - await pipeline.Invoke(new FakeRootContext(), activity); + await pipeline.Invoke(new FakeRootContext(), activity, new ActivityFactory(new InstrumentationOptions())); Assert.That(activity.Status, Is.EqualTo(ActivityStatusCode.Ok)); } @@ -46,7 +46,7 @@ public void Invoke_should_set_error_status_and_tags_when_exception() using var activity = new Activity("test activity"); activity.Start(); - Assert.ThrowsAsync(() => pipeline.Invoke(new FakeRootContext(), activity)); + Assert.ThrowsAsync(() => pipeline.Invoke(new FakeRootContext(), activity, new ActivityFactory(new InstrumentationOptions()))); Assert.That(activity.Status, Is.EqualTo(ActivityStatusCode.Error)); @@ -61,6 +61,23 @@ public void Invoke_should_set_error_status_and_tags_when_exception() Assert.That(errorEvent.Name, Is.EqualTo("exception")); } + [Test] + public void Invoke_should_set_error_status_without_exception_event_when_log_mode() + { + var exception = new Exception("test exception"); + var pipeline = new FakePipeline(() => throw exception); + using var activity = new Activity("test activity"); + activity.Start(); + + Assert.ThrowsAsync(() => pipeline.Invoke(new FakeRootContext(), activity, new ActivityFactory(new InstrumentationOptions { ExceptionRecordingMode = ExceptionRecordingMode.Logs }))); + + using (Assert.EnterMultipleScope()) + { + Assert.That(activity.Status, Is.EqualTo(ActivityStatusCode.Error)); + Assert.That(activity.Events, Is.Empty, "no exception event should be added when recording via the log instead"); + } + } + class FakePipeline : IPipeline { readonly Func pipelineAction; diff --git a/src/NServiceBus.Core.Tests/Pipeline/Incoming/InvokeHandlerTerminatorTest.cs b/src/NServiceBus.Core.Tests/Pipeline/Incoming/InvokeHandlerTerminatorTest.cs index f36af8a855a..b794eb25413 100644 --- a/src/NServiceBus.Core.Tests/Pipeline/Incoming/InvokeHandlerTerminatorTest.cs +++ b/src/NServiceBus.Core.Tests/Pipeline/Incoming/InvokeHandlerTerminatorTest.cs @@ -11,7 +11,7 @@ [TestFixture] public class InvokeHandlerTerminatorTest { - InvokeHandlerTerminator terminator = new(new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc")); + readonly InvokeHandlerTerminator terminator = new(new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); [Test] public async Task When_saga_found_and_handler_is_saga_should_invoke_handler() diff --git a/src/NServiceBus.Core.Tests/Pipeline/Incoming/SerializeMessageConnectorTests.cs b/src/NServiceBus.Core.Tests/Pipeline/Incoming/SerializeMessageConnectorTests.cs index 12b7ed19bc6..76e0efb2e00 100644 --- a/src/NServiceBus.Core.Tests/Pipeline/Incoming/SerializeMessageConnectorTests.cs +++ b/src/NServiceBus.Core.Tests/Pipeline/Incoming/SerializeMessageConnectorTests.cs @@ -4,6 +4,7 @@ using System.Collections.Generic; using System.IO; using System.Threading.Tasks; +using NServiceBus.Core.Tests.OpenTelemetry; using NServiceBus.Pipeline; using NUnit.Framework; using Serialization; @@ -29,7 +30,7 @@ public async Task Should_set_content_type_header() Message = new OutgoingLogicalMessage(typeof(MyMessage), new MyMessage()) }; - var behavior = new SerializeMessageConnector(new FakeSerializer("myContentType"), registry); + var behavior = new SerializeMessageConnector(new FakeSerializer("myContentType"), registry, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); await behavior.Invoke(context, c => Task.CompletedTask); diff --git a/src/NServiceBus.Core.Tests/Pipeline/IncomingPipelineMetricTagsTests.cs b/src/NServiceBus.Core.Tests/Pipeline/IncomingPipelineMetricTagsTests.cs index 52576e26016..1ce103a841c 100644 --- a/src/NServiceBus.Core.Tests/Pipeline/IncomingPipelineMetricTagsTests.cs +++ b/src/NServiceBus.Core.Tests/Pipeline/IncomingPipelineMetricTagsTests.cs @@ -5,6 +5,7 @@ namespace NServiceBus.Core.Tests.Pipeline.Incoming; using System.IO; using System.Threading.Tasks; using MessageInterfaces.MessageMapper.Reflection; +using NServiceBus.Core.Tests.OpenTelemetry; using NServiceBus.Pipeline; using NUnit.Framework; using Serialization; @@ -35,11 +36,11 @@ public void Should_not_fail_when_handling_more_than_one_logical_message() }; var messageMapper = new MessageMapper(); - var behavior = new DeserializeMessageConnector(new MessageDeserializerResolver(new FakeSerializer(), []), new LogicalMessageFactory(registry, messageMapper), registry, messageMapper, false); + var behavior = new DeserializeMessageConnector(new MessageDeserializerResolver(new FakeSerializer(), []), new LogicalMessageFactory(registry, messageMapper), registry, messageMapper, false, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); Assert.DoesNotThrowAsync(async () => await behavior.Invoke(context, c => { - c.Extensions.Get().Add("Same", "Same"); + c.IncomingMetricTags.Add("Same", "Same"); return Task.CompletedTask; })); } diff --git a/src/NServiceBus.Core.Tests/Pipeline/MainPipelineExecutorTests.cs b/src/NServiceBus.Core.Tests/Pipeline/MainPipelineExecutorTests.cs index f6223a25eac..8befd4e48c9 100644 --- a/src/NServiceBus.Core.Tests/Pipeline/MainPipelineExecutorTests.cs +++ b/src/NServiceBus.Core.Tests/Pipeline/MainPipelineExecutorTests.cs @@ -123,14 +123,14 @@ static MessageContext CreateMessageContext() => static MainPipelineExecutor CreateMainPipelineExecutor(ServiceProvider serviceProvider, IPipeline receivePipeline) { - var incomingPipelineMetrics = new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc"); + var incomingPipelineMetrics = new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions()); var executor = new MainPipelineExecutor( serviceProvider, new PipelineCache(serviceProvider, new PipelineModifications()), new TestableMessageOperations(), new Notification(), receivePipeline, - new ActivityFactory(), + new ActivityFactory(new InstrumentationOptions()), incomingPipelineMetrics, new EnvelopeUnwrapper([], incomingPipelineMetrics)); diff --git a/src/NServiceBus.Core.Tests/Pipeline/TestableMessageOperations.cs b/src/NServiceBus.Core.Tests/Pipeline/TestableMessageOperations.cs index ddb58d3a66e..909b9fb796a 100644 --- a/src/NServiceBus.Core.Tests/Pipeline/TestableMessageOperations.cs +++ b/src/NServiceBus.Core.Tests/Pipeline/TestableMessageOperations.cs @@ -13,7 +13,7 @@ class TestableMessageOperations : MessageOperations public Pipeline SubscribePipeline => (Pipeline)subscribePipeline; public Pipeline UnsubscribePipeline => (Pipeline)unsubscribePipeline; - public TestableMessageOperations() : base(new MessageMapper(), new Pipeline(), new Pipeline(), new Pipeline(), new Pipeline(), new Pipeline(), new ActivityFactory()) + public TestableMessageOperations() : base(new MessageMapper(), new Pipeline(), new Pipeline(), new Pipeline(), new Pipeline(), new Pipeline(), new ActivityFactory(new InstrumentationOptions())) { } diff --git a/src/NServiceBus.Core.Tests/Recoverability/RecoverabilityExecutorTests.cs b/src/NServiceBus.Core.Tests/Recoverability/RecoverabilityExecutorTests.cs index 1b3a92cf0a9..139a3ff7185 100644 --- a/src/NServiceBus.Core.Tests/Recoverability/RecoverabilityExecutorTests.cs +++ b/src/NServiceBus.Core.Tests/Recoverability/RecoverabilityExecutorTests.cs @@ -1,7 +1,6 @@ namespace NServiceBus.Core.Tests.Recoverability; using System; -using System.Collections.Generic; using System.Threading.Tasks; using Microsoft.Extensions.DependencyInjection; using Pipeline; @@ -64,13 +63,16 @@ public async Task Should_use_error_context_extensions_as_extensions_root() static RecoverabilityPipelineExecutor CreateRecoverabilityExecutor(TestableMessageOperations.Pipeline recoverabilityPipeline) { var executor = new RecoverabilityPipelineExecutor( - new ServiceCollection().BuildServiceProvider(), // TODO: Does not get disposed + new ServiceCollection().AddLogging().BuildServiceProvider(), // TODO: Does not get disposed new ThrowingPipelineCache(), new TestableMessageOperations(), - null, (_, _) => RecoverabilityAction.Discard("test"), + null, + (_, _) => RecoverabilityAction.Discard("test"), recoverabilityPipeline, new FaultMetadataExtractor([], _ => { }), - null); + null, + NoOpActivityFactory.Instance + ); return executor; } diff --git a/src/NServiceBus.Core.Tests/Reliability/Outbox/TransportReceiveToPhysicalMessageConnectorTests.cs b/src/NServiceBus.Core.Tests/Reliability/Outbox/TransportReceiveToPhysicalMessageConnectorTests.cs index 96e3f57b8e8..e33a9ef34a2 100644 --- a/src/NServiceBus.Core.Tests/Reliability/Outbox/TransportReceiveToPhysicalMessageConnectorTests.cs +++ b/src/NServiceBus.Core.Tests/Reliability/Outbox/TransportReceiveToPhysicalMessageConnectorTests.cs @@ -6,6 +6,7 @@ using System.Diagnostics; using System.Linq; using System.Threading.Tasks; +using AcceptanceTests.Core.OpenTelemetry.Metrics; using NServiceBus.Outbox; using NServiceBus.Pipeline; using NServiceBus.Routing; @@ -130,6 +131,20 @@ public async Task Should_add_outbox_span_tag_when_deduplicating() Assert.That(pipelineActivity.TagObjects.ToImmutableDictionary()["nservicebus.outbox.deduplicate-message"], Is.EqualTo(true)); } + [Test] + public async Task Should_report_deduplicated_message_metric_when_deduplicating() + { + using var metricsListener = TestingMetricListener.SetupNServiceBusMetricsListener(); + + string messageId = Guid.NewGuid().ToString(); + fakeOutbox.ExistingMessage = new OutboxMessage(messageId, Array.Empty()); + var context = CreateContext(fakeBatchPipeline, messageId); + + await Invoke(context); + + metricsListener.AssertMetric("nservicebus.outbox.duplicates", 1); + } + [Test] public async Task Should_add_batch_dispatch_events_when_sending_batched_messages() { @@ -182,6 +197,7 @@ static TestableTransportReceiveContext CreateContext(FakeBatchPipeline pipeline, }; context.Extensions.Set(new FakePipelineCache(pipeline)); + context.Extensions.Set(new IncomingPipelineMetricTags()); return context; } @@ -191,16 +207,21 @@ public void SetUp() { fakeOutbox = new FakeOutboxStorage(); fakeBatchPipeline = new FakeBatchPipeline(); + fakeMeterFactory = new TestMeterFactory(); - behavior = new TransportReceiveToPhysicalMessageConnector(fakeOutbox, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc")); + behavior = new TransportReceiveToPhysicalMessageConnector(fakeOutbox, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions()), new InstrumentationOptions()); } + [TearDown] + public void TearDown() => fakeMeterFactory.Dispose(); + Task Invoke(ITransportReceiveContext context, Func next = null) => behavior.Invoke(context, next ?? (_ => Task.CompletedTask)); TransportReceiveToPhysicalMessageConnector behavior; FakeBatchPipeline fakeBatchPipeline; FakeOutboxStorage fakeOutbox; + TestMeterFactory fakeMeterFactory; class MyEvent; diff --git a/src/NServiceBus.Core.Tests/Routing/RoutingToDispatchConnectorTests.cs b/src/NServiceBus.Core.Tests/Routing/RoutingToDispatchConnectorTests.cs index ad4d34e8037..0d8293f2340 100644 --- a/src/NServiceBus.Core.Tests/Routing/RoutingToDispatchConnectorTests.cs +++ b/src/NServiceBus.Core.Tests/Routing/RoutingToDispatchConnectorTests.cs @@ -17,7 +17,7 @@ public class RoutingToDispatchConnectorTests [Test] public async Task Should_preserve_message_state_for_one_routing_strategy_for_allocation_reasons() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); IEnumerable operations = null; var testableRoutingContext = new TestableRoutingContext { @@ -59,7 +59,7 @@ await behavior.Invoke(testableRoutingContext, context => [Test] public async Task Should_copy_message_state_for_multiple_routing_strategies() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); List operations = null; var testableRoutingContext = new TestableRoutingContext { @@ -135,7 +135,7 @@ await behavior.Invoke(testableRoutingContext, context => [Test] public async Task Should_preserve_headers_generated_by_custom_routing_strategy() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); Dictionary headers = null; await behavior.Invoke(new TestableRoutingContext { RoutingStrategies = [new HeaderModifyingRoutingStrategy()] }, context => { @@ -153,7 +153,7 @@ public async Task Should_dispatch_immediately_if_user_requested() options.RequireImmediateDispatch(); var dispatched = false; - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var message = new OutgoingMessage("ID", [], Array.Empty()); await behavior.Invoke(new RoutingContext(message, @@ -170,7 +170,7 @@ await behavior.Invoke(new RoutingContext(message, public async Task Should_dispatch_immediately_if_not_sending_from_a_handler() { var dispatched = false; - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var message = new OutgoingMessage("ID", [], Array.Empty()); await behavior.Invoke(new RoutingContext(message, @@ -187,7 +187,7 @@ await behavior.Invoke(new RoutingContext(message, public async Task Should_not_dispatch_by_default() { var dispatched = false; - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var message = new OutgoingMessage("ID", [], Array.Empty()); await behavior.Invoke(new RoutingContext(message, @@ -203,7 +203,7 @@ await behavior.Invoke(new RoutingContext(message, [Test] public async Task Should_promote_message_headers_to_pipeline_activity() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var routingContext = new TestableRoutingContext(); routingContext.Message.Headers[Headers.ContentType] = "test content type"; // one of the headers that will be mapped to tags @@ -257,7 +257,7 @@ class MyMessage : IMessage; [Test] public async Task Should_merge_receive_properties_when_declared_by_transport() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var receiveProperties = new ReceiveProperties(new Dictionary { @@ -290,7 +290,7 @@ await behavior.Invoke(routingContext, context => [Test] public async Task Should_not_override_user_set_dispatch_property() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var receiveProperties = new ReceiveProperties(new Dictionary { @@ -324,7 +324,7 @@ await behavior.Invoke(routingContext, context => [Test] public async Task Should_preserve_user_dispatch_properties_even_with_receive_properties() { - var behavior = new RoutingToDispatchConnector(); + var behavior = new RoutingToDispatchConnector(NoOpActivityFactory.Instance); var receiveProperties = new ReceiveProperties(new Dictionary { diff --git a/src/NServiceBus.Core.Tests/Unicast/LoadHandlersConnectorTests.cs b/src/NServiceBus.Core.Tests/Unicast/LoadHandlersConnectorTests.cs index 42c5a2cd0d2..67cb7048465 100644 --- a/src/NServiceBus.Core.Tests/Unicast/LoadHandlersConnectorTests.cs +++ b/src/NServiceBus.Core.Tests/Unicast/LoadHandlersConnectorTests.cs @@ -4,6 +4,7 @@ using System.Threading.Tasks; using System.Transactions; using Core.Tests.Fakes; +using Core.Tests.OpenTelemetry; using Microsoft.Extensions.DependencyInjection; using NServiceBus.Transport; using NUnit.Framework; @@ -16,7 +17,7 @@ public class LoadHandlersConnectorTests [Test] public void Should_throw_when_there_are_no_registered_message_handlers() { - var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), new NoOpActivityFactory()); + var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), NoOpActivityFactory.Instance, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); var context = new TestableIncomingLogicalMessageContext(); @@ -29,7 +30,7 @@ public void Should_throw_when_there_are_no_registered_message_handlers() [Test] public void Should_throw_if_ambient_transaction_is_different_from_scope_used_by_transport() { - var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), new NoOpActivityFactory()); + var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), NoOpActivityFactory.Instance, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); var context = new TestableIncomingLogicalMessageContext(); @@ -49,7 +50,7 @@ public void Should_throw_if_ambient_transaction_is_different_from_scope_used_by_ [Test] public void Should_throw_if_ambient_transaction_suppressed_when_transport_uses_a_scope() { - var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), new NoOpActivityFactory()); + var behavior = new LoadHandlersConnector(new MessageHandlerRegistry(), NoOpActivityFactory.Instance, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); var context = new TestableIncomingLogicalMessageContext(); @@ -77,7 +78,7 @@ public void Should_not_throw_if_ambient_scope_is_same_as_transport_scope() context.Services.AddSingleton(); context.Extensions.Set(new NoOpOutboxTransaction()); - var behavior = new LoadHandlersConnector(messageHandlerRegistry, new NoOpActivityFactory()); + var behavior = new LoadHandlersConnector(messageHandlerRegistry, NoOpActivityFactory.Instance, new IncomingPipelineMetrics(new TestMeterFactory(), "queue", "disc", new MetersOptions())); using (new TransactionScope(TransactionScopeAsyncFlowOption.Enabled)) { diff --git a/src/NServiceBus.Core/EndpointCreator.cs b/src/NServiceBus.Core/EndpointCreator.cs index 71c893904df..627887e0ff7 100644 --- a/src/NServiceBus.Core/EndpointCreator.cs +++ b/src/NServiceBus.Core/EndpointCreator.cs @@ -157,7 +157,7 @@ void Configure() pipelineSettings); receiveComponent.AddManifest(hostingConfiguration, settings); - pipelineComponent = PipelineComponent.Initialize(pipelineSettings, hostingConfiguration, receiveConfiguration); + pipelineComponent = PipelineComponent.Initialize(pipelineSettings, hostingConfiguration, receiveConfiguration, hostingConfiguration.ActivityFactory.Options.Meters); // The settings can only be locked after initializing the feature component since it uses the settings to store & share feature state. // As well as all the other components have been initialized diff --git a/src/NServiceBus.Core/Hosting/HostingComponent.Configuration.cs b/src/NServiceBus.Core/Hosting/HostingComponent.Configuration.cs index 4ed38527c71..6326b1a5006 100644 --- a/src/NServiceBus.Core/Hosting/HostingComponent.Configuration.cs +++ b/src/NServiceBus.Core/Hosting/HostingComponent.Configuration.cs @@ -26,7 +26,7 @@ public static Configuration PrepareConfiguration(Settings settings, List a serviceCollection, settings.ShouldRunInstallers, settings.UserRegistrations, - new ActivityFactory(), + new ActivityFactory(settings.InstrumentationOptions), persistenceConfiguration, installerComponent); diff --git a/src/NServiceBus.Core/Hosting/HostingComponent.Settings.cs b/src/NServiceBus.Core/Hosting/HostingComponent.Settings.cs index f46a6101f05..d2b8bdb4027 100644 --- a/src/NServiceBus.Core/Hosting/HostingComponent.Settings.cs +++ b/src/NServiceBus.Core/Hosting/HostingComponent.Settings.cs @@ -95,6 +95,8 @@ public bool WriteDiagnosticsToLog get; set; } + public InstrumentationOptions InstrumentationOptions => settings.GetOrCreate(); + internal void ConfigureHostLogging(object? endpointIdentifier) { EndpointIdentifier = endpointIdentifier; diff --git a/src/NServiceBus.Core/OpenTelemetry/ExceptionRecordingMode.cs b/src/NServiceBus.Core/OpenTelemetry/ExceptionRecordingMode.cs new file mode 100644 index 00000000000..32c9da69655 --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/ExceptionRecordingMode.cs @@ -0,0 +1,20 @@ +#nullable enable + +namespace NServiceBus; + +/// +/// Controls how exception details are recorded when an operation represented by an activity fails. +/// +public enum ExceptionRecordingMode +{ + /// + /// Records the exception details via NServiceBus's logging infrastructure instead of adding an event to the + /// activity. + /// + Logs, + + /// + /// Records the exception details via NServiceBus's logging infrastructure and as an event the activity. + /// + SpanAndLogs +} diff --git a/src/NServiceBus.Core/OpenTelemetry/InstrumentationOptions.cs b/src/NServiceBus.Core/OpenTelemetry/InstrumentationOptions.cs new file mode 100644 index 00000000000..4930b5d2ffe --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/InstrumentationOptions.cs @@ -0,0 +1,95 @@ +#nullable enable + +namespace NServiceBus; + +/// +/// Controls opt-in OpenTelemetry instrumentation behaviors. +/// Accessed via endpointConfiguration.Tracing(). +/// +public partial class InstrumentationOptions +{ + /// + /// Appends the destination to span names following the OTel messaging convention + /// {messaging.operation.name} {destination}, e.g. "process orders" or "send payments". + /// Disabled by default for backward compatibility. + /// + public bool UseMessageDestinationInSpanNames { get; set; } + + /// + /// Controls instrumentation of the recoverability pipeline (retries and error handling). + /// + public RecoverabilityInstrumentationOptions Recoverability { get; } = new(); + + /// + /// Controls meter instruments behaviors. + /// + public MetersOptions Meters { get; } = new(); + + /// + /// Controls instrumentation of explicitly delayed messages (SendOptions.DelayDeliveryWith + /// / DoNotDeliverBefore and saga timeouts. + /// Recoverability-driven delayed retries are controlled separately via + /// . + /// + public DelayedDeliveryInstrumentationOptions DelayedDelivery { get; } = new(); + + /// + /// Controls whether the "Start dispatching" and "Finished dispatching" activity events + /// are added to the incoming message span when outgoing messages are dispatched. + /// Enabled by default for backward compatibility. Disable to avoid the ingestion cost + /// of these events when they add no diagnostic value. + /// + public bool EmitMessageDispatchingEvents { get; set; } = true; + + /// + /// Controls how the receive-side processing span relates to the send span for messages sent by this endpoint. + /// Defaults to : receivers continue the trace. + /// Can be overridden per message via + /// or . + /// + public TraceMode SendTraceMode { get; set; } = TraceMode.ContinueExisting; + + /// + /// Controls how the receive-side processing span relates to the publish span for events published by this endpoint. + /// Defaults to : receivers start a new trace linked back to the publish span. + /// Can be overridden per message via + /// or . + /// + public TraceMode PublishTraceMode { get; set; } = TraceMode.StartNew; + + /// + /// Controls how exception details are recorded when an operation fails. + /// Defaults to : exceptions are recorded as an event on the activity. + /// + public ExceptionRecordingMode ExceptionRecordingMode { get; set; } = ExceptionRecordingMode.SpanAndLogs; +} + +/// +/// Controls instrumentation of the recoverability pipeline (retries and error handling). +/// +public class RecoverabilityInstrumentationOptions +{ + /// + /// Controls how the span for a delayed retry relates to the failed + /// attempt's trace. + /// + public TraceMode DelayedRetryTraceMode { get; set; } = TraceMode.StartNew; +} + +/// +/// Controls instrumentation of delayed messages. +/// +public class DelayedDeliveryInstrumentationOptions +{ + /// + /// Controls how a delayed Send relates to the sender's trace, when requested directly + /// by application code via SendOptions.DelayDeliveryWith/DoNotDeliverBefore. + /// + public TraceMode SendOperationTraceMode { get; set; } = TraceMode.StartNew; + + /// + /// Controls how a saga timeout (Saga.RequestTimeout) relates to the trace of the + /// message that requested it. + /// + public TraceMode SagaTimeoutTraceMode { get; set; } = TraceMode.StartNew; +} diff --git a/src/NServiceBus.Core/OpenTelemetry/MetersOptions.cs b/src/NServiceBus.Core/OpenTelemetry/MetersOptions.cs new file mode 100644 index 00000000000..0838da8aea8 --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/MetersOptions.cs @@ -0,0 +1,17 @@ +#nullable enable + +namespace NServiceBus; + +/// +/// Controls opt-in meter instruments behaviors. +/// Accessed via endpointConfiguration.Tracing().Meters. +/// +public class MetersOptions +{ + /// + /// Emits the legacy execution.result tag with values "success" or "failure" + /// on handler time, processing time, saga fetch time, deserialize time, and serialize time metrics. + /// Enabled by default for backwards compatibility. Disable to reduce tag cardinality. + /// + public bool EmitExecutionResultTags { get; set; } = true; +} diff --git a/src/NServiceBus.Core/OpenTelemetry/Metrics/MeterTags.cs b/src/NServiceBus.Core/OpenTelemetry/Metrics/MeterTags.cs index 9eb8795c87f..f3fc9666fdb 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Metrics/MeterTags.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Metrics/MeterTags.cs @@ -7,9 +7,11 @@ static class MeterTags public const string EndpointDiscriminator = "nservicebus.discriminator"; public const string QueueName = "nservicebus.queue"; public const string MessageType = "nservicebus.message_type"; + public const string EnclosedMessageTypes = "nservicebus.enclosed_message_types"; public const string MessageHandlerTypes = "nservicebus.message_handler_types"; public const string MessageHandlerType = "nservicebus.message_handler_type"; public const string ExecutionResult = "execution.result"; public const string ErrorType = "error.type"; public const string EnvelopeUnwrapperType = "nservicebus.envelope.unwrapper_type"; + public const string SagaType = "nservicebus.saga_type"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryExtensions.cs b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryExtensions.cs index bc263ffe423..6db97f31694 100644 --- a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryExtensions.cs +++ b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryExtensions.cs @@ -2,26 +2,67 @@ namespace NServiceBus; +using System; + /// /// Gives users control over the depth of an OpenTelemetry trace. /// public static class OpenTelemetryExtensions { /// - /// Start a new OpenTelemetry trace conversation. + /// Provides access to instrumentation options for OpenTelemetry tracing. + /// + /// The endpoint configuration. + /// The instance for this endpoint. + public static InstrumentationOptions Tracing(this EndpointConfiguration config) + { + ArgumentNullException.ThrowIfNull(config); + return config.Settings.GetOrCreate(); + } + + /// + /// Start a new OpenTelemetry trace on receive of this message, linked back to the send span. + /// Overrides for this message. /// /// The option being extended. public static void StartNewTraceOnReceive(this SendOptions sendOptions) { - sendOptions.Context.Set(OpenTelemetrySendBehavior.StartNewTraceOnReceive, true); + ArgumentNullException.ThrowIfNull(sendOptions); + sendOptions.Context.Set(TraceConnectorOverrideKey, TraceMode.StartNew); } /// - /// Start a new OpenTelemetry trace conversation. + /// Continue the existing OpenTelemetry trace on receive of this message. + /// Overrides for this message. + /// + /// The option being extended. + public static void ContinueExistingTraceOnReceive(this SendOptions sendOptions) + { + ArgumentNullException.ThrowIfNull(sendOptions); + sendOptions.Context.Set(TraceConnectorOverrideKey, TraceMode.ContinueExisting); + } + + /// + /// Start a new OpenTelemetry trace on receive of this event, linked back to the publish span. + /// Overrides for this message. + /// + /// The option being extended. + public static void StartNewTraceOnReceive(this PublishOptions publishOptions) + { + ArgumentNullException.ThrowIfNull(publishOptions); + publishOptions.Context.Set(TraceConnectorOverrideKey, TraceMode.StartNew); + } + + /// + /// Continue the existing OpenTelemetry trace on receive of this event. + /// Overrides for this message. /// /// The option being extended. public static void ContinueExistingTraceOnReceive(this PublishOptions publishOptions) { - publishOptions.Context.Set(OpenTelemetryPublishBehavior.ContinueTraceOnReceive, true); + ArgumentNullException.ThrowIfNull(publishOptions); + publishOptions.Context.Set(TraceConnectorOverrideKey, TraceMode.ContinueExisting); } + + internal const string TraceConnectorOverrideKey = "NServiceBus.OpenTelemetry.TraceConnectorOverride"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryFeature.cs b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryFeature.cs index c485129eee0..7ae9288c9a7 100644 --- a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryFeature.cs +++ b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryFeature.cs @@ -6,20 +6,24 @@ namespace NServiceBus; sealed class OpenTelemetryFeature : Feature { + public OpenTelemetryFeature() => Defaults(InstrumentationOptions.SetExceptionRecordingModeDefault); + protected override void Setup(FeatureConfigurationContext context) { + var instrumentationOptions = context.Settings.GetOrDefault() ?? new InstrumentationOptions(); + context.Pipeline.Register( - new OpenTelemetryPublishBehavior(), + new OpenTelemetryPublishBehavior(instrumentationOptions), "Manages the depth of the trace for publishes" ); context.Pipeline.Register( - new OpenTelemetrySendBehavior(), + new OpenTelemetrySendBehavior(instrumentationOptions), "Manages the depth of the trace for sends" ); context.Pipeline.Register( - new PopulateRecoverabilityTraceMetadataBehavior(), + new PopulateRecoverabilityTraceMetadataBehavior(instrumentationOptions), "Populates the recoverability metadata" ); } diff --git a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryPublishBehavior.cs b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryPublishBehavior.cs index 55617620d7f..367647a0148 100644 --- a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryPublishBehavior.cs +++ b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetryPublishBehavior.cs @@ -6,22 +6,17 @@ namespace NServiceBus; using System.Threading.Tasks; using Pipeline; -class OpenTelemetryPublishBehavior : IBehavior +class OpenTelemetryPublishBehavior(InstrumentationOptions instrumentationOptions) : IBehavior { public Task Invoke(IOutgoingPublishContext context, Func next) { - // publishes always start a new trace on receive - context.Headers[Headers.StartNewTrace] = bool.TrueString; + // the per-message override wins over the endpoint-level default + var connector = context.Extensions.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode requestedConnector) + ? requestedConnector + : instrumentationOptions.PublishTraceMode; - // unless the user explicitly requests to continue the trace - bool continueTraceWasSet = context.Extensions.TryGet(ContinueTraceOnReceive, out var continueTraceRequested); - if (continueTraceWasSet && continueTraceRequested) - { - context.Headers[Headers.StartNewTrace] = bool.FalseString; - } + context.Headers[Headers.StartNewTrace] = connector == TraceMode.StartNew ? bool.TrueString : bool.FalseString; return next(context); } - - public const string ContinueTraceOnReceive = "ContinueTraceRequested"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetrySendBehavior.cs b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetrySendBehavior.cs index b8ca6de993c..ef86db89c94 100644 --- a/src/NServiceBus.Core/OpenTelemetry/OpenTelemetrySendBehavior.cs +++ b/src/NServiceBus.Core/OpenTelemetry/OpenTelemetrySendBehavior.cs @@ -5,23 +5,45 @@ namespace NServiceBus; using System; using System.Threading.Tasks; using Pipeline; +using Transport; -class OpenTelemetrySendBehavior : IBehavior +class OpenTelemetrySendBehavior(InstrumentationOptions instrumentationOptions) : IBehavior { public Task Invoke(IOutgoingSendContext context, Func next) { - // sends never start a new trace on receive - context.Headers[Headers.StartNewTrace] = bool.FalseString; + // the per-message override wins over the endpoint-level default + var operationTraceMode = context.Extensions.TryGet(OpenTelemetryExtensions.TraceConnectorOverrideKey, out TraceMode requestedConnector) + ? requestedConnector + : instrumentationOptions.SendTraceMode; - // unless the user explicitly requests to start a new trace - bool breakTraceWasSet = context.Extensions.TryGet(StartNewTraceOnReceive, out var breakTraceWasRequested); - if (breakTraceWasSet && breakTraceWasRequested) + if (operationTraceMode == TraceMode.StartNew) { context.Headers[Headers.StartNewTrace] = bool.TrueString; } + else + { + // This is needed to ensure the trace continuation behavior is backwards compatible. + // If the message is delayed, we always start a new trace unless different behavior is explicitly configured. + var isDelayed = context.Extensions.TryGet(out var dispatchProperties) && + (dispatchProperties.DelayDeliveryWith != null || dispatchProperties.DoNotDeliverBefore != null); + + bool startNewTrace; + if (isDelayed) + { + var isSagaTimeout = context.Headers.ContainsKey(Headers.IsSagaTimeoutMessage); + var mode = isSagaTimeout + ? instrumentationOptions.DelayedDelivery.SagaTimeoutTraceMode + : instrumentationOptions.DelayedDelivery.SendOperationTraceMode; + startNewTrace = mode == TraceMode.StartNew; + } + else + { + startNewTrace = false; + } + + context.Headers[Headers.StartNewTrace] = startNewTrace ? bool.TrueString : bool.FalseString; + } return next(context); } - - public const string StartNewTraceOnReceive = "BreakTraceRequested"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/TraceMode.cs b/src/NServiceBus.Core/OpenTelemetry/TraceMode.cs new file mode 100644 index 00000000000..590258b3b71 --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/TraceMode.cs @@ -0,0 +1,19 @@ +#nullable enable + +namespace NServiceBus; + +/// +/// Controls how the receive-side processing span relates to the outgoing send or publish span. +/// +public enum TraceMode +{ + /// + /// The receiving endpoint continues the trace: the processing span becomes a child of the outgoing span. + /// + ContinueExisting, + + /// + /// The receiving endpoint starts a new trace: the processing span becomes the root of a new trace with a link back to the outgoing span. + /// + StartNew +} diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityDisplayNames.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityDisplayNames.cs index ca6d81aff76..50b874bfac3 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityDisplayNames.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityDisplayNames.cs @@ -10,4 +10,14 @@ static class ActivityDisplayNames public const string UnsubscribeEvent = "unsubscribe event"; public const string SendMessage = "send message"; public const string ReplyMessage = "reply"; + public const string Recoverability = "recover"; + + // Operation-only prefixes used when UseMessageDestinationInSpanNames is enabled + internal const string ProcessOperation = "process"; + internal const string PublishOperation = "publish"; + internal const string SendOperation = "send"; + internal const string ImmediateRetryOperation = "immediate retry"; + internal const string DelayedRetryOperation = "delayed retry"; + internal const string MoveToErrorOperation = "move to"; + internal const string DiscardOperation = "discard"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityExtensions.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityExtensions.cs index 04e287679c0..3f784962a9b 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityExtensions.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityExtensions.cs @@ -2,11 +2,8 @@ namespace NServiceBus; -using System; -using System.Collections.Generic; using System.Diagnostics; using System.Diagnostics.CodeAnalysis; -using System.Threading.Tasks; using Extensibility; static class ActivityExtensions @@ -35,23 +32,4 @@ static bool TryGetRecordingPipelineActivity(this ContextBag pipelineContext, str public static void SetOutgoingPipelineActivity(this ContextBag pipelineContext, Activity activity) => pipelineContext.Set(OutgoingActivityKey, activity); public static void SetIncomingPipelineActivity(this ContextBag pipelineContext, Activity activity) => pipelineContext.Set(IncomingActivityKey, activity); - - public static void SetErrorStatus(this Activity activity, Exception ex) - { - activity.SetStatus(ActivityStatusCode.Error, ex.Message); - activity.SetTag("otel.status_code", "ERROR"); - activity.SetTag("otel.status_description", ex.Message); - activity.AddEvent(new ActivityEvent("exception", DateTimeOffset.UtcNow, - [ - new KeyValuePair("exception.escaped", true), - new KeyValuePair("exception.type", ex.GetType()), - new KeyValuePair("exception.message", ex.Message), - new KeyValuePair("exception.stacktrace", ex.ToString()) - ])); - - if (ex is TaskCanceledException) - { - activity.SetTag(ActivityTags.CancelledTask, true); - } - } } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityFactory.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityFactory.cs index 6c0202a51d7..c8a958733fd 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityFactory.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityFactory.cs @@ -2,26 +2,33 @@ namespace NServiceBus; +using System; +using System.Collections.Generic; using System.Diagnostics; +using System.Threading.Tasks; +using Extensibility; +using Logging; using Pipeline; using Transport; -sealed class ActivityFactory : IActivityFactory +sealed class ActivityFactory(InstrumentationOptions options) : IActivityFactory { - public Activity? StartIncomingPipelineActivity(MessageContext context) + public InstrumentationOptions Options { get; } = options; + + static Activity? CreateActivityFromIncomingMessage(ActivitySource activitySource, string activityName, Dictionary headers, string nativeMessageId, ContextBag extensions) { // CreateActivity is a no-op if there are no listeners but we are doing a fast path check // here nonetheless to avoid having to parse headers, access the extension bag, etc. - if (!ActivitySources.Main.HasListeners()) + if (!activitySource.HasListeners()) { return null; } Activity? activity; - var incomingTraceParentExists = context.Headers.TryGetValue(Headers.DiagnosticsTraceParent, out var sendSpanId); + var incomingTraceParentExists = headers.TryGetValue(Headers.DiagnosticsTraceParent, out var sendSpanId); var activityContextCreatedFromIncomingTraceParent = ActivityContext.TryParse(sendSpanId, null, out var sendSpanContext); - if (context.Extensions.TryGet(out var transportActivity)) // attach to transport span but link receive pipeline span to send pipeline span + if (extensions.TryGet(out var transportActivity)) // attach to transport span but link receive pipeline span to send pipeline span { ActivityLink[]? links = null; if (incomingTraceParentExists && sendSpanId != transportActivity.Id) @@ -32,31 +39,31 @@ sealed class ActivityFactory : IActivityFactory } } - activity = ActivitySources.Main.CreateActivity(name: ActivityNames.IncomingMessageActivityName, + activity = activitySource.CreateActivity(name: activityName, ActivityKind.Consumer, transportActivity.Context, links: links, idFormat: ActivityIdFormat.W3C); } else if (incomingTraceParentExists && activityContextCreatedFromIncomingTraceParent) // otherwise directly create child from logical send { - var isStartNewTraceHeaderAvailable = context.Headers.TryGetValue(Headers.StartNewTrace, out var shouldStartNewTrace); + var isStartNewTraceHeaderAvailable = headers.TryGetValue(Headers.StartNewTrace, out var shouldStartNewTrace); if (isStartNewTraceHeaderAvailable && shouldStartNewTrace?.Equals(bool.TrueString) is true) { // create a new trace or root activity - ActivityLink[] links = [new ActivityLink(sendSpanContext)]; + ActivityLink[] links = [new(sendSpanContext)]; //null the current activity so that the new one is created as root https://github.com/dotnet/runtime/issues/65528#issuecomment-2613486896 Activity.Current = null; - activity = ActivitySources.Main.StartActivity(name: ActivityNames.IncomingMessageActivityName, ActivityKind.Consumer, parentContext: default, tags: null, links: links); + activity = activitySource.StartActivity(name: activityName, ActivityKind.Consumer, parentContext: default, tags: null, links: links); } else { // no new trace was requested, so start a child trace ActivityContext.TryParse(sendSpanId, null, true, out var remoteParentActivityContext); - activity = ActivitySources.Main.CreateActivity(name: ActivityNames.IncomingMessageActivityName, ActivityKind.Consumer, remoteParentActivityContext); + activity = activitySource.CreateActivity(name: activityName, ActivityKind.Consumer, remoteParentActivityContext); } } - else // otherwise start new trace + else // otherwise start a new trace { // This will set Activity.Current as parent if available - activity = ActivitySources.Main.CreateActivity(name: ActivityNames.IncomingMessageActivityName, ActivityKind.Consumer); + activity = activitySource.CreateActivity(name: activityName, ActivityKind.Consumer); } if (activity is null) @@ -64,13 +71,33 @@ sealed class ActivityFactory : IActivityFactory return activity; } - ContextPropagation.PropagateContextFromHeaders(activity, context.Headers); + ContextPropagation.PropagateContextFromHeaders(activity, headers); - activity.DisplayName = ActivityDisplayNames.ProcessMessage; activity.SetIdFormat(ActivityIdFormat.W3C); - activity.AddTag(ActivityTags.NativeMessageId, context.NativeMessageId); + activity.AddTag(ActivityTags.NativeMessageId, nativeMessageId); + + ActivityDecorator.PromoteHeadersToTags(activity, headers); + + return activity; + } + + public Activity? StartIncomingPipelineActivity(MessageContext context) + { + var activity = CreateActivityFromIncomingMessage( + ActivitySources.Main, + ActivityNames.IncomingMessageActivityName, + context.Headers, + context.NativeMessageId, + context.Extensions); + + if (activity is null) + { + return activity; + } - ActivityDecorator.PromoteHeadersToTags(activity, context.Headers); + activity.DisplayName = Options.UseMessageDestinationInSpanNames + ? $"{ActivityDisplayNames.ProcessOperation} {context.ReceiveAddress}" + : ActivityDisplayNames.ProcessMessage; activity.Start(); @@ -102,7 +129,13 @@ sealed class ActivityFactory : IActivityFactory return null; } - var activity = ActivitySources.Main.StartActivity(ActivityNames.InvokeHandlerActivityName); + // Until v11 the dedicated handler source is opt-in; existing configurations only + // subscribe to the main source and must keep receiving handler spans from it. + var source = HandlerActivitySourceSwitch.UseHandlerActivitySource + ? ActivitySources.Handler + : ActivitySources.Main; + + var activity = source.StartActivity(ActivityNames.InvokeHandlerActivityName); if (activity is null) { @@ -113,4 +146,93 @@ sealed class ActivityFactory : IActivityFactory activity.AddTag(ActivityTags.HandlerType, messageHandler.HandlerType.FullName); return activity; } + + public Activity? StartRecoverabilityActivity(ErrorContext context) + { + var activity = CreateActivityFromIncomingMessage( + ActivitySources.Recoverability, + ActivityNames.RecoverabilityActivityName, + context.Headers, + context.NativeMessageId, + context.Extensions); + + if (activity is null) + { + return activity; + } + + activity.DisplayName = ActivityDisplayNames.Recoverability; + + activity.Start(); + + return activity; + } + + public void UpdateActivityFromRecoverabilityAction(Activity activity, RecoverabilityAction recoverabilityAction, string receiveAddress) + { + if (recoverabilityAction is ImmediateRetry) + { + activity.AddTag(ActivityTags.RecoverabilityAction, "immediate_retry"); + activity.DisplayName = ActivityDisplayNames.ImmediateRetryOperation; + + if (Options.UseMessageDestinationInSpanNames) + { + activity.DisplayName += $" {receiveAddress}"; + } + } + else if (recoverabilityAction is DelayedRetry) + { + activity.AddTag(ActivityTags.RecoverabilityAction, "delayed_retry"); + activity.DisplayName = ActivityDisplayNames.DelayedRetryOperation; + + if (Options.UseMessageDestinationInSpanNames) + { + activity.DisplayName += $" {receiveAddress}"; + } + } + else if (recoverabilityAction is MoveToError moveToError) + { + activity.AddTag(ActivityTags.RecoverabilityAction, "move_to_error"); + + activity.DisplayName = Options.UseMessageDestinationInSpanNames + ? $"{ActivityDisplayNames.MoveToErrorOperation} {moveToError.ErrorQueue}" + : $"{ActivityDisplayNames.MoveToErrorOperation} error"; + } + else if (recoverabilityAction is Discard) + { + activity.AddTag(ActivityTags.RecoverabilityAction, "discard"); + activity.DisplayName = ActivityDisplayNames.DiscardOperation; + } + } + + public void RecordError(Activity activity, Exception exception, ContextBag context) + { + activity.SetStatus(ActivityStatusCode.Error, exception.Message); + activity.SetTag(ActivityTags.ErrorType, exception.GetType().FullName); + + LegacyExceptionTags.SetLegacyStatusTags(activity, exception); + + if (!exception.Data.Contains(ExceptionRecordedFlag)) + { + if (Options.ExceptionRecordingMode == ExceptionRecordingMode.Logs) + { + Logger.Error($"An exception occurred while executing '{activity.DisplayName}'.", exception); + } + else + { + activity.AddException(exception, LegacyExceptionTags.EscapedTagList); + } + + exception.Data[ExceptionRecordedFlag] = true; + } + + if (exception is TaskCanceledException) + { + activity.SetTag(ActivityTags.CancelledTask, true); + } + } + + const string ExceptionRecordedFlag = "otel.exception.recorded"; + + static readonly ILog Logger = LogManager.GetLogger(); } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityNames.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityNames.cs index 0399bb931bd..5472c817385 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityNames.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityNames.cs @@ -10,4 +10,5 @@ static class ActivityNames public const string SubscribeActivityName = "NServiceBus.Diagnostics.Subscribe"; public const string UnsubscribeActivityName = "NServiceBus.Diagnostics.Unsubscribe"; public const string InvokeHandlerActivityName = "NServiceBus.Diagnostics.InvokeHandler"; + public const string RecoverabilityActivityName = "NServiceBus.Diagnostics.Recoverability"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivitySources.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivitySources.cs index 8f6e26858e1..b3d86aeaf63 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivitySources.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivitySources.cs @@ -9,4 +9,12 @@ static class ActivitySources public static readonly ActivitySource Main = new("NServiceBus.Core", "0.1.0"); + + public static readonly ActivitySource Handler = + new("NServiceBus.Core.Handler", + "0.1.0"); + + public static readonly ActivitySource Recoverability = + new("NServiceBus.Core.Recoverability", + "0.1.0"); } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityTags.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityTags.cs index c7597a63f2e..ff03de38003 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityTags.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ActivityTags.cs @@ -41,4 +41,6 @@ static class ActivityTags public const string HandlerSagaId = "nservicebus.handler.saga_id"; public const string EventTypes = "nservicebus.event_types"; public const string CancelledTask = "nservicebus.cancelled"; + public const string ErrorType = "error.type"; + public const string RecoverabilityAction = "nservicebus.recoverability_action"; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/ContextPropagation.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/ContextPropagation.cs index 0f1d8868270..dc0e568dd87 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/ContextPropagation.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/ContextPropagation.cs @@ -2,86 +2,74 @@ namespace NServiceBus; -using System; using System.Collections.Generic; using System.Diagnostics; -using System.Linq; -using Extensibility; static class ContextPropagation { - public static void PropagateContextToHeaders(Activity? activity, Dictionary headers, ContextBag contextBag) + public static void PropagateContextToHeaders(Activity? activity, Dictionary headers) { - if (activity is null) + // TODO: investigate if we need to improve the switch check for better performance + // Removed in v11, see obsolete_v11.cs + if (!LegacyContextPropagation.UseDistributedContextPropagator) { + LegacyContextPropagation.PropagateContextToHeaders(activity, headers); return; } - if (activity.Id is not null) - { - headers[Headers.DiagnosticsTraceParent] = activity.Id; - } - - if (activity.TraceStateString is not null) - { - headers[Headers.DiagnosticsTraceState] = activity.TraceStateString; - } - - // Check whether the startnewtrace setting was set in the context, if so, add it to the headers now the trace parent was added - if (contextBag.TryGet(Headers.StartNewTrace, out var headerContent)) + // The following part was intentionally not extracted to a separate class to prevent + // accidental leftovers when because that the legacy propagator will be removed in v11 + if (activity is null) { - headers[Headers.StartNewTrace] = headerContent; + return; } - var baggage = string.Join(",", activity.Baggage.Select(item => $"{item.Key}={Uri.EscapeDataString(item.Value ?? string.Empty)}")); - if (!string.IsNullOrEmpty(baggage)) - { - headers[Headers.DiagnosticsBaggage] = baggage; - } + DistributedContextPropagator.Current.Inject(activity, headers, Setter); } public static void PropagateContextFromHeaders(Activity? activity, IDictionary headers) { - if (activity is null) + // Removed in v11, see obsolete_v11.cs + if (!LegacyContextPropagation.UseDistributedContextPropagator) { + LegacyContextPropagation.PropagateContextFromHeaders(activity, headers); return; } - if (headers.TryGetValue(Headers.DiagnosticsTraceState, out var traceState)) + // The following part was intentionally not extracted to a separate class to prevent + // accidental leftovers when because that the legacy propagator will be removed in v11 + if (activity is null) { - activity.TraceStateString = traceState; + return; } - if (headers.TryGetValue(Headers.DiagnosticsBaggage, out var baggageValue)) + DistributedContextPropagator.Current.ExtractTraceIdAndState(headers, Getter, out _, out var traceState); + + if (traceState is not null) { - var baggageSpan = baggageValue.AsSpan(); - // HINT: Iterate in reverse order because Activity baggage is LIFO - while (!baggageSpan.IsEmpty) - { - var lastComma = baggageSpan.LastIndexOf(','); - ReadOnlySpan baggageItem; + activity.TraceStateString = traceState; + } - if (lastComma >= 0) - { - baggageItem = baggageSpan[(lastComma + 1)..]; - baggageSpan = baggageSpan[..lastComma]; - } - else - { - baggageItem = baggageSpan; - baggageSpan = []; - } + var baggage = DistributedContextPropagator.Current.ExtractBaggage(headers, Getter); - var firstEquals = baggageItem.IndexOf('='); - if (firstEquals < 0 || firstEquals >= baggageItem.Length) - { - continue; - } + if (baggage is null) + { + return; + } - var key = baggageItem[..firstEquals].Trim(); - var value = baggageItem[(firstEquals + 1)..]; - activity.AddBaggage(key.ToString(), Uri.UnescapeDataString(value)); - } + foreach (var baggageItem in baggage) + { + activity.AddBaggage(baggageItem.Key, baggageItem.Value); } } + + static readonly DistributedContextPropagator.PropagatorSetterCallback Setter = static (carrier, key, value) => + ((IDictionary)carrier!)[key] = value; + + static readonly DistributedContextPropagator.PropagatorGetterCallback Getter = + static (carrier, key, out value, out values) => + { + values = null; + value = ((IReadOnlyDictionary)carrier!).GetValueOrDefault(key); + }; } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/IActivityFactory.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/IActivityFactory.cs index 8a47acb7fdd..bccdf87faf6 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/IActivityFactory.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/IActivityFactory.cs @@ -2,13 +2,19 @@ namespace NServiceBus; +using System; using System.Diagnostics; +using Extensibility; using Pipeline; using Transport; interface IActivityFactory { + InstrumentationOptions Options { get; } Activity? StartIncomingPipelineActivity(MessageContext context); Activity? StartOutgoingPipelineActivity(string activityName, string displayName, IBehaviorContext outgoingContext); Activity? StartHandlerActivity(MessageHandler messageHandler); + Activity? StartRecoverabilityActivity(ErrorContext context); + void UpdateActivityFromRecoverabilityAction(Activity activity, RecoverabilityAction recoverabilityAction, string receiveAddress); + void RecordError(Activity activity, Exception exception, ContextBag context); } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/NoOpActivityFactory.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/NoOpActivityFactory.cs index a36d268a3bd..6e2e183c637 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/NoOpActivityFactory.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/NoOpActivityFactory.cs @@ -2,15 +2,29 @@ namespace NServiceBus; +using System; using System.Diagnostics; +using Extensibility; using Pipeline; using Transport; sealed class NoOpActivityFactory : IActivityFactory { + NoOpActivityFactory() { } + public static readonly NoOpActivityFactory Instance = new(); + public InstrumentationOptions Options { get; } = new(); + public Activity? StartIncomingPipelineActivity(MessageContext context) => null; public Activity? StartOutgoingPipelineActivity(string activityName, string displayName, IBehaviorContext outgoingContext) => null; public Activity? StartHandlerActivity(MessageHandler messageHandler) => null; + public Activity? StartRecoverabilityActivity(ErrorContext context) => null; + public void UpdateActivityFromRecoverabilityAction(Activity activity, RecoverabilityAction recoverabilityAction, string receiveAddress) + { + } + + public void RecordError(Activity activity, Exception exception, ContextBag context) + { + } } \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/PopulateRecoverabilityTraceMetadataBehavior.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/PopulateRecoverabilityTraceMetadataBehavior.cs index 0bb256ecef2..0a1a5c50881 100644 --- a/src/NServiceBus.Core/OpenTelemetry/Tracing/PopulateRecoverabilityTraceMetadataBehavior.cs +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/PopulateRecoverabilityTraceMetadataBehavior.cs @@ -4,7 +4,7 @@ namespace NServiceBus; using System.Threading.Tasks; using Pipeline; -class PopulateRecoverabilityTraceMetadataBehavior : IBehavior +class PopulateRecoverabilityTraceMetadataBehavior(InstrumentationOptions instrumentationOptions) : IBehavior { public Task Invoke(IRecoverabilityContext context, Func next) { @@ -13,9 +13,19 @@ public Task Invoke(IRecoverabilityContext context, Func(this IPipeline pipeline, TContext context, Activity? activity) where TContext : IBehaviorContext + public static Task Invoke(this IPipeline pipeline, TContext context, Activity? activity, IActivityFactory activityFactory) where TContext : IBehaviorContext { - return activity is null ? pipeline.Invoke(context) : TracePipelineStatus(pipeline, context, activity); + return activity is null ? pipeline.Invoke(context) : TracePipelineStatus(pipeline, context, activity, activityFactory); - static async Task TracePipelineStatus(IPipeline pipeline, TContext context, Activity activity) + static async Task TracePipelineStatus(IPipeline pipeline, TContext context, Activity activity, IActivityFactory activityFactory) { #pragma warning disable PS0019 // When catching System.Exception, cancellation needs to be properly accounted for try @@ -23,7 +23,7 @@ static async Task TracePipelineStatus(IPipeline pipeline, TContext con } catch (Exception ex) { - activity.SetErrorStatus(ex); + activityFactory.RecordError(activity, ex, context.Extensions); throw; } #pragma warning restore PS0019 // When catching System.Exception, cancellation needs to be properly accounted for diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v11.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v11.cs new file mode 100644 index 00000000000..0e8dd5f4d4f --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v11.cs @@ -0,0 +1,211 @@ +#nullable enable + +namespace NServiceBus; + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using Particular.Obsoletes; + +// ============================================================================= +// EVERYTHING IN THIS FILE IS TEMPORARY AND WILL BE REMOVED IN v11. +// +// In v10.3, switching to System.Diagnostics.DistributedContextPropagator for +// OpenTelemetry trace-context/baggage propagation changes the baggage wire +// format (W3C OWS encoding + whitespace trimming) and is therefore breaking on +// rolling upgrades. To stay backwards compatible it is opt-in via an AppContext +// switch and the legacy propagator below remains the default. +// +// In v11 the new propagator becomes the default: delete this entire file and +// remove the two `if (!ObsoleteV11.UseDistributedContextPropagator)` delegation +// blocks in ContextPropagation.cs. +// ============================================================================= +static class LegacyContextPropagation +{ + enum SwitchState : byte + { + Unchecked = 0, + Enabled = 1, + Disabled = 2 + } + + static SwitchState cachedUseDistributedContextPropagator; + + [PreObsolete("https://github.com/Particular/NServiceBus/issues/7825", + Note = "In v11, DistributedContextPropagator-based context propagation becomes the default and this switch will be removed together with the legacy propagator in obsolete_v11.cs.", + ReplacementTypeOrMember = "ContextPropagation")] + public const string UseDistributedContextPropagatorSwitchName = "NServiceBus.Core.OpenTelemetry.UseDistributedContextPropagator"; + + [PreObsolete("https://github.com/Particular/NServiceBus/issues/7825", + Note = "In v11, DistributedContextPropagator-based context propagation becomes the default and this switch will be removed together with the legacy propagator in obsolete_v11.cs.", + ReplacementTypeOrMember = "ContextPropagation")] + public static bool UseDistributedContextPropagator + { + get + { + var state = cachedUseDistributedContextPropagator; + if (state != SwitchState.Unchecked) + { + return state == SwitchState.Enabled; + } + + state = AppContext.TryGetSwitch(UseDistributedContextPropagatorSwitchName, out var isEnabled) && isEnabled + ? SwitchState.Enabled + : SwitchState.Disabled; + cachedUseDistributedContextPropagator = state; + + return state == SwitchState.Enabled; + } + } + + internal static void ResetUseDistributedContextPropagator() => cachedUseDistributedContextPropagator = SwitchState.Unchecked; + + public static void PropagateContextToHeaders(Activity? activity, Dictionary headers) + { + if (activity is null) + { + return; + } + + if (activity.Id is not null) + { + headers[Headers.DiagnosticsTraceParent] = activity.Id; + } + + if (activity.TraceStateString is not null) + { + headers[Headers.DiagnosticsTraceState] = activity.TraceStateString; + } + + var baggage = string.Join(",", activity.Baggage.Select(item => $"{item.Key}={Uri.EscapeDataString(item.Value ?? string.Empty)}")); + if (!string.IsNullOrEmpty(baggage)) + { + headers[Headers.DiagnosticsBaggage] = baggage; + } + } + + public static void PropagateContextFromHeaders(Activity? activity, IDictionary headers) + { + if (activity is null) + { + return; + } + + if (headers.TryGetValue(Headers.DiagnosticsTraceState, out var traceState)) + { + activity.TraceStateString = traceState; + } + + if (headers.TryGetValue(Headers.DiagnosticsBaggage, out var baggageValue)) + { + var baggageSpan = baggageValue.AsSpan(); + // HINT: Iterate in reverse order because Activity baggage is LIFO + while (!baggageSpan.IsEmpty) + { + var lastComma = baggageSpan.LastIndexOf(','); + ReadOnlySpan baggageItem; + + if (lastComma >= 0) + { + baggageItem = baggageSpan[(lastComma + 1)..]; + baggageSpan = baggageSpan[..lastComma]; + } + else + { + baggageItem = baggageSpan; + baggageSpan = []; + } + + var firstEquals = baggageItem.IndexOf('='); + if (firstEquals < 0 || firstEquals >= baggageItem.Length) + { + continue; + } + + var key = baggageItem[..firstEquals].Trim(); + var value = baggageItem[(firstEquals + 1)..]; + activity.AddBaggage(key.ToString(), Uri.UnescapeDataString(value)); + } + } + } +} + +// Handler spans move from the "NServiceBus.Core" ActivitySource to the dedicated +// "NServiceBus.Core.Handler" source so they can be filtered/sampled independently +// (https://github.com/Particular/NServiceBus/issues/7284). Existing OpenTelemetry +// configurations only subscribe to "NServiceBus.Core" and would silently lose handler +// spans, so the new source is opt-in via an AppContext switch until v11. +// +// In v11 the dedicated source becomes the default: delete this class and remove the +// source selection in ActivityFactory.StartHandlerActivity so it always uses +// ActivitySources.Handler. +static class HandlerActivitySourceSwitch +{ + enum SwitchState : byte + { + Unchecked = 0, + Enabled = 1, + Disabled = 2 + } + + static SwitchState cachedUseHandlerActivitySource; + + [PreObsolete("https://github.com/Particular/NServiceBus/issues/7284", + Note = "In v11, handler spans are always emitted from the NServiceBus.Core.Handler ActivitySource and this switch will be removed.", + ReplacementTypeOrMember = "ActivitySources.Handler")] + public const string UseHandlerActivitySourceSwitchName = "NServiceBus.Core.OpenTelemetry.UseHandlerActivitySource"; + + [PreObsolete("https://github.com/Particular/NServiceBus/issues/7284", + Note = "In v11, handler spans are always emitted from the NServiceBus.Core.Handler ActivitySource and this switch will be removed.", + ReplacementTypeOrMember = "ActivitySources.Handler")] + public static bool UseHandlerActivitySource + { + get + { + var state = cachedUseHandlerActivitySource; + if (state != SwitchState.Unchecked) + { + return state == SwitchState.Enabled; + } + + state = AppContext.TryGetSwitch(UseHandlerActivitySourceSwitchName, out var isEnabled) && isEnabled + ? SwitchState.Enabled + : SwitchState.Disabled; + cachedUseHandlerActivitySource = state; + + return state == SwitchState.Enabled; + } + } + + internal static void ResetUseHandlerActivitySource() => cachedUseHandlerActivitySource = SwitchState.Unchecked; +} + + +// This class bridges two independent legacy exception-tagging behaviors, both +// scheduled for removal in v11: +// +// - SetLegacyStatusTags sets the "otel.status_code"/"otel.status_description" +// tags, which predate native support for Activity.SetStatus/Activity.Status +// and are now redundant with it. Kept only for consumers still reading the +// tags directly instead of Activity.Status. +// - EscapedTagList carries "exception.escaped", an attribute the OTel semantic +// conventions have marked Deprecated: +// https://opentelemetry.io/docs/specs/semconv/exceptions/exceptions-logs/ +// It's added to the exception event for backward compatibility with +// existing consumers of that attribute. +// +// In v11, delete this entire class, remove the +// `LegacyExceptionTags.SetLegacyStatusTags(activity, exception);` call in +// ActivityFactory.RecordError, and stop passing EscapedTagList to +// activity.AddException in the same method. +static class LegacyExceptionTags +{ + public static void SetLegacyStatusTags(Activity activity, Exception exception) + { + activity.SetTag("otel.status_code", "ERROR"); + activity.SetTag("otel.status_description", exception.Message); + } + + public static TagList EscapedTagList { get; } = new() { { "exception.escaped", true } }; +} \ No newline at end of file diff --git a/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v12.cs b/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v12.cs new file mode 100644 index 00000000000..13e193f8957 --- /dev/null +++ b/src/NServiceBus.Core/OpenTelemetry/Tracing/obsolete_v12.cs @@ -0,0 +1,39 @@ +#nullable enable + +namespace NServiceBus; + +using Settings; + +// This scaffolds a temporary, environment-variable-driven override for +// ExceptionRecordingMode so users can opt in ahead of time to the "logs" +// model described by the OTEL_SEMCONV_EXCEPTION_SIGNAL_OPT_IN convention: +// https://opentelemetry.io/docs/specs/semconv/exceptions/exceptions-logs/ +// The environment variable is the highest-priority signal for this setting: +// when it's set to a recognized value it always wins, even over an +// explicitly configured ExceptionRecordingMode, so operators can force the +// exception-signal behavior without a code change/redeploy. +// +// In v12, once the exceptions-as-logs migration has settled, delete this +// entire file (SetExceptionRecordingModeDefault and +// ExceptionSignalOptInEnvironmentVariableKey), and remove the +// `Defaults(InstrumentationOptions.SetExceptionRecordingModeDefault);` call in +// OpenTelemetryFeature's constructor. +public partial class InstrumentationOptions +{ + internal static void SetExceptionRecordingModeDefault(SettingsHolder settings) + { + var options = settings.GetOrCreate(); + + var environment = settings.Get(); + var variableValue = environment.GetEnvironmentVariable(ExceptionSignalOptInEnvironmentVariableKey); + + options.ExceptionRecordingMode = variableValue switch + { + "logs" => ExceptionRecordingMode.Logs, + "logs/dup" => ExceptionRecordingMode.SpanAndLogs, + _ => options.ExceptionRecordingMode + }; + } + + internal static readonly string ExceptionSignalOptInEnvironmentVariableKey = "OTEL_SEMCONV_EXCEPTION_SIGNAL_OPT_IN"; +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs b/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs index dc01b394b78..1afa8f9986c 100644 --- a/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs +++ b/src/NServiceBus.Core/Pipeline/Incoming/DeserializeMessageConnector.cs @@ -1,10 +1,11 @@ -#nullable enable +#nullable enable namespace NServiceBus; using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Diagnostics; using System.Threading.Tasks; using Logging; using MessageInterfaces; @@ -17,21 +18,36 @@ class DeserializeMessageConnector( LogicalMessageFactory logicalMessageFactory, MessageMetadataRegistry messageMetadataRegistry, IMessageMapper mapper, - bool allowContentTypeInference) + bool allowContentTypeInference, + IncomingPipelineMetrics incomingPipelineMetrics) : StageConnector { public override async Task Invoke(IIncomingPhysicalMessageContext context, Func stage) { var incomingMessage = context.Message; - var messages = ExtractWithExceptionHandling(incomingMessage); + LogicalMessage[] messages; + var deserializeStart = Stopwatch.GetTimestamp(); + try + { + messages = ExtractWithExceptionHandling(incomingMessage); + } +#pragma warning disable PS0019 + catch (Exception ex) +#pragma warning restore PS0019 + { + incomingPipelineMetrics.RecordDeserializeTime(context, Stopwatch.GetElapsedTime(deserializeStart), error: ex); + throw; + } + + incomingPipelineMetrics.RecordDeserializeTime(context, Stopwatch.GetElapsedTime(deserializeStart)); bool first = true; foreach (var message in messages) { if (first) // ignore the legacy case in which a single message payload contained multiple messages { - var availableMetricTags = context.Extensions.Get(); + var availableMetricTags = context.IncomingMetricTags; availableMetricTags.Add(MeterTags.MessageType, message.MessageType.FullName!); first = false; } @@ -137,4 +153,4 @@ LogicalMessage[] Extract(IncomingMessage physicalMessage) static readonly ILog log = LogManager.GetLogger(); static ReadOnlySpan ImplSuffix => "__impl".AsSpan(); static ReadOnlySpan EnclosedMessageTypeSeparator => ";".AsSpan(); -} \ No newline at end of file +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/IMetricsTags.cs b/src/NServiceBus.Core/Pipeline/Incoming/IMetricsTags.cs new file mode 100644 index 00000000000..d5b90d6446a --- /dev/null +++ b/src/NServiceBus.Core/Pipeline/Incoming/IMetricsTags.cs @@ -0,0 +1,23 @@ +#nullable enable + +namespace NServiceBus; + +/// +/// The tags applied to the metrics reported for the message currently being processed. +/// +public interface IMetricsTags +{ + /// + /// Adds the specified tag and value to , overwriting any value previously added + /// for that instrument and tag key, and taking precedence over the value NServiceBus reports for that tag. + /// + /// + /// Tags are scoped to a single instrument because a tag value is frequently only valid for one measurement (for + /// example, which handler just ran) rather than a fact that holds for every metric reported for the message. For + /// the same reason a later call for the same instrument and tag key replaces an earlier one. + /// + /// The tag to add. + /// The value assigned to the tag. + /// The name of the instrument the tag applies to. + void AddOrOverride(string tagKey, object value, string instrumentName); +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetricTags.cs b/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetricTags.cs index 534d735e08b..f1f0f4d7a47 100644 --- a/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetricTags.cs +++ b/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetricTags.cs @@ -9,9 +9,26 @@ namespace NServiceBus; /// /// Captures possible metric tags that can be applied to a metric throughout the incoming processing pipeline. /// -public sealed class IncomingPipelineMetricTags +sealed class IncomingPipelineMetricTags : IMetricsTags { - Dictionary>? tags; + readonly Dictionary> tags = []; + readonly Dictionary>> instrumentTags = []; + + /// + /// + /// Unlike , this overwrites rather than keeping the first value, and the tag + /// isn't visible to other instruments applying tags from this collection. + /// + public void AddOrOverride(string tagKey, object value, string instrumentName) + { + if (!instrumentTags.TryGetValue(instrumentName, out var perInstrumentTags)) + { + perInstrumentTags = []; + instrumentTags.Add(instrumentName, perInstrumentTags); + } + + perInstrumentTags[tagKey] = new(tagKey, value); + } /// /// Adds the specified tag and value to the collection if not already present. @@ -19,48 +36,55 @@ public sealed class IncomingPipelineMetricTags /// The tag to add. /// The value assigned to the tag. public void Add(string tagKey, object value) - { - tags ??= []; - // We are using tryAdd to mitigate multiple logical messages transmitted in a single physical message - tags.TryAdd(tagKey, new(tagKey, value)); - } + => tags.TryAdd(tagKey, new KeyValuePair(tagKey, value)); /// - /// Applies the specified tag to the . + /// Applies the specified tags to the , replacing any tag already in + /// with a matching key - so a caller can populate with its + /// own computed defaults before calling this, and have any matching tag from this collection take precedence. + /// General tags (from ) are only applied when their key is in + /// . When is provided, every tag added for that + /// instrument via is applied unconditionally - regardless of whether its + /// key is in - and takes precedence over a general tag with the same key: naming an + /// instrument when adding a tag is already an explicit statement of intent for that one instrument, so callers + /// don't also need to know about it to pull it in. /// - /// The tagList to apply the specified tag to. - /// The tag to add to the . - public void ApplyTag(ref TagList tagList, string tagKey) + /// The tagList to add the tags to. + /// The collection of tag keys to apply to the . + /// The instrument to apply instrument-specific tags for, if any. + public void ApplyTags(ref TagList tagList, ReadOnlySpan tagKeys, string? instrumentName = null) { - if (tags == null) + foreach (var tagKey in tagKeys) { - return; + if (tags.TryGetValue(tagKey, out var keyValuePair)) + { + SetOrAdd(ref tagList, keyValuePair); + } } - if (tags.TryGetValue(tagKey, out var keyValuePair)) + if (instrumentName != null && instrumentTags.TryGetValue(instrumentName, out var perInstrumentTags)) { - tagList.Add(keyValuePair); + foreach (var (_, keyValuePair) in perInstrumentTags) + { + SetOrAdd(ref tagList, keyValuePair); + } } } - /// - /// Applies the specified tags to the . - /// - /// The tagList to add the tags to. - /// The collection of tag keys to apply to the . - public void ApplyTags(ref TagList tagList, ReadOnlySpan tagKeys) + // A caller may have already added a computed default for this key directly to tagList before calling + // ApplyTag/ApplyTags. Replacing it in place - rather than appending a duplicate - is what lets a tag from this + // collection act as an override regardless of how a consumer of the recorded measurement handles duplicate keys. + static void SetOrAdd(ref TagList tagList, KeyValuePair tag) { - if (tags == null || tagKeys.IsEmpty) + for (var i = 0; i < tagList.Count; i++) { - return; - } - - foreach (var tagKey in tagKeys) - { - if (tags.TryGetValue(tagKey, out var keyValuePair)) + if (tagList[i].Key == tag.Key) { - tagList.Add(keyValuePair); + tagList[i] = tag; + return; } } + + tagList.Add(tag); } -} \ No newline at end of file +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetrics.cs b/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetrics.cs index b842e912a3c..45ee4da5c5e 100644 --- a/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetrics.cs +++ b/src/NServiceBus.Core/Pipeline/Incoming/IncomingPipelineMetrics.cs @@ -1,4 +1,4 @@ -#nullable enable +#nullable enable namespace NServiceBus; @@ -21,16 +21,27 @@ class IncomingPipelineMetrics const string RecoverabilityDelayed = "nservicebus.recoverability.delayed"; const string RecoverabilityError = "nservicebus.recoverability.error"; const string EnvelopeUnwrapping = "nservicebus.envelope.unwrapped"; - - public IncomingPipelineMetrics(IMeterFactory meterFactory, string queueName, string discriminator) + const string ActiveMessages = "nservicebus.messaging.active_messages"; + const string TotalDeduplicated = "nservicebus.outbox.duplicates"; + const string SagaFetchTime = "nservicebus.sagas.fetch_time"; + const string MessageDeserializeTime = "nservicebus.messaging.deserialize_time"; + const string MessageSerializeTime = "nservicebus.messaging.serialize_time"; + const string OutboxFetchTime = "nservicebus.outbox.fetch_time"; + const string OutboxStoreTime = "nservicebus.outbox.store_time"; + const string CommitTime = "nservicebus.persistence.commit_time"; + + public IncomingPipelineMetrics(IMeterFactory meterFactory, string queueName, string discriminator, MetersOptions metersOptions) { - var meter = meterFactory.Create("NServiceBus.Core.Pipeline.Incoming", "0.2.0"); + emitExecutionResultTags = metersOptions.EmitExecutionResultTags; + var meter = meterFactory.Create("NServiceBus.Core.Pipeline.Incoming", "0.4.0"); totalProcessedSuccessfully = meter.CreateCounter(TotalProcessedSuccessfully, description: "Total number of messages processed successfully by the endpoint."); totalFetched = meter.CreateCounter(TotalFetched, description: "Total number of messages fetched from the queue by the endpoint."); totalFailures = meter.CreateCounter(TotalFailures, description: "Total number of messages processed unsuccessfully by the endpoint."); + totalDeduplicated = meter.CreateCounter(TotalDeduplicated, + description: "Total number of duplicate messages detected by the Outbox."); messageHandlerTime = meter.CreateHistogram(MessageHandlerTime, "s", "The time in seconds for the execution of the business code."); criticalTime = meter.CreateHistogram(CriticalTime, "s", @@ -45,15 +56,29 @@ public IncomingPipelineMetrics(IMeterFactory meterFactory, string queueName, str description: "Total number of messages sent to the error queue."); totalEnvelopeUnwrapping = meter.CreateCounter(EnvelopeUnwrapping, description: "Total number of unwrapping attempts by the endpoint."); + activeMessages = meter.CreateUpDownCounter(ActiveMessages, + description: "Number of messages currently being processed by the endpoint."); + sagaFetchTime = meter.CreateHistogram(SagaFetchTime, "s", + "The time in seconds for loading saga data from the persister."); + messageDeserializeTime = meter.CreateHistogram(MessageDeserializeTime, "s", + "The time in seconds for deserializing an incoming message."); + messageSerializeTime = meter.CreateHistogram(MessageSerializeTime, "s", + "The time in seconds for serializing an outgoing message."); + outboxFetchTime = meter.CreateHistogram(OutboxFetchTime, "s", + "The time in seconds for querying the outbox storage for deduplication."); + outboxStoreTime = meter.CreateHistogram(OutboxStoreTime, "s", + "The time in seconds for storing a message in the outbox storage."); + persistenceTime = meter.CreateHistogram(CommitTime, "s", + "The time in seconds for completing the synchronized storage session."); queueNameBase = queueName; endpointDiscriminator = discriminator; } - public void AddDefaultIncomingPipelineMetricTags(IncomingPipelineMetricTags incomingPipelineMetricsTags) + public void AddDefaultIncomingPipelineMetricTags(IncomingPipelineMetricTags incomingPipelineMetricTags) { - incomingPipelineMetricsTags.Add(MeterTags.QueueName, queueNameBase); - incomingPipelineMetricsTags.Add(MeterTags.EndpointDiscriminator, endpointDiscriminator ?? ""); + incomingPipelineMetricTags.Add(MeterTags.QueueName, queueNameBase); + incomingPipelineMetricTags.Add(MeterTags.EndpointDiscriminator, endpointDiscriminator); } public void RecordProcessingTime(ITransportReceiveContext context, TimeSpan elapsed) @@ -63,15 +88,19 @@ public void RecordProcessingTime(ITransportReceiveContext context, TimeSpan elap return; } - var incomingPipelineMetricTags = context.Extensions.Get(); - TagList tags; - tags.Add(new(MeterTags.ExecutionResult, "success")); - incomingPipelineMetricTags.ApplyTags(ref tags, [ + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, "success")); + } + + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerTypes]); + MeterTags.MessageHandlerTypes], + processingTime.Name); processingTime.Record(elapsed.TotalSeconds, tags); } @@ -82,28 +111,34 @@ public void RecordCriticalTimeAndTotalProcessed(ITransportReceiveContext context { return; } - - var incomingPipelineMetricTags = context.Extensions.Get(); - TagList tags; - tags.Add(new(MeterTags.ExecutionResult, "success")); - incomingPipelineMetricTags.ApplyTags(ref tags, [ + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, "success")); + } + + // totalProcessedSuccessfully and criticalTime always share the same tags in this method, so overrides are + // looked up under criticalTime's instrument name. + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerTypes]); + MeterTags.MessageHandlerTypes], + criticalTime.Name); if (totalProcessedSuccessfully.Enabled) { totalProcessedSuccessfully.Add(1, tags); } - var completedAt = DateTimeOffset.UtcNow; if (criticalTime.Enabled) { if (context.Message.Headers.TryGetDeliverAt(out var startTime) || context.Message.Headers.TryGetTimeSent(out startTime)) { + var completedAt = DateTimeOffset.UtcNow; var criticalTimeElapsed = completedAt - startTime; + criticalTime.Record(criticalTimeElapsed.TotalSeconds, tags); } } @@ -117,13 +152,21 @@ public void RecordMessageProcessingFailure(IncomingPipelineMetricTags incomingPi } TagList tags; - tags.Add(new(MeterTags.ErrorType, error.GetType().FullName)); - tags.Add(new(MeterTags.ExecutionResult, "failure")); + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, "failure")); + } + + tags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); + incomingPipelineMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerTypes]); + MeterTags.MessageHandlerTypes, + MeterTags.ErrorType], + totalFailures.Name); totalFailures.Add(1, tags); // the processing and critical time are intentionally not recorded in case of failure @@ -140,107 +183,303 @@ public void RecordFetchedMessage(IncomingPipelineMetricTags incomingPipelineMetr incomingPipelineMetricTags.ApplyTags(ref tags, [ MeterTags.EndpointDiscriminator, MeterTags.QueueName, - MeterTags.MessageType]); + MeterTags.MessageType], + totalFetched.Name); totalFetched.Add(1, tags); } - public void RecordSuccessfulMessageHandlerTime(IInvokeHandlerContext invokeHandlerContext, TimeSpan elapsed) + public void RecordDeduplicatedMessage(ITransportReceiveContext context) + { + if (!totalDeduplicated.Enabled) + { + return; + } + + TagList tags; + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.EndpointDiscriminator, + MeterTags.QueueName, + MeterTags.MessageType], + totalDeduplicated.Name); + + totalDeduplicated.Add(1, tags); + } + + public void RecordSuccessfulMessageHandlerTime(IInvokeHandlerContext context, TimeSpan elapsed) { if (!messageHandlerTime.Enabled) { return; } - var incomingPipelineMetricTags = invokeHandlerContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ + TagList tags; + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, "success")); + } + + tags.Add(new KeyValuePair(MeterTags.MessageHandlerType, context.MessageHandler.HandlerType.FullName)); + + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerType]); - // This is what Add(string, object) does so skipping an unnecessary stack frame - meterTags.Add(new KeyValuePair(MeterTags.MessageHandlerType, invokeHandlerContext.MessageHandler.HandlerType.FullName)); - meterTags.Add(new KeyValuePair(MeterTags.ExecutionResult, "success")); - messageHandlerTime.Record(elapsed.TotalSeconds, meterTags); + MeterTags.MessageHandlerType], + messageHandlerTime.Name); + messageHandlerTime.Record(elapsed.TotalSeconds, tags); } - public void RecordFailedMessageHandlerTime(IInvokeHandlerContext invokeHandlerContext, TimeSpan elapsed, Exception error) + public void RecordFailedMessageHandlerTime(IInvokeHandlerContext context, TimeSpan elapsed, Exception error) { if (!messageHandlerTime.Enabled) { return; } - var incomingPipelineMetricTags = invokeHandlerContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ + TagList tags; + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, "failure")); + } + + tags.Add(new KeyValuePair(MeterTags.MessageHandlerType, context.MessageHandler.HandlerType.FullName)); + tags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); + + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerType]); - // This is what Add(string, object) does so skipping an unnecessary stack frame - meterTags.Add(new KeyValuePair(MeterTags.MessageHandlerType, invokeHandlerContext.MessageHandler.HandlerType.FullName)); - meterTags.Add(new KeyValuePair(MeterTags.ExecutionResult, "failure")); - meterTags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); - messageHandlerTime.Record(elapsed.TotalSeconds, meterTags); + MeterTags.MessageHandlerType, + MeterTags.ErrorType], + messageHandlerTime.Name); + messageHandlerTime.Record(elapsed.TotalSeconds, tags); } - public void RecordImmediateRetry(IRecoverabilityContext recoverabilityContext) + public void RecordImmediateRetry(IRecoverabilityContext context) { if (!totalImmediateRetries.Enabled) { return; } - var incomingPipelineMetricTags = recoverabilityContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ + TagList tags; + tags.Add(new KeyValuePair(MeterTags.ErrorType, context.Exception.GetType().FullName)); + + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerType]); - // This is what Add(string, object) does so skipping an unnecessary stack frame - meterTags.Add(new KeyValuePair(MeterTags.ErrorType, recoverabilityContext.Exception.GetType().FullName)); - totalImmediateRetries.Add(1, meterTags); + MeterTags.MessageHandlerType, + MeterTags.ErrorType], + totalImmediateRetries.Name); + totalImmediateRetries.Add(1, tags); } - public void RecordDelayedRetry(IRecoverabilityContext recoverabilityContext) + public void RecordDelayedRetry(IRecoverabilityContext context) { if (!totalDelayedRetries.Enabled) { return; } - var incomingPipelineMetricTags = recoverabilityContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ + TagList tags; + tags.Add(new KeyValuePair(MeterTags.ErrorType, context.Exception.GetType().FullName)); + + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerType]); - // This is what Add(string, object) does so skipping an unnecessary stack frame - meterTags.Add(new KeyValuePair(MeterTags.ErrorType, recoverabilityContext.Exception.GetType().FullName)); - totalDelayedRetries.Add(1, meterTags); + MeterTags.MessageHandlerType, + MeterTags.ErrorType], + totalDelayedRetries.Name); + totalDelayedRetries.Add(1, tags); } - public void RecordSendToErrorQueue(IRecoverabilityContext recoverabilityContext) + public void RecordSendToErrorQueue(IRecoverabilityContext context) { if (!totalSentToErrorQueue.Enabled) { return; } - var incomingPipelineMetricTags = recoverabilityContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ + TagList tags; + tags.Add(new KeyValuePair(MeterTags.ErrorType, context.Exception.GetType().FullName)); + + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator, + MeterTags.MessageType, + MeterTags.MessageHandlerType, + MeterTags.ErrorType], + totalSentToErrorQueue.Name); + totalSentToErrorQueue.Add(1, tags); + } + + public ActiveMessageScope TrackMessageProcessing(IncomingPipelineMetricTags incomingPipelineMetricTags, IncomingMessage message) + { + if (!activeMessages.Enabled) + { + return default; + } + + TagList tags; + if (message.Headers.TryGetValue(Headers.EnclosedMessageTypes, out var enclosedMessageTypes)) + { + tags.Add(new KeyValuePair(MeterTags.EnclosedMessageTypes, enclosedMessageTypes)); + } + incomingPipelineMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator, + MeterTags.EnclosedMessageTypes], + activeMessages.Name); + + activeMessages.Add(1, tags); + return new ActiveMessageScope(activeMessages, tags); + } + + public void RecordSagaFetchTime(IInvokeHandlerContext context, TimeSpan elapsed, string sagaType, Exception? error = null) + { + if (!sagaFetchTime.Enabled) + { + return; + } + + TagList tags; + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, error != null ? "failure" : "success")); + } + tags.Add(new KeyValuePair(MeterTags.SagaType, sagaType)); + if (error != null) + { + tags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); + } + + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator, + MeterTags.MessageType, + MeterTags.SagaType, + MeterTags.ErrorType], + sagaFetchTime.Name); + sagaFetchTime.Record(elapsed.TotalSeconds, tags); + } + + public void RecordDeserializeTime(IIncomingPhysicalMessageContext context, TimeSpan elapsed, Exception? error = null) + { + if (!messageDeserializeTime.Enabled) + { + return; + } + + TagList tags; + if (context.Message.Headers.TryGetValue(Headers.EnclosedMessageTypes, out var messageTypes)) + { + tags.Add(new KeyValuePair(MeterTags.EnclosedMessageTypes, messageTypes)); + } + if (error != null) + { + tags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); + } + if (emitExecutionResultTags) + { + // Execution result is to be removed so we don't support overriding it by the user + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, error != null ? "failure" : "success")); + } + + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator, + MeterTags.EnclosedMessageTypes, + MeterTags.ErrorType], + messageDeserializeTime.Name); + + messageDeserializeTime.Record(elapsed.TotalSeconds, tags); + } + + public void RecordSerializeTime(IOutgoingLogicalMessageContext context, TimeSpan elapsed, string? messageType, Exception? error = null) + { + // No incoming pipeline context is available here (this fires from the outgoing send pipeline, which may + // run with no incoming message at all), so there's no IncomingPipelineMetricTags to route these through. + if (!messageSerializeTime.Enabled) + { + return; + } + + TagList tags; + if (messageType != null) + { + tags.Add(new KeyValuePair(MeterTags.MessageType, messageType)); // tag-bag-bypass: see comment above + } + if (error != null) + { + tags.Add(new KeyValuePair(MeterTags.ErrorType, error.GetType().FullName)); // tag-bag-bypass: see comment above + } + if (emitExecutionResultTags) + { + tags.Add(new KeyValuePair(MeterTags.ExecutionResult, error != null ? "failure" : "success")); // tag-bag-bypass: see comment above + } + + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.MessageType, + MeterTags.ErrorType], + messageSerializeTime.Name); + + messageSerializeTime.Record(elapsed.TotalSeconds, tags); + } + + public void RecordOutboxFetchTime(ITransportReceiveContext context, TimeSpan elapsed) + { + if (!outboxFetchTime.Enabled) + { + return; + } + + TagList tags; + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator], + outboxFetchTime.Name); + + outboxFetchTime.Record(elapsed.TotalSeconds, tags); + } + + public void RecordOutboxStoreTime(ITransportReceiveContext context, TimeSpan elapsed) + { + if (!outboxStoreTime.Enabled) + { + return; + } + + TagList tags; + context.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator], + outboxStoreTime.Name); + + outboxStoreTime.Record(elapsed.TotalSeconds, tags); + } + + public void RecordPersistenceTime(IIncomingLogicalMessageContext context, TimeSpan elapsed) + { + if (!persistenceTime.Enabled) + { + return; + } + + TagList tags; + context.IncomingMetricTags.ApplyTags(ref tags, [ MeterTags.QueueName, MeterTags.EndpointDiscriminator, MeterTags.MessageType, - MeterTags.MessageHandlerType]); - // This is what Add(string, object) does so skipping an unnecessary stack frame - meterTags.Add(new KeyValuePair(MeterTags.ErrorType, recoverabilityContext.Exception.GetType().FullName)); - totalSentToErrorQueue.Add(1, meterTags); + MeterTags.MessageHandlerTypes], + persistenceTime.Name); + + persistenceTime.Record(elapsed.TotalSeconds, tags); } public void EnvelopeUnwrappingSucceeded(MessageContext messageContext, IEnvelopeHandler type) => RecordEnvelopeUnwrapping(messageContext, type, true, null); @@ -251,24 +490,32 @@ void RecordEnvelopeUnwrapping(MessageContext messageContext, IEnvelopeHandler ty { return; } - - var incomingPipelineMetricTags = messageContext.Extensions.Get(); - TagList meterTags; - incomingPipelineMetricTags.ApplyTags(ref meterTags, [ - MeterTags.QueueName, - MeterTags.EndpointDiscriminator]); - meterTags.Add(new KeyValuePair(MeterTags.EnvelopeUnwrapperType, type.GetType().FullName)); + TagList tags; + tags.Add(new KeyValuePair(MeterTags.EnvelopeUnwrapperType, type.GetType().FullName)); if (exception != null) { - meterTags.Add(new KeyValuePair(MeterTags.ErrorType, exception.GetType().FullName)); + tags.Add(new KeyValuePair(MeterTags.ErrorType, exception.GetType().FullName)); } - totalEnvelopeUnwrapping.Add(succeeded ? 0 : 1, meterTags); + messageContext.IncomingMetricTags.ApplyTags(ref tags, [ + MeterTags.QueueName, + MeterTags.EndpointDiscriminator, + MeterTags.EnvelopeUnwrapperType, + MeterTags.ErrorType], + totalEnvelopeUnwrapping.Name); + + totalEnvelopeUnwrapping.Add(succeeded ? 0 : 1, tags); + } + + public readonly struct ActiveMessageScope(UpDownCounter? counter, TagList tags) : IDisposable + { + public void Dispose() => counter?.Add(-1, tags); } readonly Counter totalProcessedSuccessfully; readonly Counter totalFetched; readonly Counter totalFailures; + readonly Counter totalDeduplicated; readonly Histogram messageHandlerTime; readonly Histogram criticalTime; readonly Histogram processingTime; @@ -276,6 +523,15 @@ void RecordEnvelopeUnwrapping(MessageContext messageContext, IEnvelopeHandler ty readonly Counter totalDelayedRetries; readonly Counter totalSentToErrorQueue; readonly Counter totalEnvelopeUnwrapping; - string queueNameBase; - string endpointDiscriminator; -} \ No newline at end of file + readonly UpDownCounter activeMessages; + readonly Histogram sagaFetchTime; + readonly Histogram messageDeserializeTime; + readonly Histogram messageSerializeTime; + readonly Histogram outboxFetchTime; + readonly Histogram outboxStoreTime; + readonly Histogram persistenceTime; + + readonly string queueNameBase; + readonly string endpointDiscriminator; + readonly bool emitExecutionResultTags; +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/LoadHandlersConnector.cs b/src/NServiceBus.Core/Pipeline/Incoming/LoadHandlersConnector.cs index 1fce445695a..bb140dcb96c 100644 --- a/src/NServiceBus.Core/Pipeline/Incoming/LoadHandlersConnector.cs +++ b/src/NServiceBus.Core/Pipeline/Incoming/LoadHandlersConnector.cs @@ -16,7 +16,7 @@ namespace NServiceBus; using Pipeline; using Unicast; -class LoadHandlersConnector(MessageHandlerRegistry messageHandlerRegistry, IActivityFactory activityFactory) : StageConnector +class LoadHandlersConnector(MessageHandlerRegistry messageHandlerRegistry, IActivityFactory activityFactory, IncomingPipelineMetrics incomingPipelineMetrics) : StageConnector { public override async Task Invoke(IIncomingLogicalMessageContext context, Func stage) { @@ -43,7 +43,7 @@ public override async Task Invoke(IIncomingLogicalMessageContext context, Func(); + var availableMetricTags = context.IncomingMetricTags; availableMetricTags.Add(MeterTags.MessageHandlerTypes, string.Join(';', handlersToInvoke.Select(x => x.HandlerType.FullName))); foreach (var messageHandler in handlersToInvoke) @@ -64,7 +64,10 @@ public override async Task Invoke(IIncomingLogicalMessageContext context, Func +/// Provides access to the metric tags captured for the message currently being processed. +/// +public static class MetricTagsExtensions +{ + /// The context to extend. + extension(IBehaviorContext context) + { + /// + /// The collected for the message currently being processed. Add to this + /// collection to have the tags applied to the metrics emitted for that message. + /// + public IMetricsTags MetricTags => context.Extensions.GetOrCreate(); + + internal IncomingPipelineMetricTags IncomingMetricTags => context.Extensions.GetOrCreate(); + } + + extension(MessageContext context) + { + internal IncomingPipelineMetricTags IncomingMetricTags => context.Extensions.GetOrCreate(); + } +} diff --git a/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs b/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs index 0504c24f16e..e50a23835d1 100644 --- a/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs +++ b/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs @@ -15,7 +15,8 @@ namespace NServiceBus; class TransportReceiveToPhysicalMessageConnector( IOutboxStorage outboxStorage, - IncomingPipelineMetrics incomingPipelineMetrics) + IncomingPipelineMetrics incomingPipelineMetrics, + InstrumentationOptions instrumentationOptions) : IStageForkConnector { public async Task Invoke(ITransportReceiveContext context, Func next) @@ -24,7 +25,9 @@ public async Task Invoke(ITransportReceiveContext context, Func(); await outboxTransaction.Commit(context.CancellationToken).ConfigureAwait(false); @@ -58,6 +63,7 @@ public async Task Invoke(ITransportReceiveContext context, Func(); + var incomingPipelineMetricsTags = messageContext.IncomingMetricTags; incomingPipelineMetrics.AddDefaultIncomingPipelineMetricTags(incomingPipelineMetricsTags); @@ -35,6 +35,9 @@ public async Task Invoke(MessageContext messageContext, CancellationToken cancel using var incomingMessageHandle = envelopeUnwrapper.UnwrapEnvelope(messageContext); IncomingMessage message = incomingMessageHandle; + //This needs to happen after envelope unwrapping to ensure the proper value of the EnclosedMessageTypes header + using var activeMessageScope = incomingPipelineMetrics.TrackMessageProcessing(incomingPipelineMetricsTags, message); + var transportReceiveContext = new TransportReceiveContext( childScope.ServiceProvider, messageOperations, @@ -51,7 +54,7 @@ public async Task Invoke(MessageContext messageContext, CancellationToken cancel try { - await receivePipeline.Invoke(transportReceiveContext, activity).ConfigureAwait(false); + await receivePipeline.Invoke(transportReceiveContext, activity, activityFactory).ConfigureAwait(false); } #pragma warning disable PS0019 // Do not catch Exception without considering OperationCanceledException - enriching and rethrowing catch (Exception ex) diff --git a/src/NServiceBus.Core/Pipeline/Outgoing/AttachSenderRelatedInfoOnMessageBehavior.cs b/src/NServiceBus.Core/Pipeline/Outgoing/AttachSenderRelatedInfoOnMessageBehavior.cs index 3472a9355f5..7ba822fbc6e 100644 --- a/src/NServiceBus.Core/Pipeline/Outgoing/AttachSenderRelatedInfoOnMessageBehavior.cs +++ b/src/NServiceBus.Core/Pipeline/Outgoing/AttachSenderRelatedInfoOnMessageBehavior.cs @@ -35,12 +35,10 @@ public Task Invoke(IRoutingContext context, Func next) { var timeDelay = dispatchProperties.DelayDeliveryWith.Delay; message.Headers[Headers.DeliverAt] = DateTimeOffsetHelper.ToWireFormattedString(utcNow.Add(timeDelay)); - context.Extensions.Set(Headers.StartNewTrace, bool.TrueString); } else if (dispatchProperties.DoNotDeliverBefore != null) { message.Headers[Headers.DeliverAt] = DateTimeOffsetHelper.ToWireFormattedString(dispatchProperties.DoNotDeliverBefore.At); - context.Extensions.Set(Headers.StartNewTrace, bool.TrueString); } } } diff --git a/src/NServiceBus.Core/Pipeline/Outgoing/RoutingToDispatchConnector.cs b/src/NServiceBus.Core/Pipeline/Outgoing/RoutingToDispatchConnector.cs index bc4be17db8b..3243dd7b150 100644 --- a/src/NServiceBus.Core/Pipeline/Outgoing/RoutingToDispatchConnector.cs +++ b/src/NServiceBus.Core/Pipeline/Outgoing/RoutingToDispatchConnector.cs @@ -14,6 +14,13 @@ namespace NServiceBus; class RoutingToDispatchConnector : StageConnector { + readonly IActivityFactory activityFactory; + + public RoutingToDispatchConnector(IActivityFactory activityFactory) + { + this.activityFactory = activityFactory; + } + public override Task Invoke(IRoutingContext context, Func stage) { var dispatchConsistency = DispatchConsistency.Default; @@ -26,7 +33,7 @@ public override Task Invoke(IRoutingContext context, Func 0 + && operations[0].AddressTag is UnicastAddressTag unicastTag + && outgoingMessage.Headers.TryGetValue(Headers.MessageIntent, out var intentStr) + && intentStr is "Send" or "Reply") + { + activity.DisplayName = $"{activity.DisplayName} {unicastTag.Destination}"; + } } if (dispatchConsistency == DispatchConsistency.Default && context.Extensions.TryGet(out var pendingOperations)) diff --git a/src/NServiceBus.Core/Pipeline/Outgoing/SendComponent.cs b/src/NServiceBus.Core/Pipeline/Outgoing/SendComponent.cs index c00d0880656..5899d352981 100644 --- a/src/NServiceBus.Core/Pipeline/Outgoing/SendComponent.cs +++ b/src/NServiceBus.Core/Pipeline/Outgoing/SendComponent.cs @@ -27,7 +27,7 @@ public static SendComponent Initialize(PipelineSettings pipelineSettings, Hostin pipelineSettings.Register(new OutgoingPhysicalToRoutingConnector(), "Starts the message dispatch pipeline"); - pipelineSettings.Register(new RoutingToDispatchConnector(), + pipelineSettings.Register(new RoutingToDispatchConnector(hostingConfiguration.ActivityFactory), "Decides if the current message should be batched or immediately be dispatched to the transport"); pipelineSettings.Register(new BatchToDispatchConnector(), "Passes batched messages over to the immediate dispatch part of the pipeline"); pipelineSettings.Register(b => new ImmediateDispatchTerminator(b.GetRequiredService()), "Hands the outgoing messages over to the transport for immediate delivery"); diff --git a/src/NServiceBus.Core/Pipeline/Outgoing/SerializeMessageConnector.cs b/src/NServiceBus.Core/Pipeline/Outgoing/SerializeMessageConnector.cs index 38e3cc223cc..f8fe0d459e8 100644 --- a/src/NServiceBus.Core/Pipeline/Outgoing/SerializeMessageConnector.cs +++ b/src/NServiceBus.Core/Pipeline/Outgoing/SerializeMessageConnector.cs @@ -3,6 +3,7 @@ namespace NServiceBus; using System; +using System.Diagnostics; using System.IO; using System.Threading.Tasks; using Logging; @@ -12,10 +13,11 @@ namespace NServiceBus; class SerializeMessageConnector : StageConnector { - public SerializeMessageConnector(IMessageSerializer messageSerializer, MessageMetadataRegistry messageMetadataRegistry) + public SerializeMessageConnector(IMessageSerializer messageSerializer, MessageMetadataRegistry messageMetadataRegistry, IncomingPipelineMetrics incomingPipelineMetrics) { this.messageSerializer = messageSerializer; this.messageMetadataRegistry = messageMetadataRegistry; + this.incomingPipelineMetrics = incomingPipelineMetrics; } public override async Task Invoke(IOutgoingLogicalMessageContext context, Func stage) @@ -39,7 +41,19 @@ public override async Task Invoke(IOutgoingLogicalMessageContext context, Func(); -} \ No newline at end of file +} diff --git a/src/NServiceBus.Core/Pipeline/PipelineComponent.cs b/src/NServiceBus.Core/Pipeline/PipelineComponent.cs index fba1beea0e1..03326dc412b 100644 --- a/src/NServiceBus.Core/Pipeline/PipelineComponent.cs +++ b/src/NServiceBus.Core/Pipeline/PipelineComponent.cs @@ -12,14 +12,15 @@ sealed class PipelineComponent PipelineComponent(PipelineModifications modifications) => this.modifications = modifications; public static PipelineComponent Initialize(PipelineSettings settings, - HostingComponent.Configuration hostingConfiguration, ReceiveComponent.Configuration receiveConfiguration) + HostingComponent.Configuration hostingConfiguration, ReceiveComponent.Configuration receiveConfiguration, + MetersOptions metersOptions) { // make the PipelineMetrics available to the Pipeline hostingConfiguration.Services.AddSingleton(sp => { var meterFactory = sp.GetRequiredService(); string discriminator = receiveConfiguration.InstanceSpecificQueueAddress?.Discriminator ?? ""; - return new IncomingPipelineMetrics(meterFactory, receiveConfiguration.LocalQueueAddress.BaseAddress, discriminator); + return new IncomingPipelineMetrics(meterFactory, receiveConfiguration.LocalQueueAddress.BaseAddress, discriminator, metersOptions); }); return new PipelineComponent(settings.modifications); diff --git a/src/NServiceBus.Core/Receiving/ReceiveComponent.cs b/src/NServiceBus.Core/Receiving/ReceiveComponent.cs index f9b6236be20..5d859914cef 100644 --- a/src/NServiceBus.Core/Receiving/ReceiveComponent.cs +++ b/src/NServiceBus.Core/Receiving/ReceiveComponent.cs @@ -67,10 +67,10 @@ public static ReceiveComponent Configure( pipelineSettings.Register("TransportReceiveToPhysicalMessageProcessingConnector", b => { var storage = b.GetService() ?? new NoOpOutboxStorage(); - return new TransportReceiveToPhysicalMessageConnector(storage, b.GetRequiredService()); + return new TransportReceiveToPhysicalMessageConnector(storage, b.GetRequiredService(), hostingConfiguration.ActivityFactory.Options); }, "Allows to abort processing the message"); - pipelineSettings.Register("LoadHandlersConnector", b => new LoadHandlersConnector(b.GetRequiredService(), hostingConfiguration.ActivityFactory), "Gets all the handlers to invoke from the MessageHandler registry based on the message type."); + pipelineSettings.Register("LoadHandlersConnector", b => new LoadHandlersConnector(b.GetRequiredService(), hostingConfiguration.ActivityFactory, b.GetRequiredService()), "Gets all the handlers to invoke from the MessageHandler registry based on the message type."); pipelineSettings.Register("InvokeHandlers", sp => new InvokeHandlerTerminator(sp.GetRequiredService()), "Calls the IHandleMessages.Handle(T)"); @@ -180,7 +180,9 @@ public async Task Initialize( builder, pipelineCache, pipelineComponent, - messageOperations); + messageOperations, + activityFactory + ); await mainPump.Initialize( configuration.PushRuntimeSettings, diff --git a/src/NServiceBus.Core/Recoverability/DelayedRetry.cs b/src/NServiceBus.Core/Recoverability/DelayedRetry.cs index e6ac5cea2e1..b59e59e4a15 100644 --- a/src/NServiceBus.Core/Recoverability/DelayedRetry.cs +++ b/src/NServiceBus.Core/Recoverability/DelayedRetry.cs @@ -5,7 +5,6 @@ namespace NServiceBus; using System; using System.Collections.Generic; using DelayedDelivery; -using Logging; using Pipeline; using Recoverability; using Routing; @@ -36,8 +35,6 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover { var exception = context.Exception; - Logger.Warn($"Delayed Retry will reschedule message '{context.MessageId}' after a delay of {Delay} because of an exception:", exception); - var outgoingMessage = new OutgoingMessage(context.MessageId, new Dictionary(context.Headers), context.Body); var currentDelayedRetriesAttempt = context.DelayedDeliveriesPerformed + 1; @@ -73,6 +70,4 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover }); return [routingContext]; } - - static readonly ILog Logger = LogManager.GetLogger(); } \ No newline at end of file diff --git a/src/NServiceBus.Core/Recoverability/Discard.cs b/src/NServiceBus.Core/Recoverability/Discard.cs index 7ecc8e0b6ea..86862add7dc 100644 --- a/src/NServiceBus.Core/Recoverability/Discard.cs +++ b/src/NServiceBus.Core/Recoverability/Discard.cs @@ -3,7 +3,6 @@ namespace NServiceBus; using System.Collections.Generic; -using Logging; using Pipeline; using Transport; @@ -28,11 +27,5 @@ public class Discard : RecoverabilityAction public override ErrorHandleResult ErrorHandleResult => ErrorHandleResult.Handled; /// - public override IReadOnlyCollection GetRoutingContexts(IRecoverabilityActionContext context) - { - Logger.Info($"Discarding message with id '{context.MessageId}'. Reason: {Reason}", context.Exception); - return []; - } - - static readonly ILog Logger = LogManager.GetLogger(); + public override IReadOnlyCollection GetRoutingContexts(IRecoverabilityActionContext context) => []; } \ No newline at end of file diff --git a/src/NServiceBus.Core/Recoverability/ImmediateRetry.cs b/src/NServiceBus.Core/Recoverability/ImmediateRetry.cs index 2b43ca652eb..71b7fb9cdc9 100644 --- a/src/NServiceBus.Core/Recoverability/ImmediateRetry.cs +++ b/src/NServiceBus.Core/Recoverability/ImmediateRetry.cs @@ -4,8 +4,7 @@ namespace NServiceBus; using System; using System.Collections.Generic; -using NServiceBus.Logging; -using NServiceBus.Transport; +using Transport; using Pipeline; /// @@ -30,7 +29,6 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover { var exception = context.Exception; - Logger.Info($"Immediate Retry is going to retry message '{context.MessageId}' because of an exception:", exception); if (context is IRecoverabilityActionContextNotifications notifications) { notifications.Add(new MessageToBeRetried( @@ -46,6 +44,4 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover } return []; } - - static readonly ILog Logger = LogManager.GetLogger(); } \ No newline at end of file diff --git a/src/NServiceBus.Core/Recoverability/MoveToError.cs b/src/NServiceBus.Core/Recoverability/MoveToError.cs index 8c805833676..cbb148a7a46 100644 --- a/src/NServiceBus.Core/Recoverability/MoveToError.cs +++ b/src/NServiceBus.Core/Recoverability/MoveToError.cs @@ -3,7 +3,6 @@ namespace NServiceBus; using System.Collections.Generic; -using Logging; using Pipeline; using Recoverability; using Routing; @@ -35,8 +34,6 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover var metadata = context.Metadata; var exception = context.Exception; - Logger.Error($"Moving message '{context.MessageId}' to the error queue '{ErrorQueue}' because processing failed due to an exception:", exception); - if (context is IRecoverabilityActionContextNotifications notifications) { notifications.Add(new MessageFaulted(ErrorQueue, context.NativeMessageId, context.MessageId, context.Headers, context.Body, context.ReceiveProperties, exception)); @@ -56,6 +53,4 @@ public override IReadOnlyCollection GetRoutingContexts(IRecover context.CreateRoutingContext(outgoingMessage, new UnicastRoutingStrategy(ErrorQueue)) ]; } - - static readonly ILog Logger = LogManager.GetLogger(); } \ No newline at end of file diff --git a/src/NServiceBus.Core/Recoverability/RecoverabilityAction.cs b/src/NServiceBus.Core/Recoverability/RecoverabilityAction.cs index 9d6992336f3..cbdb330cde1 100644 --- a/src/NServiceBus.Core/Recoverability/RecoverabilityAction.cs +++ b/src/NServiceBus.Core/Recoverability/RecoverabilityAction.cs @@ -74,5 +74,5 @@ public static Discard Discard(string reason) /// public abstract ErrorHandleResult ErrorHandleResult { get; } - static readonly ImmediateRetry CachedImmediateRetry = new ImmediateRetry(); + static readonly ImmediateRetry CachedImmediateRetry = new(); } \ No newline at end of file diff --git a/src/NServiceBus.Core/Recoverability/RecoverabilityActionLogger.cs b/src/NServiceBus.Core/Recoverability/RecoverabilityActionLogger.cs new file mode 100644 index 00000000000..ca722b5550f --- /dev/null +++ b/src/NServiceBus.Core/Recoverability/RecoverabilityActionLogger.cs @@ -0,0 +1,129 @@ +#nullable enable + +namespace NServiceBus; + +using System; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using Transport; + +sealed class RecoverabilityActionLogger(IServiceProvider serviceProvider) +{ + public void LogRecoverabilityAction(RecoverabilityAction recoverabilityAction, ErrorContext errorContext, ExceptionRecordingMode exceptionRecordingMode) + { + // ExceptionRecordingMode.SpanAndLogs option preserves exception details behavior from the older version of NSB + // In this mode the exception details are captured both on the span and here in the logs. + // The other option (Logs) emits details in logs. Not here but rather in the proper OTel scope i.e., in the span + // in which the exception was thrown. + var exceptionToLog = exceptionRecordingMode == ExceptionRecordingMode.SpanAndLogs + ? errorContext.Exception + : null; + + switch (recoverabilityAction) + { + case ImmediateRetry: + immediateRetryLogger.ImmediateRetryLogged(exceptionToLog, errorContext.MessageId); + break; + case DelayedRetry delayedRetry: + delayedRetryLogger.DelayedRetryLogged(exceptionToLog, errorContext.MessageId, delayedRetry.Delay); + break; + case MoveToError moveToError: + moveToErrorLogger.MoveToErrorLogged(exceptionToLog, errorContext.MessageId, moveToError.ErrorQueue); + break; + case Discard discard: + discardLogger.DiscardLogged(exceptionToLog, errorContext.MessageId, discard.Reason); + break; + default: + unknownActionLogger.UnknownRecoverabilityActionLogged(exceptionToLog, recoverabilityAction.GetType().Name, errorContext.MessageId); + break; + } + } + + readonly ILogger immediateRetryLogger = serviceProvider.GetRequiredService>(); + readonly ILogger delayedRetryLogger = serviceProvider.GetRequiredService>(); + readonly ILogger moveToErrorLogger = serviceProvider.GetRequiredService>(); + readonly ILogger discardLogger = serviceProvider.GetRequiredService>(); + readonly ILogger unknownActionLogger = serviceProvider.GetRequiredService>(); +} + +static partial class RecoverabilityActionLoggerMessages +{ + // Exception is only attached when it hasn't already been logged separately by + // ActivityFactory.RecordError (see RecoverabilityActionLogger.LogRecoverabilityAction). + // The trailing punctuation differs in both scenarios, and we need to keep the colon when + // an exception is logged to ensure backwards compatibility + public static void ImmediateRetryLogged(this ILogger logger, Exception? exception, string messageId) + { + if (exception is not null) + { + ImmediateRetryLoggedWithException(logger, exception, messageId); + } + else + { + ImmediateRetryLoggedWithoutException(logger, messageId); + } + } + + [LoggerMessage(Level = LogLevel.Information, Message = "Immediate Retry is going to retry message '{MessageId}' because of an exception:")] + static partial void ImmediateRetryLoggedWithException(ILogger logger, Exception exception, string messageId); + + [LoggerMessage(Level = LogLevel.Information, Message = "Immediate Retry is going to retry message '{MessageId}' because of an exception.")] + static partial void ImmediateRetryLoggedWithoutException(ILogger logger, string messageId); + + public static void DelayedRetryLogged(this ILogger logger, Exception? exception, string messageId, TimeSpan delay) + { + if (exception is not null) + { + DelayedRetryLoggedWithException(logger, exception, messageId, delay); + } + else + { + DelayedRetryLoggedWithoutException(logger, messageId, delay); + } + } + + [LoggerMessage(Level = LogLevel.Warning, Message = "Delayed Retry will reschedule message '{MessageId}' after a delay of {Delay} because of an exception:")] + static partial void DelayedRetryLoggedWithException(ILogger logger, Exception exception, string messageId, TimeSpan delay); + + [LoggerMessage(Level = LogLevel.Warning, Message = "Delayed Retry will reschedule message '{MessageId}' after a delay of {Delay} because of an exception.")] + static partial void DelayedRetryLoggedWithoutException(ILogger logger, string messageId, TimeSpan delay); + + public static void MoveToErrorLogged(this ILogger logger, Exception? exception, string messageId, string errorQueue) + { + if (exception is not null) + { + MoveToErrorLoggedWithException(logger, exception, messageId, errorQueue); + } + else + { + MoveToErrorLoggedWithoutException(logger, messageId, errorQueue); + } + } + + [LoggerMessage(Level = LogLevel.Error, Message = "Moving message '{MessageId}' to the error queue '{ErrorQueue}' because processing failed due to an exception:")] + static partial void MoveToErrorLoggedWithException(ILogger logger, Exception exception, string messageId, string errorQueue); + + [LoggerMessage(Level = LogLevel.Error, Message = "Moving message '{MessageId}' to the error queue '{ErrorQueue}' because processing failed due to an exception.")] + static partial void MoveToErrorLoggedWithoutException(ILogger logger, string messageId, string errorQueue); + + public static void DiscardLogged(this ILogger logger, Exception? exception, string messageId, string reason) + { + if (exception is not null) + { + DiscardLoggedWithException(logger, exception, messageId, reason); + } + else + { + DiscardLoggedWithoutException(logger, messageId, reason); + } + } + + [LoggerMessage(Level = LogLevel.Information, Message = "Discarding message with id '{MessageId}'. Reason: {Reason}")] + static partial void DiscardLoggedWithException(ILogger logger, Exception exception, string messageId, string reason); + + [LoggerMessage(Level = LogLevel.Information, Message = "Discarding message with id '{MessageId}'. Reason: {Reason}.")] + static partial void DiscardLoggedWithoutException(ILogger logger, string messageId, string reason); + + [LoggerMessage(Level = LogLevel.Information, Message = "Recoverability action '{ActionType}' invoked for message '{MessageId}'.")] + public static partial void UnknownRecoverabilityActionLogged(this ILogger logger, Exception? exception, string actionType, string messageId); +} diff --git a/src/NServiceBus.Core/Recoverability/RecoverabilityComponent.cs b/src/NServiceBus.Core/Recoverability/RecoverabilityComponent.cs index a3be93fa090..972bcba47d2 100644 --- a/src/NServiceBus.Core/Recoverability/RecoverabilityComponent.cs +++ b/src/NServiceBus.Core/Recoverability/RecoverabilityComponent.cs @@ -74,7 +74,8 @@ public IRecoverabilityPipelineExecutor CreateRecoverabilityPipelineExecutor( IServiceProvider serviceProvider, IPipelineCache pipelineCache, PipelineComponent pipeline, - MessageOperations messageOperations) + MessageOperations messageOperations, + IActivityFactory activityFactory) { ArgumentNullException.ThrowIfNull(recoverabilityConfig); ArgumentNullException.ThrowIfNull(faultMetadataExtractor); @@ -103,7 +104,9 @@ public IRecoverabilityPipelineExecutor CreateRecoverabilityPipelineExecutor( }, recoverabilityPipeline, faultMetadataExtractor, - (this, policy)); + (this, policy), + activityFactory + ); } public IRecoverabilityPipelineExecutor CreateSatelliteRecoverabilityExecutor( diff --git a/src/NServiceBus.Core/Recoverability/RecoverabilityPipelineExecutor.cs b/src/NServiceBus.Core/Recoverability/RecoverabilityPipelineExecutor.cs index 70f9c4ffb63..e6c0e8ba9e1 100644 --- a/src/NServiceBus.Core/Recoverability/RecoverabilityPipelineExecutor.cs +++ b/src/NServiceBus.Core/Recoverability/RecoverabilityPipelineExecutor.cs @@ -1,4 +1,4 @@ -#nullable enable +#nullable enable namespace NServiceBus; @@ -6,50 +6,51 @@ namespace NServiceBus; using System.Threading; using System.Threading.Tasks; using Microsoft.Extensions.DependencyInjection; -using NServiceBus.Pipeline; +using Pipeline; using Transport; -class RecoverabilityPipelineExecutor : IRecoverabilityPipelineExecutor +class RecoverabilityPipelineExecutor( + IServiceProvider serviceProvider, + IPipelineCache pipelineCache, + MessageOperations messageOperations, + RecoverabilityConfig recoverabilityConfig, + Func recoverabilityPolicy, + IPipeline recoverabilityPipeline, + FaultMetadataExtractor faultMetadataExtractor, + TState state, + IActivityFactory activityFactory) : IRecoverabilityPipelineExecutor { - public RecoverabilityPipelineExecutor( - IServiceProvider serviceProvider, - IPipelineCache pipelineCache, - MessageOperations messageOperations, - RecoverabilityConfig recoverabilityConfig, - Func recoverabilityPolicy, - IPipeline recoverabilityPipeline, - FaultMetadataExtractor faultMetadataExtractor, - TState state) - { - this.state = state; - this.serviceProvider = serviceProvider; - this.pipelineCache = pipelineCache; - this.messageOperations = messageOperations; - this.recoverabilityConfig = recoverabilityConfig; - this.recoverabilityPolicy = recoverabilityPolicy; - this.recoverabilityPipeline = recoverabilityPipeline; - this.faultMetadataExtractor = faultMetadataExtractor; - } - public async Task Invoke(ErrorContext errorContext, CancellationToken cancellationToken = default) { var childScope = serviceProvider.CreateAsyncScope(); await using (childScope.ConfigureAwait(false)) { - var recoverabilityAction = recoverabilityPolicy(errorContext, state); + RecoverabilityAction? recoverabilityAction; + + using (var activity = activityFactory.StartRecoverabilityActivity(errorContext)) + { + recoverabilityAction = recoverabilityPolicy(errorContext, state); + + if (activity is not null) + { + activityFactory.UpdateActivityFromRecoverabilityAction(activity, recoverabilityAction, errorContext.ReceiveAddress); + } + + recoverabilityActionLogger.LogRecoverabilityAction(recoverabilityAction, errorContext, activityFactory.Options.ExceptionRecordingMode); + } var metadata = faultMetadataExtractor.Extract(errorContext); var recoverabilityContext = new RecoverabilityContext( - childScope.ServiceProvider, - messageOperations, - pipelineCache, - errorContext, - recoverabilityConfig, - metadata, - recoverabilityAction, - errorContext.Extensions, - cancellationToken); + childScope.ServiceProvider, + messageOperations, + pipelineCache, + errorContext, + recoverabilityConfig, + metadata, + recoverabilityAction, + errorContext.Extensions, + cancellationToken); await recoverabilityPipeline.Invoke(recoverabilityContext).ConfigureAwait(false); @@ -57,12 +58,5 @@ public async Task Invoke(ErrorContext errorContext, Cancellat } } - readonly IServiceProvider serviceProvider; - readonly IPipelineCache pipelineCache; - readonly MessageOperations messageOperations; - readonly RecoverabilityConfig recoverabilityConfig; - readonly Func recoverabilityPolicy; - readonly IPipeline recoverabilityPipeline; - readonly FaultMetadataExtractor faultMetadataExtractor; - readonly TState state; -} \ No newline at end of file + readonly RecoverabilityActionLogger recoverabilityActionLogger = new(serviceProvider); +} diff --git a/src/NServiceBus.Core/Recoverability/RecoverabilityRoutingConnector.cs b/src/NServiceBus.Core/Recoverability/RecoverabilityRoutingConnector.cs index b81ad021265..62f10fb27c2 100644 --- a/src/NServiceBus.Core/Recoverability/RecoverabilityRoutingConnector.cs +++ b/src/NServiceBus.Core/Recoverability/RecoverabilityRoutingConnector.cs @@ -56,4 +56,4 @@ public override async Task Invoke(IRecoverabilityContext context, Func { public async Task Invoke(IInvokeHandlerContext context, Func next) @@ -67,7 +67,20 @@ public async Task Invoke(IInvokeHandlerContext context, Func(); // Register the Saga related behaviors for incoming messages - context.Pipeline.Register("InvokeSaga", b => new SagaPersistenceBehavior(b.GetRequiredService(), sagaIdGenerator, sagaMetaModel, b), "Invokes the saga logic"); + context.Pipeline.Register("InvokeSaga", b => new SagaPersistenceBehavior(b.GetRequiredService(), sagaIdGenerator, sagaMetaModel, b, b.GetRequiredService()), "Invokes the saga logic"); context.Pipeline.Register("AttachSagaDetailsToOutGoingMessage", new AttachSagaDetailsToOutGoingMessageBehavior(), "Makes sure that outgoing messages have saga info attached to them"); } } \ No newline at end of file diff --git a/src/NServiceBus.Core/Serialization/SerializationFeature.cs b/src/NServiceBus.Core/Serialization/SerializationFeature.cs index a332f50bd37..41bec7b6d5a 100644 --- a/src/NServiceBus.Core/Serialization/SerializationFeature.cs +++ b/src/NServiceBus.Core/Serialization/SerializationFeature.cs @@ -48,8 +48,8 @@ protected override void Setup(FeatureConfigurationContext context) var allowMessageTypeInference = settings.IsMessageTypeInferenceEnabled(); var resolver = new MessageDeserializerResolver(mainSerializer, additionalDeserializers); var logicalMessageFactory = new LogicalMessageFactory(messageMetadataRegistry, mapper); - context.Pipeline.Register("DeserializeLogicalMessagesConnector", new DeserializeMessageConnector(resolver, logicalMessageFactory, messageMetadataRegistry, mapper, allowMessageTypeInference), "Deserializes the physical message body into logical messages"); - context.Pipeline.Register("SerializeMessageConnector", new SerializeMessageConnector(mainSerializer, messageMetadataRegistry), "Converts a logical message into a physical message"); + context.Pipeline.Register("DeserializeLogicalMessagesConnector", b => new DeserializeMessageConnector(resolver, logicalMessageFactory, messageMetadataRegistry, mapper, allowMessageTypeInference, b.GetRequiredService()), "Deserializes the physical message body into logical messages"); + context.Pipeline.Register("SerializeMessageConnector", b => new SerializeMessageConnector(mainSerializer, messageMetadataRegistry, b.GetRequiredService()), "Converts a logical message into a physical message"); context.Services.AddSingleton(mapper); context.Services.AddSingleton(mapper); diff --git a/src/NServiceBus.Core/Transports/MessageContext.cs b/src/NServiceBus.Core/Transports/MessageContext.cs index 7d191154923..a3c64d702a7 100644 --- a/src/NServiceBus.Core/Transports/MessageContext.cs +++ b/src/NServiceBus.Core/Transports/MessageContext.cs @@ -49,8 +49,6 @@ public MessageContext(string nativeMessageId, Dictionary headers Extensions = context; ReceiveAddress = receiveAddress; TransportTransaction = transportTransaction; - - context.GetOrCreate(); } /// diff --git a/src/NServiceBus.Core/Unicast/MessageOperations.cs b/src/NServiceBus.Core/Unicast/MessageOperations.cs index 34c60f3cda1..cfceeb4c684 100644 --- a/src/NServiceBus.Core/Unicast/MessageOperations.cs +++ b/src/NServiceBus.Core/Unicast/MessageOperations.cs @@ -65,9 +65,13 @@ async Task Publish(IBehaviorContext context, Type messageType, object message, P MergeDispatchProperties(publishContext, options.DispatchProperties); - using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.OutgoingEventActivityName, ActivityDisplayNames.PublishEvent, publishContext); + var publishDisplayName = activityFactory.Options.UseMessageDestinationInSpanNames + ? $"{ActivityDisplayNames.PublishOperation} {messageType.Name}" + : ActivityDisplayNames.PublishEvent; - await publishPipeline.Invoke(publishContext, activity).ConfigureAwait(false); + using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.OutgoingEventActivityName, publishDisplayName, publishContext); + + await publishPipeline.Invoke(publishContext, activity, activityFactory).ConfigureAwait(false); } public Task Subscribe(IBehaviorContext context, Type eventType, SubscribeOptions options) @@ -86,7 +90,7 @@ public async Task Subscribe(IBehaviorContext context, Type[] eventTypes, Subscri using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.SubscribeActivityName, ActivityDisplayNames.SubscribeEvent, context); - await subscribePipeline.Invoke(subscribeContext, activity).ConfigureAwait(false); + await subscribePipeline.Invoke(subscribeContext, activity, activityFactory).ConfigureAwait(false); } public async Task Unsubscribe(IBehaviorContext context, Type eventType, UnsubscribeOptions options) @@ -100,7 +104,7 @@ public async Task Unsubscribe(IBehaviorContext context, Type eventType, Unsubscr using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.UnsubscribeActivityName, ActivityDisplayNames.UnsubscribeEvent, context); - await unsubscribePipeline.Invoke(unsubscribeContext, activity).ConfigureAwait(false); + await unsubscribePipeline.Invoke(unsubscribeContext, activity, activityFactory).ConfigureAwait(false); } public Task Send(IBehaviorContext context, Action messageConstructor, SendOptions options) @@ -134,7 +138,7 @@ async Task SendMessage(IBehaviorContext context, Type messageType, object messag using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.OutgoingMessageActivityName, ActivityDisplayNames.SendMessage, outgoingContext); - await sendPipeline.Invoke(outgoingContext, activity).ConfigureAwait(false); + await sendPipeline.Invoke(outgoingContext, activity, activityFactory).ConfigureAwait(false); } public Task Reply(IBehaviorContext context, object message, ReplyOptions options) @@ -168,7 +172,7 @@ async Task ReplyMessage(IBehaviorContext context, Type messageType, object messa using var activity = activityFactory.StartOutgoingPipelineActivity(ActivityNames.OutgoingMessageActivityName, ActivityDisplayNames.ReplyMessage, outgoingContext); - await replyPipeline.Invoke(outgoingContext, activity).ConfigureAwait(false); + await replyPipeline.Invoke(outgoingContext, activity, activityFactory).ConfigureAwait(false); } static void MergeDispatchProperties(ContextBag context, DispatchProperties dispatchProperties) diff --git a/src/NServiceBus.Testing.Fakes/TestablePipelineContext.cs b/src/NServiceBus.Testing.Fakes/TestablePipelineContext.cs index ca256ad6b42..4090f548108 100644 --- a/src/NServiceBus.Testing.Fakes/TestablePipelineContext.cs +++ b/src/NServiceBus.Testing.Fakes/TestablePipelineContext.cs @@ -16,11 +16,7 @@ public partial class TestablePipelineContext : IPipelineContext /// /// Creates a new instance. /// - public TestablePipelineContext(IMessageCreator messageCreator = null) - { - this.messageCreator = messageCreator ?? new MessageMapper(); - Extensions.GetOrCreate(); - } + public TestablePipelineContext(IMessageCreator messageCreator = null) => this.messageCreator = messageCreator ?? new MessageMapper(); /// /// A list of all messages sent with a saga timeout header.