Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
<PackageReference Include="NServiceBus" Version="9.2.5" />
<PackageReference Include="NServiceBus.Persistence.Sql" Version="8.2.0" />
<PackageReference Include="Microsoft.Data.SqlClient" Version="6.0.1" />
<PackageReference Include="Microsoft.ApplicationInsights" Version="2.22.0" />
</ItemGroup>

<ItemGroup>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,184 @@
using ClearMeasure.HostedEndpoint.Infrastructure;
using FluentAssertions;
using Microsoft.ApplicationInsights;
using Microsoft.ApplicationInsights.Channel;
using Microsoft.ApplicationInsights.DataContracts;
using Microsoft.ApplicationInsights.Extensibility;
using Moq;
using NServiceBus.Pipeline;
using Xunit;

namespace ClearHostedEndpoint.Tests.Infrastructure;

public class HandlerTimingBehaviorTests
{
[Fact]
public async Task Invoke_ShouldCallNextBehavior()
{
// Arrange
var behavior = new HandlerTimingBehavior();
var context = new Mock<IInvokeHandlerContext>();
var messageHandler = new Mock<MessageHandler>();
messageHandler.Setup(h => h.HandlerType).Returns(typeof(HandlerTimingBehaviorTests));
context.Setup(c => c.MessageHandler).Returns(messageHandler.Object);
context.Setup(c => c.MessageBeingHandled).Returns(new object());
context.Setup(c => c.MessageId).Returns("test-id");
context.Setup(c => c.Headers).Returns(new Dictionary<string, string>());

var nextCalled = false;

// Act
await behavior.Invoke(context.Object, () =>
{
nextCalled = true;
return Task.CompletedTask;
});

// Assert
nextCalled.Should().BeTrue();
}

[Fact]
public async Task Invoke_WhenTelemetryClientIsNull_ShouldNotThrow()
{
// Arrange
var behavior = new HandlerTimingBehavior(null);
var context = new Mock<IInvokeHandlerContext>();
var messageHandler = new Mock<MessageHandler>();
messageHandler.Setup(h => h.HandlerType).Returns(typeof(HandlerTimingBehaviorTests));
context.Setup(c => c.MessageHandler).Returns(messageHandler.Object);
context.Setup(c => c.MessageBeingHandled).Returns(new object());
context.Setup(c => c.MessageId).Returns("test-id");
context.Setup(c => c.Headers).Returns(new Dictionary<string, string>());

// Act
Func<Task> act = async () => await behavior.Invoke(context.Object, () => Task.CompletedTask);

// Assert
await act.Should().NotThrowAsync();
}

[Fact]
public async Task Invoke_WhenExceptionOccurs_ShouldRethrowException()
{
// Arrange
var behavior = new HandlerTimingBehavior();
var context = new Mock<IInvokeHandlerContext>();
var messageHandler = new Mock<MessageHandler>();
messageHandler.Setup(h => h.HandlerType).Returns(typeof(HandlerTimingBehaviorTests));
context.Setup(c => c.MessageHandler).Returns(messageHandler.Object);
context.Setup(c => c.MessageBeingHandled).Returns(new object());
context.Setup(c => c.MessageId).Returns("test-id");
context.Setup(c => c.Headers).Returns(new Dictionary<string, string>());

var expectedException = new InvalidOperationException("Test exception");

// Act
Func<Task> act = async () => await behavior.Invoke(context.Object, () => throw expectedException);

// Assert
await act.Should().ThrowAsync<InvalidOperationException>()
.WithMessage("Test exception");
}

[Fact]
public async Task Invoke_WithTelemetryClient_ShouldTrackDependency()
{
// Arrange
var telemetryItems = new List<ITelemetry>();
var telemetryConfiguration = new TelemetryConfiguration
{
TelemetryChannel = new StubTelemetryChannel { OnSend = telemetryItems.Add }
};
var telemetryClient = new TelemetryClient(telemetryConfiguration);
var behavior = new HandlerTimingBehavior(telemetryClient);

var context = new Mock<IInvokeHandlerContext>();
var messageHandler = new Mock<MessageHandler>();
messageHandler.Setup(h => h.HandlerType).Returns(typeof(HandlerTimingBehaviorTests));
context.Setup(c => c.MessageHandler).Returns(messageHandler.Object);
context.Setup(c => c.MessageBeingHandled).Returns(new object());
context.Setup(c => c.MessageId).Returns("test-id");
context.Setup(c => c.Headers).Returns(new Dictionary<string, string>());

// Act
await behavior.Invoke(context.Object, () => Task.CompletedTask);

// Give telemetry time to flush
await Task.Delay(100);

// Assert
telemetryItems.Should().NotBeEmpty();
telemetryItems.Should().ContainSingle(t => t is DependencyTelemetry);

var dependency = telemetryItems.OfType<DependencyTelemetry>().First();
dependency.Type.Should().Be("NServiceBus.Handler");
dependency.Success.Should().BeTrue();
}

[Fact]
public async Task Invoke_WhenExceptionOccurs_ShouldTrackFailedDependency()
{
// Arrange
var telemetryItems = new List<ITelemetry>();
var telemetryConfiguration = new TelemetryConfiguration
{
TelemetryChannel = new StubTelemetryChannel { OnSend = telemetryItems.Add }
};
var telemetryClient = new TelemetryClient(telemetryConfiguration);
var behavior = new HandlerTimingBehavior(telemetryClient);

var context = new Mock<IInvokeHandlerContext>();
var messageHandler = new Mock<MessageHandler>();
messageHandler.Setup(h => h.HandlerType).Returns(typeof(HandlerTimingBehaviorTests));
context.Setup(c => c.MessageHandler).Returns(messageHandler.Object);
context.Setup(c => c.MessageBeingHandled).Returns(new object());
context.Setup(c => c.MessageId).Returns("test-id");
context.Setup(c => c.Headers).Returns(new Dictionary<string, string>());

var expectedException = new InvalidOperationException("Handler failed");

// Act
try
{
await behavior.Invoke(context.Object, () => throw expectedException);
}
catch (InvalidOperationException)
{
// Expected exception
}

// Give telemetry time to flush
await Task.Delay(100);

// Assert
telemetryItems.Should().NotBeEmpty();
telemetryItems.Should().ContainSingle(t => t is DependencyTelemetry);

var dependency = telemetryItems.OfType<DependencyTelemetry>().First();
dependency.Type.Should().Be("NServiceBus.Handler");
dependency.Success.Should().BeFalse();
dependency.Properties.Should().ContainKey("ExceptionType");
dependency.Properties.Should().ContainKey("ExceptionMessage");
}

private class StubTelemetryChannel : ITelemetryChannel
{
public Action<ITelemetry>? OnSend { get; set; }
public bool? DeveloperMode { get; set; }
public string? EndpointAddress { get; set; }

public void Send(ITelemetry item)
{
OnSend?.Invoke(item);
}

public void Flush()
{
}

public void Dispose()
{
}
}
}
46 changes: 46 additions & 0 deletions src/ClearHostedEndpoint/ClearHostedEndpoint.cs
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@
private IEndpointInstance? _endpointInstance;
private IServiceCollection? _nsbServiceCollection;

protected ClearHostedEndpoint(IConfiguration configuration) : base(configuration)

Check warning on line 20 in src/ClearHostedEndpoint/ClearHostedEndpoint.cs

View workflow job for this annotation

GitHub Actions / Build and Test

Missing XML comment for publicly visible type or member 'ClearHostedEndpoint.ClearHostedEndpoint(IConfiguration)'

Check warning on line 20 in src/ClearHostedEndpoint/ClearHostedEndpoint.cs

View workflow job for this annotation

GitHub Actions / Build and Test

Missing XML comment for publicly visible type or member 'ClearHostedEndpoint.ClearHostedEndpoint(IConfiguration)'
{
}

Expand Down Expand Up @@ -138,9 +138,55 @@
// Configure concurrency
endpointConfiguration.LimitMessageProcessingConcurrencyTo(EndpointOptions.MaxConcurrency);

// Register handler timing behavior if Application Insights is enabled
var loggingOptions = GetLoggingOptions();
if (loggingOptions.EnableApplicationInsights)
{
RegisterHandlerTimingBehavior(endpointConfiguration, loggingOptions);
}

return endpointConfiguration;
}

/// <summary>
/// Registers the handler timing behavior for Application Insights telemetry.
/// </summary>
/// <param name="endpointConfiguration">The endpoint configuration.</param>
/// <param name="loggingOptions">The logging options containing Application Insights settings.</param>
protected virtual void RegisterHandlerTimingBehavior(EndpointConfiguration endpointConfiguration, HostedService.Configuration.LoggingOptions loggingOptions)
{
var connectionString = loggingOptions.ApplicationInsightsConnectionString;

#pragma warning disable CS0618
if (string.IsNullOrEmpty(connectionString) && !string.IsNullOrEmpty(loggingOptions.ApplicationInsightsInstrumentationKey))
{
connectionString = $"InstrumentationKey={loggingOptions.ApplicationInsightsInstrumentationKey}";
}
#pragma warning restore CS0618

if (string.IsNullOrEmpty(connectionString))
{
Logger.Warning("Application Insights is enabled but no connection string provided. Handler timing metrics will not be tracked.");
return;
}

var telemetryConfiguration = new Microsoft.ApplicationInsights.Extensibility.TelemetryConfiguration
{
ConnectionString = connectionString
};

// Add cloud role telemetry initializer
telemetryConfiguration.TelemetryInitializers.Add(new HostedService.Infrastructure.CloudRoleTelemetryInitializer(EffectiveEndpointName));

var telemetryClient = new Microsoft.ApplicationInsights.TelemetryClient(telemetryConfiguration);

endpointConfiguration.Pipeline.Register(
new Infrastructure.HandlerTimingBehavior(telemetryClient),
"Tracks handler execution time and sends metrics to Application Insights");

Logger.Information("Handler timing behavior registered for Application Insights in endpoint {EndpointName}", EffectiveEndpointName);
}

/// <summary>
/// Configures the message transport. This method must be overridden to specify the transport.
/// </summary>
Expand Down
1 change: 1 addition & 0 deletions src/ClearHostedEndpoint/ClearMeasure.HostedEndpoint.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
<PackageReference Include="NServiceBus" Version="9.2.5" />
<PackageReference Include="NServiceBus.Persistence.Sql" Version="8.2.0" />
<PackageReference Include="Microsoft.Data.SqlClient" Version="6.0.1" />
<PackageReference Include="Microsoft.ApplicationInsights" Version="2.22.0" />
</ItemGroup>

</Project>
97 changes: 97 additions & 0 deletions src/ClearHostedEndpoint/Infrastructure/HandlerTimingBehavior.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,97 @@
using Microsoft.ApplicationInsights;
using Microsoft.ApplicationInsights.DataContracts;
using NServiceBus;
using NServiceBus.Pipeline;

namespace ClearMeasure.HostedEndpoint.Infrastructure;

/// <summary>
/// NServiceBus pipeline behavior that tracks handler execution time and sends metrics to Application Insights.
/// </summary>
public class HandlerTimingBehavior : Behavior<IInvokeHandlerContext>
{
private readonly TelemetryClient? _telemetryClient;

/// <summary>
/// Initializes a new instance of the <see cref="HandlerTimingBehavior"/> class.
/// </summary>
/// <param name="telemetryClient">Optional telemetry client for Application Insights tracking.</param>
public HandlerTimingBehavior(TelemetryClient? telemetryClient = null)
{
_telemetryClient = telemetryClient;
}

/// <summary>
/// Invokes the behavior to track handler execution time.
/// </summary>
/// <param name="context">The handler context.</param>
/// <param name="next">The next behavior in the pipeline.</param>
public override async Task Invoke(IInvokeHandlerContext context, Func<Task> next)
{
var startTime = DateTimeOffset.UtcNow;
var handlerType = context.MessageHandler.HandlerType;
var messageType = context.MessageBeingHandled.GetType();

Exception? exception = null;

try
{
await next();
}
catch (Exception ex)
{
exception = ex;
throw;
}
finally
{
var duration = DateTimeOffset.UtcNow - startTime;

if (_telemetryClient != null)
{
TrackHandlerExecution(handlerType, messageType, duration, exception, context);
}
}
}

private void TrackHandlerExecution(
Type handlerType,
Type messageType,
TimeSpan duration,
Exception? exception,
IInvokeHandlerContext context)
{
// Track as a dependency telemetry (represents a call to handle a message)
var dependencyTelemetry = new DependencyTelemetry
{
Name = $"{handlerType.Name}.Handle({messageType.Name})",
Type = "NServiceBus.Handler",
Duration = duration,
Success = exception == null,
Timestamp = DateTimeOffset.UtcNow - duration
};

// Add custom properties for better filtering and analysis
dependencyTelemetry.Properties["HandlerType"] = handlerType.FullName ?? handlerType.Name;
dependencyTelemetry.Properties["MessageType"] = messageType.FullName ?? messageType.Name;
dependencyTelemetry.Properties["MessageId"] = context.MessageId;

if (context.Headers.TryGetValue(NServiceBus.Headers.CorrelationId, out var correlationId))
{
dependencyTelemetry.Properties["CorrelationId"] = correlationId;
}

if (context.Headers.TryGetValue(NServiceBus.Headers.ConversationId, out var conversationId))
{
dependencyTelemetry.Properties["ConversationId"] = conversationId;
}

if (exception != null)
{
dependencyTelemetry.Properties["ExceptionType"] = exception.GetType().FullName ?? exception.GetType().Name;
dependencyTelemetry.Properties["ExceptionMessage"] = exception.Message;
}

_telemetryClient?.TrackDependency(dependencyTelemetry);
}
}
13 changes: 11 additions & 2 deletions src/ClearHostedService.Tests/Infrastructure/ConfigurationTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,10 @@ public void Constructor_ShouldSetDefaultValues()
options.EnableConsoleLogging.Should().BeTrue();
options.EnableFileLogging.Should().BeTrue();
options.EnableApplicationInsights.Should().BeFalse();
options.ApplicationInsightsConnectionString.Should().BeNull();
#pragma warning disable CS0618
options.ApplicationInsightsInstrumentationKey.Should().BeNull();
#pragma warning restore CS0618
}

[Fact]
Expand All @@ -37,7 +40,10 @@ public void Properties_ShouldBeSettable()
options.EnableConsoleLogging = false;
options.EnableFileLogging = false;
options.EnableApplicationInsights = true;
options.ApplicationInsightsInstrumentationKey = "test-key";
options.ApplicationInsightsConnectionString = "InstrumentationKey=test-key;IngestionEndpoint=https://test.applicationinsights.azure.com/";
#pragma warning disable CS0618
options.ApplicationInsightsInstrumentationKey = "test-key-legacy";
#pragma warning restore CS0618

// Assert
options.LogLevel.Should().Be(LogEventLevel.Debug);
Expand All @@ -46,7 +52,10 @@ public void Properties_ShouldBeSettable()
options.EnableConsoleLogging.Should().BeFalse();
options.EnableFileLogging.Should().BeFalse();
options.EnableApplicationInsights.Should().BeTrue();
options.ApplicationInsightsInstrumentationKey.Should().Be("test-key");
options.ApplicationInsightsConnectionString.Should().Be("InstrumentationKey=test-key;IngestionEndpoint=https://test.applicationinsights.azure.com/");
#pragma warning disable CS0618
options.ApplicationInsightsInstrumentationKey.Should().Be("test-key-legacy");
#pragma warning restore CS0618
}
}

Expand Down
Loading
Loading