Skip to content

Commit

Permalink
feat: track az servicebus in app insights (#269)
Browse files Browse the repository at this point in the history
* feat: track az servicebus in app insights

* pr-fix: query only last half hour

* pr-fix: clean-up and better xml docs
  • Loading branch information
stijnmoreels authored Jan 25, 2022
1 parent 1e363b7 commit 03f6ff8
Show file tree
Hide file tree
Showing 4 changed files with 251 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -8,11 +8,11 @@ public enum RequestSourceSystem
/// <summary>
/// Specifies that the request-source is an Azure Service Bus queue or topic.
/// </summary>
AzureServiceBus,
AzureServiceBus = 1,

/// <summary>
/// Specifies that the request-source is a HTTP request
/// </summary>
Http
Http = 2
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Conver
/// </summary>
public class RequestTelemetryConverter : CustomTelemetryConverter<RequestTelemetry>
{
private ApplicationInsightsSinkRequestOptions _options;
private readonly ApplicationInsightsSinkRequestOptions _options;

/// <summary>
/// Initializes a new instance of the <see cref="RequestTelemetryConverter" /> class.
Expand Down Expand Up @@ -55,30 +55,61 @@ protected override RequestTelemetry CreateTelemetryEntry(LogEvent logEvent, IFor
TimeSpan requestDuration = logEntry.Properties.GetAsTimeSpan(nameof(RequestLogEntry.RequestDuration));
DateTimeOffset requestTime = logEntry.Properties.GetAsDateTimeOffset(nameof(RequestLogEntry.RequestTime));
IDictionary<string, string> context = logEntry.Properties.GetAsDictionary(nameof(RequestLogEntry.Context));
var sourceSystem = logEntry.Properties.GetAsObject<RequestSourceSystem>(nameof(RequestLogEntry.SourceSystem));

string id = _options.GenerateId();

var requestName = $"{requestMethod} {requestUri}";
string sourceName = DetermineSourceName(sourceSystem, requestMethod, requestUri, operationName);
bool isSuccessfulRequest = DetermineRequestOutcome(responseStatusCode);
var url = new Uri($"{requestHost}{requestUri}");
Uri url = DetermineUrl(sourceSystem, requestHost, requestUri);
string source = DetermineRequestSource(sourceSystem, context);
string requestOperationName = DetermineRequestOperationName(sourceSystem, requestMethod, operationName);

var requestTelemetry = new RequestTelemetry(requestName, requestTime, requestDuration, responseStatusCode, isSuccessfulRequest)
var requestTelemetry = new RequestTelemetry(sourceName, requestTime, requestDuration, responseStatusCode, isSuccessfulRequest)
{
Id = id,
Url = url
Url = url,
Source = source,
Context = { Operation = { Name = requestOperationName } }
};

if (!operationName.StartsWith(requestMethod))
requestTelemetry.Properties.AddRange(context);
return requestTelemetry;
}

private static string DetermineSourceName(RequestSourceSystem sourceSystem, string requestMethod, string requestUri, string operationName)
{
if (sourceSystem is RequestSourceSystem.Http)
{
requestTelemetry.Context.Operation.Name = $"{requestMethod} {operationName}";
var requestName = $"{requestMethod} {requestUri}";
return requestName;
}
else

return operationName;
}

private static Uri DetermineUrl(RequestSourceSystem sourceSystem, string requestHost, string requestUri)
{
if (sourceSystem is RequestSourceSystem.Http)
{
requestTelemetry.Context.Operation.Name = operationName;
var url = new Uri($"{requestHost}{requestUri}");
return url;
}

requestTelemetry.Properties.AddRange(context);
return requestTelemetry;
return null;
}

private static string DetermineRequestSource(RequestSourceSystem sourceSystem, IDictionary<string, string> context)
{
if (sourceSystem is RequestSourceSystem.AzureServiceBus)
{
string entityName = context[ContextProperties.RequestTracking.ServiceBus.EntityName];
string namespaceEndpoint = context[ContextProperties.RequestTracking.ServiceBus.Endpoint];

return $"type:Azure Service Bus | name:{entityName} | endpoint:sb://{namespaceEndpoint}/";
}

return null;
}

private static bool DetermineRequestOutcome(string rawResponseStatusCode)
Expand All @@ -87,5 +118,15 @@ private static bool DetermineRequestOutcome(string rawResponseStatusCode)

return statusCode >= 200 && statusCode < 300;
}

private static string DetermineRequestOperationName(RequestSourceSystem sourceSystem, string requestMethod, string operationName)
{
if (sourceSystem is RequestSourceSystem.Http && !operationName.StartsWith(requestMethod))
{
return $"{requestMethod} {operationName}";
}

return operationName;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -183,5 +183,32 @@ internal static bool GetAsBool(this IReadOnlyList<LogEventProperty> properties,
bool value = bool.Parse(propertyValue);
return value;
}

/// <summary>
/// Gets a <typeparamref name="TValue"/> representation of a property in the <paramref name="properties"/> associated with the <paramref name="propertyKey"/>.
/// </summary>
/// <typeparam name="TValue">The custom type to cast to.</typeparam>
/// <param name="properties">The properties containing the property value associated with the <paramref name="propertyKey"/>.</param>
/// <param name="propertyKey">The key the property is associated with.</param>
/// <returns>
/// An <typeparamref name="TValue"/> representation when the property was found; <c>default</c> otherwise.
/// </returns>
/// <exception cref="ArgumentNullException">Thrown when the <paramref name="properties"/> is <c>null</c>.</exception>
/// <exception cref="ArgumentException">Thrown when the <paramref name="propertyKey"/> is blank.</exception>
internal static TValue GetAsObject<TValue>(this IReadOnlyList<LogEventProperty> properties, string propertyKey)
{
Guard.NotNull(properties, nameof(properties), "Requires a series of event properties to retrieve a Serilog event property as an enumeration representation");
Guard.NotNullOrWhitespace(propertyKey, nameof(propertyKey), "Requires a non-blank property to retrieve a Serilog event property as an enumeration representation");

LogEventProperty property = properties.FirstOrDefault(prop => prop.Name == propertyKey);
if (property != null
&& property.Value is ScalarValue scalarValue
&& scalarValue.Value is TValue value)
{
return value;
}

return default(TValue);
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,170 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using Arcus.Observability.Telemetry.Core;
using Microsoft.Azure.ApplicationInsights.Query;
using Microsoft.Azure.ApplicationInsights.Query.Models;
using Microsoft.Extensions.Logging;
using Xunit;
using Xunit.Abstractions;

namespace Arcus.Observability.Tests.Integration.Serilog.Sinks.ApplicationInsights
{
public class ServiceBusRequestTests : ApplicationInsightsSinkTests
{
public ServiceBusRequestTests(ITestOutputHelper outputWriter) : base(outputWriter)
{
}

[Fact]
public async Task LogServiceBusQueueRequest_SinksToApplicationInsights_ResultsInRequestTelemetry()
{
// Arrange
string queueName = BogusGenerator.Lorem.Word();
string serviceBusNamespace = $"{BogusGenerator.Lorem.Word()}.servicebus.windows.net";
string operationName = BogusGenerator.Lorem.Sentence();
bool isSuccessful = BogusGenerator.Random.Bool();
TimeSpan duration = BogusGenerator.Date.Timespan();
DateTimeOffset startTime = DateTimeOffset.Now;
Dictionary<string, object> telemetryContext = CreateTestTelemetryContext();

using (ILoggerFactory loggerFactory = CreateLoggerFactory())
{
ILogger logger = loggerFactory.CreateLogger<ServiceBusRequestTests>();

// Act
logger.LogServiceBusQueueRequest(serviceBusNamespace, queueName, operationName, isSuccessful, duration, startTime, telemetryContext);
}

// Assert
using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient())
{
await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () =>
{
EventsResults<EventsRequestResult> results = await client.Events.GetRequestEventsAsync(ApplicationId, timespan: PastHalfHourTimeSpan);
Assert.NotNull(results.Value);
Assert.NotEmpty(results.Value);
AssertX.Any(results.Value, result =>
{
Assert.Equal(operationName, result.Request.Name);
Assert.Contains(queueName, result.Request.Source);
Assert.Contains(serviceBusNamespace, result.Request.Source);
Assert.Empty(result.Request.Url);
Assert.Equal(operationName, result.Operation.Name);
Assert.True(bool.TryParse(result.Request.Success, out bool success));
Assert.Equal(isSuccessful, success);

AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityType, ServiceBusEntityType.Queue.ToString());
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityName, queueName);
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.Endpoint, serviceBusNamespace);
});
});
}
}

[Fact]
public async Task LogServiceBusTopicRequestWithSuffix_SinksToApplicationInsights_ResultsInRequestTelemetry()
{
// Arrange
string topicName = BogusGenerator.Lorem.Word();
string subscriptionName = BogusGenerator.Lorem.Word();
string serviceBusNamespace = BogusGenerator.Lorem.Word();
string serviceBusNamespaceSuffix = ".servicebus.windows.de";
string operationName = BogusGenerator.Lorem.Sentence();
bool isSuccessful = BogusGenerator.Random.Bool();
TimeSpan duration = BogusGenerator.Date.Timespan();
DateTimeOffset startTime = DateTimeOffset.Now;
Dictionary<string, object> telemetryContext = CreateTestTelemetryContext();

using (ILoggerFactory loggerFactory = CreateLoggerFactory())
{
ILogger logger = loggerFactory.CreateLogger<ServiceBusRequestTests>();

// Act
logger.LogServiceBusTopicRequestWithSuffix(serviceBusNamespace, serviceBusNamespaceSuffix, topicName, subscriptionName, operationName, isSuccessful, duration, startTime, telemetryContext);
}

// Assert
using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient())
{
await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () =>
{
EventsResults<EventsRequestResult> results = await client.Events.GetRequestEventsAsync(ApplicationId, timespan: PastHalfHourTimeSpan);
Assert.NotNull(results.Value);
Assert.NotEmpty(results.Value);
AssertX.Any(results.Value, result =>
{
Assert.Equal(operationName, result.Request.Name);
Assert.Contains(topicName, result.Request.Source);
Assert.Contains(serviceBusNamespace, result.Request.Source);
Assert.Contains(serviceBusNamespaceSuffix, result.Request.Source);
Assert.Empty(result.Request.Url);
Assert.Equal(operationName, result.Operation.Name);
Assert.True(bool.TryParse(result.Request.Success, out bool success));
Assert.Equal(isSuccessful, success);

AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityType, ServiceBusEntityType.Topic.ToString());
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityName, topicName);
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.Endpoint, serviceBusNamespace + serviceBusNamespaceSuffix);
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.Topic.SubscriptionName, subscriptionName);
});
});
}
}

[Fact]
public async Task LogServiceBusRequest_SinksToApplicationInsights_ResultsInRequestTelemetry()
{
// Arrange
string entityName = BogusGenerator.Lorem.Word();
string serviceBusNamespace = $"{BogusGenerator.Lorem.Word()}.servicebus.windows.net";
string operationName = BogusGenerator.Lorem.Sentence();
bool isSuccessful = BogusGenerator.Random.Bool();
TimeSpan duration = BogusGenerator.Date.Timespan();
DateTimeOffset startTime = DateTimeOffset.Now;
var entityType = BogusGenerator.PickRandom<ServiceBusEntityType>();
Dictionary<string, object> telemetryContext = CreateTestTelemetryContext();

using (ILoggerFactory loggerFactory = CreateLoggerFactory())
{
ILogger logger = loggerFactory.CreateLogger<ServiceBusRequestTests>();

// Act
logger.LogServiceBusRequest(serviceBusNamespace, entityName, operationName, isSuccessful, duration, startTime, entityType, telemetryContext);
}

// Assert
using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient())
{
await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () =>
{
EventsResults<EventsRequestResult> results = await client.Events.GetRequestEventsAsync(ApplicationId, timespan: PastHalfHourTimeSpan);
Assert.NotNull(results.Value);
Assert.NotEmpty(results.Value);
AssertX.Any(results.Value, result =>
{
Assert.Equal(operationName, result.Request.Name);
Assert.Contains(entityName, result.Request.Source);
Assert.Contains(serviceBusNamespace, result.Request.Source);
Assert.Empty(result.Request.Url);
Assert.Equal(operationName, result.Operation.Name);
Assert.True(bool.TryParse(result.Request.Success, out bool success));
Assert.Equal(isSuccessful, success);

AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityType, entityType.ToString());
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.EntityName, entityName);
AssertContainsCustomDimension(result.CustomDimensions, ContextProperties.RequestTracking.ServiceBus.Endpoint, serviceBusNamespace);
});
});
}
}

private static void AssertContainsCustomDimension(EventsResultDataCustomDimensions customDimensions, string key, string expected)
{
Assert.True(customDimensions.TryGetValue(key, out string actual), $"Cannot find {key} in custom dimensions: {String.Join(", ", customDimensions.Keys)}");
Assert.Equal(expected, actual);
}
}
}

0 comments on commit 03f6ff8

Please sign in to comment.