diff --git a/docs/preview/02-Features/sinks/azure-application-insights.md b/docs/preview/02-Features/sinks/azure-application-insights.md index 2b066c2d..722eb8d9 100644 --- a/docs/preview/02-Features/sinks/azure-application-insights.md +++ b/docs/preview/02-Features/sinks/azure-application-insights.md @@ -45,6 +45,25 @@ ILogger logger = new LoggerConfiguration() The Azure Application Insights sink has some additional configuration which can be changed to influence the tracking. +### Requests + +### Request ID + +When tracking requests, the ID for the request telemetry is by default a generated GUID. The generation of this ID can be configured via the options. +This is useful (for example) in a service-to-service correlation system where you want the ID of the incoming request to be based on the sending system, or you want to incorporate the operation ID in the request ID. + +```csharp +using Serilog; +using Serilog.Configuration; + +ILogger logger = new LoggerConfiguration() + .WriteTo.AzureApplicationInsights("", options => + { + // Configurable generation function for the telemetry request ID. + options.Request.GenerateId = () => $"my-custom-ID-{Guid.NewGuid()}"; + }) +``` + ### Exceptions #### Properties diff --git a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkOptions.cs b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkOptions.cs index 59b35292..1ebbea92 100644 --- a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkOptions.cs +++ b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkOptions.cs @@ -5,6 +5,11 @@ /// public class ApplicationInsightsSinkOptions { + /// + /// Gets the Application Insights options related to tracking requests. + /// + public ApplicationInsightsSinkRequestOptions Request { get; } = new ApplicationInsightsSinkRequestOptions(); + /// /// Gets the Application Insights options related to tracking exceptions. /// diff --git a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkRequestOptions.cs b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkRequestOptions.cs new file mode 100644 index 00000000..34664298 --- /dev/null +++ b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Configuration/ApplicationInsightsSinkRequestOptions.cs @@ -0,0 +1,28 @@ +using System; +using GuardNet; + +namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Configuration +{ + /// + /// User-defined configuration options to influence the behavior of the Azure Application Insights Serilog sink while tracking requests. + /// + public class ApplicationInsightsSinkRequestOptions + { + private Func _generatedId = Guid.NewGuid().ToString; + + /// + /// Gets or sets the function to generate the request ID of the telemetry model while tracking requests. + /// Default: GUID generation. + /// + /// Thrown when the is null. + public Func GenerateId + { + get => _generatedId; + set + { + Guard.NotNull(value, nameof(value), "Requires a function to generate the request ID of the telemetry model while tracking requests"); + _generatedId = value; + } + } + } +} diff --git a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ApplicationInsightsTelemetryConverter.cs b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ApplicationInsightsTelemetryConverter.cs index 4b762cb0..ea48dc88 100644 --- a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ApplicationInsightsTelemetryConverter.cs +++ b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/ApplicationInsightsTelemetryConverter.cs @@ -15,16 +15,17 @@ namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Conver /// public class ApplicationInsightsTelemetryConverter : TelemetryConverterBase { + private readonly RequestTelemetryConverter _requestTelemetryConverter; private readonly ExceptionTelemetryConverter _exceptionTelemetryConverter; private readonly TraceTelemetryConverter _traceTelemetryConverter = new TraceTelemetryConverter(); private readonly EventTelemetryConverter _eventTelemetryConverter = new EventTelemetryConverter(); private readonly MetricTelemetryConverter _metricTelemetryConverter = new MetricTelemetryConverter(); - private readonly RequestTelemetryConverter _requestTelemetryConverter = new RequestTelemetryConverter(); private readonly DependencyTelemetryConverter _dependencyTelemetryConverter = new DependencyTelemetryConverter(); private ApplicationInsightsTelemetryConverter(ApplicationInsightsSinkOptions options) { Guard.NotNull(options, nameof(options), "Requires a set of options to influence how to track to Application Insights"); + _requestTelemetryConverter = new RequestTelemetryConverter(options.Request); _exceptionTelemetryConverter = new ExceptionTelemetryConverter(options.Exception); } diff --git a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/RequestTelemetryConverter.cs b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/RequestTelemetryConverter.cs index 0ae2d72f..a7865430 100644 --- a/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/RequestTelemetryConverter.cs +++ b/src/Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/RequestTelemetryConverter.cs @@ -2,6 +2,7 @@ using System.Collections.Generic; using Arcus.Observability.Telemetry.Core; using Arcus.Observability.Telemetry.Core.Logging; +using Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Configuration; using GuardNet; using Microsoft.ApplicationInsights.DataContracts; using Serilog.Events; @@ -13,6 +14,27 @@ namespace Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Conver /// public class RequestTelemetryConverter : CustomTelemetryConverter { + private ApplicationInsightsSinkRequestOptions _options; + + /// + /// Initializes a new instance of the class. + /// + public RequestTelemetryConverter() + : this(new ApplicationInsightsSinkRequestOptions()) + { + } + + /// + /// Initializes a new instance of the class. + /// + /// The user-defined configuration options to tracking requests. + /// Thrown when the is null. + public RequestTelemetryConverter(ApplicationInsightsSinkRequestOptions options) + { + Guard.NotNull(options, nameof(options), "Requires a set of user-configurable options to influence the behavior of how requests are tracked"); + _options = options; + } + /// /// Creates a telemetry entry for a given log event /// @@ -34,7 +56,7 @@ protected override RequestTelemetry CreateTelemetryEntry(LogEvent logEvent, IFor DateTimeOffset requestTime = logEntry.Properties.GetAsDateTimeOffset(nameof(RequestLogEntry.RequestTime)); IDictionary context = logEntry.Properties.GetAsDictionary(nameof(RequestLogEntry.Context)); - string operationId = logEvent.Properties.GetAsRawString(ContextProperties.Correlation.OperationId); + string id = _options.GenerateId(); var requestName = $"{requestMethod} {requestUri}"; bool isSuccessfulRequest = DetermineRequestOutcome(responseStatusCode); @@ -42,11 +64,10 @@ protected override RequestTelemetry CreateTelemetryEntry(LogEvent logEvent, IFor var requestTelemetry = new RequestTelemetry(requestName, requestTime, requestDuration, responseStatusCode, isSuccessfulRequest) { - Id = operationId, + Id = id, Url = url }; - // Add requestMethod to the operationName if it is missing if (!operationName.StartsWith(requestMethod)) { requestTelemetry.Context.Operation.Name = $"{requestMethod} {operationName}"; diff --git a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs index 6fea5a71..43879d88 100644 --- a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs +++ b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs @@ -85,7 +85,7 @@ protected async Task RetryAssertUntilTelemetryShouldBeAvailableAsync(Func await Policy.TimeoutAsync(timeout) .WrapAsync(Policy.Handle(exception => { - _outputWriter.WriteLine($"Failed to contact Azure Application Insights. Reason: {exception.Message}"); + _outputWriter.WriteLine($"Failed to find correct telemetry at Azure Application Insights. Reason: {exception.Message}"); return true; }) .WaitAndRetryForeverAsync(index => TimeSpan.FromSeconds(3))) diff --git a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/RequestTests.cs b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/RequestTests.cs index f44b39ee..c7512d50 100644 --- a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/RequestTests.cs +++ b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/RequestTests.cs @@ -1,6 +1,5 @@ using System; using System.Collections.Generic; -using System.Linq; using System.Net; using System.Net.Http; using System.Threading.Tasks; @@ -24,20 +23,19 @@ public RequestTests(ITestOutputHelper outputWriter) : base(outputWriter) } [Fact] - public async Task LogRequest_SinksToApplicationInsightsWithoutOperationName_ResultsInRequestTelemetry() + public async Task LogRequest_SinksToApplicationInsightsWithoutOperationNameAndCustomId_ResultsInRequestTelemetry() { // Arrange HttpMethod httpMethod = GenerateHttpMethod(); var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); HttpRequest request = CreateStubRequest(httpMethod, requestUri.Scheme, requestUri.Host, requestUri.AbsolutePath); - + var statusCode = BogusGenerator.PickRandom(); + using (ILoggerFactory loggerFactory = CreateLoggerFactory()) { ILogger logger = loggerFactory.CreateLogger(); - var statusCode = BogusGenerator.PickRandom(); HttpResponse response = CreateStubResponse(statusCode); - TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); @@ -52,8 +50,13 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}"); - Assert.Contains(results.Value, result => !String.IsNullOrEmpty(result.Operation.Name)); + Assert.Contains(results.Value, result => + { + return result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}" + && result.Request.ResultCode == ((int) statusCode).ToString() + && Guid.TryParse(result.Request.Id, out Guid _) + && result.Operation.Name.StartsWith(httpMethod.Method); + }); }); } @@ -61,21 +64,20 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => } [Fact] - public async Task LogRequest_SinksToApplicationInsightsWithOperationName_ResultsInRequestTelemetry() + public async Task LogRequest_SinksToApplicationInsightsWithOperationNameWithoutCustomId_ResultsInRequestTelemetry() { // Arrange string operationName = "sampleoperation"; HttpMethod httpMethod = GenerateHttpMethod(); var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); HttpRequest request = CreateStubRequest(httpMethod, requestUri.Scheme, requestUri.Host, requestUri.AbsolutePath); - + var statusCode = BogusGenerator.PickRandom(); + using (ILoggerFactory loggerFactory = CreateLoggerFactory()) { ILogger logger = loggerFactory.CreateLogger(); - var statusCode = BogusGenerator.PickRandom(); HttpResponse response = CreateStubResponse(statusCode); - TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); @@ -90,8 +92,13 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}"); - Assert.Contains(results.Value, result => result.Operation.Name == $"{httpMethod} {operationName}"); + Assert.Contains(results.Value, result => + { + return result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}" + && result.Request.ResultCode == ((int) statusCode).ToString() + && Guid.TryParse(result.Request.Id, out Guid _) + && result.Operation.Name == $"{httpMethod} {operationName}"; + }); }); } @@ -99,20 +106,20 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => } [Fact] - public async Task LogRequest_SinksToApplicationInsightsWithResponse_ResultsInRequestTelemetry() + public async Task LogRequest_SinksToApplicationInsightsWithResponseStatusCodeWithoutOperationNameWithCustomId_ResultsInRequestTelemetry() { // Arrange HttpMethod httpMethod = GenerateHttpMethod(); - var requestUri = new Uri(BogusGenerator.Internet.Url()); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); HttpRequest request = CreateStubRequest(httpMethod, requestUri.Scheme, requestUri.Host, requestUri.AbsolutePath); - - using (ILoggerFactory loggerFactory = CreateLoggerFactory()) + var statusCode = BogusGenerator.PickRandom(); + var requestId = Guid.NewGuid().ToString(); + + using (ILoggerFactory loggerFactory = CreateLoggerFactory(configureOptions: options => options.Request.GenerateId = () => requestId)) { ILogger logger = loggerFactory.CreateLogger(); - - var statusCode = BogusGenerator.PickRandom(); + HttpResponse response = CreateStubResponse(statusCode); - TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); @@ -127,7 +134,13 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}"); + Assert.Contains(results.Value, result => + { + return result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}" + && result.Request.ResultCode == ((int) statusCode).ToString() + && result.Request.Id == requestId + && result.Operation.Name.StartsWith(httpMethod.Method); + }); }); } @@ -135,23 +148,66 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => } [Fact] - public async Task LogRequest_SinksToApplicationInsightsWithResponseStatusCode_ResultsInRequestTelemetry() + public async Task LogRequest_SinksToApplicationInsightsWithResponseStatusCodeWithOperationNameAndCustomId_ResultsInRequestTelemetry() { // Arrange + string operationName = "sampleoperation"; HttpMethod httpMethod = GenerateHttpMethod(); - var requestUri = new Uri(BogusGenerator.Internet.Url()); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); HttpRequest request = CreateStubRequest(httpMethod, requestUri.Scheme, requestUri.Host, requestUri.AbsolutePath); + var statusCode = BogusGenerator.PickRandom(); + var requestId = Guid.NewGuid().ToString(); + + using (ILoggerFactory loggerFactory = CreateLoggerFactory(configureOptions: options => options.Request.GenerateId = () => requestId)) + { + ILogger logger = loggerFactory.CreateLogger(); - using (ILoggerFactory loggerFactory = CreateLoggerFactory()) + TimeSpan duration = BogusGenerator.Date.Timespan(); + Dictionary telemetryContext = CreateTestTelemetryContext(); + + // Act + logger.LogRequest(request, (int) statusCode, operationName, duration, telemetryContext); + } + + // Assert + using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient()) + { + await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => + { + EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); + Assert.NotEmpty(results.Value); + Assert.Contains(results.Value, result => + { + return result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}" + && result.Request.ResultCode == ((int) statusCode).ToString() + && result.Request.Id == requestId + && result.Operation.Name == $"{httpMethod.Method} {operationName}"; + }); + }); + } + + VerifyLogEventProperties(requestUri); + } + + [Fact] + public async Task LogRequestMessage_SinksToApplicationInsightsWithResponseWithoutOperationNameWithCustomId_ResultsInRequestTelemetry() + { + // Arrange + HttpMethod httpMethod = GenerateHttpMethod(); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); + var statusCode = BogusGenerator.PickRandom(); + var requestId = Guid.NewGuid().ToString(); + + using (ILoggerFactory loggerFactory = CreateLoggerFactory(configureOptions: options => options.Request.GenerateId = () => requestId)) { ILogger logger = loggerFactory.CreateLogger(); - var statusCode = BogusGenerator.PickRandom(); + var request = new HttpRequestMessage(httpMethod, requestUri); TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); // Act - logger.LogRequest(request, (int)statusCode, duration, telemetryContext); + logger.LogRequest(request, statusCode, duration, telemetryContext); } // Assert @@ -161,7 +217,13 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == $"{requestUri.Scheme}://{requestUri.Host}{requestUri.AbsolutePath}"); + Assert.Contains(results.Value, result => + { + return result.Request.Url == requestUri.ToString() + && result.Request.ResultCode == ((int) statusCode).ToString() + && result.Request.Id == requestId + && result.Operation.Name.StartsWith(httpMethod.Method); + }); }); } @@ -169,25 +231,26 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => } [Fact] - public async Task LogRequestMessage_SinksToApplicationInsightsWithResponse_ResultsInRequestTelemetry() + public async Task LogRequestMessage_SinksToApplicationInsightsWithResponseWithOperationNameWithoutCustomId_ResultsInRequestTelemetry() { // Arrange - var requestUri = new Uri(BogusGenerator.Internet.Url()); + string operationName = "sampleoperation"; + HttpMethod httpMethod = GenerateHttpMethod(); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); + var statusCode = BogusGenerator.PickRandom(); + using (ILoggerFactory loggerFactory = CreateLoggerFactory()) { ILogger logger = loggerFactory.CreateLogger(); - HttpMethod httpMethod = GenerateHttpMethod(); var request = new HttpRequestMessage(httpMethod, requestUri); - - var statusCode = BogusGenerator.PickRandom(); var response = new HttpResponseMessage(statusCode); - var duration = BogusGenerator.Date.Timespan(); + TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); // Act - logger.LogRequest(request, response, duration, telemetryContext); + logger.LogRequest(request, response, operationName, duration, telemetryContext); } // Assert @@ -197,27 +260,33 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == requestUri.ToString()); + Assert.Contains(results.Value, result => + { + return result.Request.Url == requestUri.ToString() + && result.Request.ResultCode == ((int) statusCode).ToString() + && Guid.TryParse(result.Request.Id, out Guid _) + && result.Operation.Name == $"{httpMethod.Method} {operationName}"; + }); }); } VerifyLogEventProperties(requestUri); } - + [Fact] - public async Task LogRequestMessage_SinksToApplicationInsightsWithResponseStatusCode_ResultsInRequestTelemetry() + public async Task LogRequestMessage_SinksToApplicationInsightsWithResponseStatusCodeWithoutOperationNameAndCustomId_ResultsInRequestTelemetry() { // Arrange - var requestUri = new Uri(BogusGenerator.Internet.Url()); + HttpMethod httpMethod = GenerateHttpMethod(); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); + var statusCode = BogusGenerator.PickRandom(); + using (ILoggerFactory loggerFactory = CreateLoggerFactory()) { ILogger logger = loggerFactory.CreateLogger(); - HttpMethod httpMethod = GenerateHttpMethod(); var request = new HttpRequestMessage(httpMethod, requestUri); - - var statusCode = BogusGenerator.PickRandom(); - var duration = BogusGenerator.Date.Timespan(); + TimeSpan duration = BogusGenerator.Date.Timespan(); Dictionary telemetryContext = CreateTestTelemetryContext(); // Act @@ -231,7 +300,55 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => { EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); Assert.NotEmpty(results.Value); - Assert.Contains(results.Value, result => result.Request.Url == requestUri.ToString()); + Assert.Contains(results.Value, result => + { + return result.Request.Url == requestUri.ToString() + && result.Request.ResultCode == ((int) statusCode).ToString() + && Guid.TryParse(result.Request.Id, out Guid _) + && result.Operation.Name.StartsWith(httpMethod.Method); + }); + }); + } + + VerifyLogEventProperties(requestUri); + } + + [Fact] + public async Task LogRequestMessage_SinksToApplicationInsightsWithResponseStatusCodeWithOperationNameAndCustomId_ResultsInRequestTelemetry() + { + // Arrange + string operationName = "sampleoperation"; + HttpMethod httpMethod = GenerateHttpMethod(); + var requestUri = new Uri(BogusGenerator.Internet.UrlWithPath()); + var statusCode = BogusGenerator.PickRandom(); + var requestId = Guid.NewGuid().ToString(); + + using (ILoggerFactory loggerFactory = CreateLoggerFactory(configureOptions: options => options.Request.GenerateId = () => requestId)) + { + ILogger logger = loggerFactory.CreateLogger(); + + var request = new HttpRequestMessage(httpMethod, requestUri); + TimeSpan duration = BogusGenerator.Date.Timespan(); + Dictionary telemetryContext = CreateTestTelemetryContext(); + + // Act + logger.LogRequest(request, statusCode, operationName, duration, telemetryContext); + } + + // Assert + using (ApplicationInsightsDataClient client = CreateApplicationInsightsClient()) + { + await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => + { + EventsResults results = await client.Events.GetRequestEventsAsync(ApplicationId, filter: OnlyLastHourFilter); + Assert.NotEmpty(results.Value); + Assert.Contains(results.Value, result => + { + return result.Request.Url == requestUri.ToString() + && result.Request.ResultCode == ((int) statusCode).ToString() + && result.Request.Id == requestId + && result.Operation.Name == $"{httpMethod.Method} {operationName}"; + }); }); } @@ -270,15 +387,18 @@ private static HttpResponse CreateStubResponse(HttpStatusCode statusCode) return response.Object; } - private void VerifyLogEventProperties(Uri requestUri){ - AssertX.Any(GetLogEventsFromMemory(), logEvent => { + private void VerifyLogEventProperties(Uri requestUri) + { + IEnumerable logEvents = GetLogEventsFromMemory(); + AssertX.Any(logEvents, logEvent => + { StructureValue logEntry = logEvent.Properties.GetAsStructureValue(ContextProperties.RequestTracking.RequestLogEntry); Assert.NotNull(logEntry); - var actualRequestHost = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(RequestLogEntry.RequestHost)); + LogEventProperty actualRequestHost = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(RequestLogEntry.RequestHost)); Assert.Equal($"{requestUri.Scheme}://{requestUri.Host}", actualRequestHost.Value.ToDecentString()); - var actualRequestUri = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(RequestLogEntry.RequestUri)); + LogEventProperty actualRequestUri = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(RequestLogEntry.RequestUri)); Assert.Equal(requestUri.AbsolutePath, actualRequestUri.Value.ToDecentString()); Assert.Single(logEntry.Properties, prop => prop.Name == nameof(RequestLogEntry.Context)); diff --git a/src/Arcus.Observability.Tests.Unit/Serilog/ApplicationInsightsTelemetryConverterTests.cs b/src/Arcus.Observability.Tests.Unit/Serilog/ApplicationInsightsTelemetryConverterTests.cs index ad6705e2..d1ac81da 100644 --- a/src/Arcus.Observability.Tests.Unit/Serilog/ApplicationInsightsTelemetryConverterTests.cs +++ b/src/Arcus.Observability.Tests.Unit/Serilog/ApplicationInsightsTelemetryConverterTests.cs @@ -7,6 +7,7 @@ using System.Xml.Serialization; using Arcus.Observability.Telemetry.Core; using Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights; +using Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Configuration; using Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Converters; using Arcus.Observability.Tests.Core; using Arcus.Observability.Tests.Unit.Fixture; @@ -74,7 +75,57 @@ public void LogRequestMessage_WithRequestAndResponse_CreatesRequestTelemetry() Assert.Equal(duration, requestTelemetry.Duration); Assert.Equal(((int)statusCode).ToString(), requestTelemetry.ResponseCode); Assert.True(requestTelemetry.Success); - Assert.Equal(operationId, requestTelemetry.Id); + Assert.True(Guid.TryParse(requestTelemetry.Id, out Guid _)); + Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); + AssertOperationContext(requestTelemetry, operationId); + + AssertContainsTelemetryProperty(requestTelemetry, "Client", "https://localhost"); + AssertContainsTelemetryProperty(requestTelemetry, "ContentType", "application/json"); + }); + } + + [Fact] + public void LogRequestMessage_WithRequestAndResponseWithCustomId_CreatesRequestTelemetry() + { + // Arrange + var spySink = new InMemoryLogSink(); + string operationId = $"operation-id-{Guid.NewGuid()}"; + ILogger logger = CreateLogger( + spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId)); + + var telemetryContext = new Dictionary + { + ["Client"] = "https://localhost", + ["ContentType"] = "application/json", + }; + var request = new HttpRequestMessage(System.Net.Http.HttpMethod.Get, new Uri("https://" + "localhost" + "/api/v1/health")); + var statusCode = HttpStatusCode.OK; + var response = new HttpResponseMessage(statusCode); + TimeSpan duration = TimeSpan.FromSeconds(5); + logger.LogRequest(request, response, duration, telemetryContext); + + LogEvent logEvent = Assert.Single(spySink.CurrentLogEmits); + Assert.NotNull(logEvent); + + var requestId = Guid.NewGuid().ToString(); + var converter = ApplicationInsightsTelemetryConverter.Create(new ApplicationInsightsSinkOptions + { + Request = { GenerateId = () => requestId } + }); + + // Act + IEnumerable telemetries = converter.Convert(logEvent, formatProvider: null); + + // Assert + AssertDoesContainLogProperty(logEvent, RequestTracking.RequestLogEntry); + Assert.Collection(telemetries, telemetry => + { + var requestTelemetry = Assert.IsType(telemetry); + Assert.Equal("GET /api/v1/health", requestTelemetry.Name); + Assert.Equal(duration, requestTelemetry.Duration); + Assert.Equal(((int) statusCode).ToString(), requestTelemetry.ResponseCode); + Assert.True(requestTelemetry.Success); + Assert.Equal(requestId, requestTelemetry.Id); Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); AssertOperationContext(requestTelemetry, operationId); @@ -121,9 +172,58 @@ public void LogRequestMessage_WithRequestAndResponseStatusCode_CreatesRequestTel var requestTelemetry = Assert.IsType(telemetry); Assert.Equal("GET /api/v1/health", requestTelemetry.Name); Assert.Equal(duration, requestTelemetry.Duration); - Assert.Equal(((int)statusCode).ToString(), requestTelemetry.ResponseCode); + Assert.Equal(((int) statusCode).ToString(), requestTelemetry.ResponseCode); + Assert.True(requestTelemetry.Success); + Assert.True(Guid.TryParse(requestTelemetry.Id, out Guid _)); + Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); + AssertOperationContext(requestTelemetry, operationId); + + AssertContainsTelemetryProperty(requestTelemetry, "Client", "https://localhost"); + AssertContainsTelemetryProperty(requestTelemetry, "ContentType", "application/json"); + }); + } + + [Fact] + public void LogRequestMessage_WithRequestAndResponseStatusCodeWithCustomId_CreatesRequestTelemetry() + { + // Arrange + var spySink = new InMemoryLogSink(); + string operationId = $"operation-id-{Guid.NewGuid()}"; + ILogger logger = CreateLogger( + spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId)); + + var telemetryContext = new Dictionary + { + ["Client"] = "https://localhost", + ["ContentType"] = "application/json", + }; + var request = new HttpRequestMessage(System.Net.Http.HttpMethod.Get, new Uri("https://" + "localhost" + "/api/v1/health")); + var statusCode = HttpStatusCode.OK; + TimeSpan duration = TimeSpan.FromSeconds(5); + logger.LogRequest(request, statusCode, duration, telemetryContext); + + LogEvent logEvent = Assert.Single(spySink.CurrentLogEmits); + Assert.NotNull(logEvent); + + var requestId = Guid.NewGuid().ToString(); + var converter = ApplicationInsightsTelemetryConverter.Create(new ApplicationInsightsSinkOptions + { + Request = { GenerateId = () => requestId } + }); + + // Act + IEnumerable telemetries = converter.Convert(logEvent, formatProvider: null); + + // Assert + AssertDoesContainLogProperty(logEvent, RequestTracking.RequestLogEntry); + Assert.Collection(telemetries, telemetry => + { + var requestTelemetry = Assert.IsType(telemetry); + Assert.Equal("GET /api/v1/health", requestTelemetry.Name); + Assert.Equal(duration, requestTelemetry.Duration); + Assert.Equal(((int) statusCode).ToString(), requestTelemetry.ResponseCode); Assert.True(requestTelemetry.Success); - Assert.Equal(operationId, requestTelemetry.Id); + Assert.Equal(requestId, requestTelemetry.Id); Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); AssertOperationContext(requestTelemetry, operationId); @@ -171,9 +271,59 @@ public void LogRequest_WithRequestAndResponse_CreatesRequestTelemetry() var requestTelemetry = Assert.IsType(telemetry); Assert.Equal("GET /api/v1/health", requestTelemetry.Name); Assert.Equal(duration, requestTelemetry.Duration); - Assert.Equal(((int)statusCode).ToString(), requestTelemetry.ResponseCode); + Assert.Equal(((int) statusCode).ToString(), requestTelemetry.ResponseCode); + Assert.True(requestTelemetry.Success); + Assert.True(Guid.TryParse(requestTelemetry.Id, out Guid _)); + Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); + AssertOperationContext(requestTelemetry, operationId); + + AssertContainsTelemetryProperty(requestTelemetry, "Client", "https://localhost"); + AssertContainsTelemetryProperty(requestTelemetry, "ContentType", "application/json"); + }); + } + + [Fact] + public void LogRequest_WithRequestAndResponseWithCustomId_CreatesRequestTelemetry() + { + // Arrange + var spySink = new InMemoryLogSink(); + string operationId = $"operation-id-{Guid.NewGuid()}"; + ILogger logger = CreateLogger( + spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId)); + + var telemetryContext = new Dictionary + { + ["Client"] = "https://localhost", + ["ContentType"] = "application/json", + }; + var statusCode = HttpStatusCode.OK; + HttpRequest request = CreateStubRequest(HttpMethod.Get, "https", "localhost", "/api/v1/health"); + HttpResponse response = CreateStubResponse(statusCode); + TimeSpan duration = TimeSpan.FromSeconds(5); + logger.LogRequest(request, response, duration, telemetryContext); + + LogEvent logEvent = Assert.Single(spySink.CurrentLogEmits); + Assert.NotNull(logEvent); + + var requestId = Guid.NewGuid().ToString(); + var converter = ApplicationInsightsTelemetryConverter.Create(new ApplicationInsightsSinkOptions + { + Request = { GenerateId = () => requestId } + }); + + // Act + IEnumerable telemetries = converter.Convert(logEvent, formatProvider: null); + + // Assert + AssertDoesContainLogProperty(logEvent, RequestTracking.RequestLogEntry); + Assert.Collection(telemetries, telemetry => + { + var requestTelemetry = Assert.IsType(telemetry); + Assert.Equal("GET /api/v1/health", requestTelemetry.Name); + Assert.Equal(duration, requestTelemetry.Duration); + Assert.Equal(((int) statusCode).ToString(), requestTelemetry.ResponseCode); Assert.True(requestTelemetry.Success); - Assert.Equal(operationId, requestTelemetry.Id); + Assert.Equal(requestId, requestTelemetry.Id); Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); AssertOperationContext(requestTelemetry, operationId); @@ -200,7 +350,7 @@ public void LogRequest_WithRequestAndResponseStatusCode_CreatesRequestTelemetry( ["ContentType"] = "application/json", ["RequestBody"] = json }; - var statusCode = (int)HttpStatusCode.OK; + var statusCode = (int) HttpStatusCode.OK; HttpRequest request = CreateStubRequest(HttpMethod.Get, "https", "localhost", "/api/v1/health"); TimeSpan duration = TimeSpan.FromSeconds(5); logger.LogRequest(request, statusCode, duration, telemetryContext); @@ -222,7 +372,56 @@ public void LogRequest_WithRequestAndResponseStatusCode_CreatesRequestTelemetry( Assert.Equal(duration, requestTelemetry.Duration); Assert.Equal(statusCode.ToString(), requestTelemetry.ResponseCode); Assert.True(requestTelemetry.Success); - Assert.Equal(operationId, requestTelemetry.Id); + Assert.True(Guid.TryParse(requestTelemetry.Id, out Guid _)); + Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); + AssertOperationContext(requestTelemetry, operationId); + + AssertContainsTelemetryProperty(requestTelemetry, "Client", "https://localhost"); + AssertContainsTelemetryProperty(requestTelemetry, "ContentType", "application/json"); + }); + } + + [Fact] + public void LogRequest_WithRequestAndResponseStatusCodeWithCustomId_CreatesRequestTelemetry() + { + // Arrange + var spySink = new InMemoryLogSink(); + string operationId = $"operation-id-{Guid.NewGuid()}"; + ILogger logger = CreateLogger( + spySink, config => config.Enrich.WithProperty(ContextProperties.Correlation.OperationId, operationId)); + + var telemetryContext = new Dictionary + { + ["Client"] = "https://localhost", + ["ContentType"] = "application/json", + }; + var statusCode = (int) HttpStatusCode.OK; + HttpRequest request = CreateStubRequest(HttpMethod.Get, "https", "localhost", "/api/v1/health"); + TimeSpan duration = TimeSpan.FromSeconds(5); + logger.LogRequest(request, statusCode, duration, telemetryContext); + + LogEvent logEvent = Assert.Single(spySink.CurrentLogEmits); + Assert.NotNull(logEvent); + + var requestId = Guid.NewGuid().ToString(); + var converter = ApplicationInsightsTelemetryConverter.Create(new ApplicationInsightsSinkOptions() + { + Request = { GenerateId = () => requestId } + }); + + // Act + IEnumerable telemetries = converter.Convert(logEvent, formatProvider: null); + + // Assert + AssertDoesContainLogProperty(logEvent, RequestTracking.RequestLogEntry); + Assert.Collection(telemetries, telemetry => + { + var requestTelemetry = Assert.IsType(telemetry); + Assert.Equal("GET /api/v1/health", requestTelemetry.Name); + Assert.Equal(duration, requestTelemetry.Duration); + Assert.Equal(statusCode.ToString(), requestTelemetry.ResponseCode); + Assert.True(requestTelemetry.Success); + Assert.Equal(requestId, requestTelemetry.Id); Assert.Equal(new Uri("https://localhost/api/v1/health"), requestTelemetry.Url); AssertOperationContext(requestTelemetry, operationId); diff --git a/src/Arcus.Observability.Tests.Unit/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkRequestOptionsTests.cs b/src/Arcus.Observability.Tests.Unit/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkRequestOptionsTests.cs new file mode 100644 index 00000000..64b03fe2 --- /dev/null +++ b/src/Arcus.Observability.Tests.Unit/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkRequestOptionsTests.cs @@ -0,0 +1,46 @@ +using System; +using Arcus.Observability.Telemetry.Serilog.Sinks.ApplicationInsights.Configuration; +using Xunit; + +namespace Arcus.Observability.Tests.Unit.Serilog.Sinks.ApplicationInsights +{ + public class ApplicationInsightsSinkRequestOptionsTests + { + [Fact] + public void DefaultGenerateId_WithNoCustomFunction_Succeeds() + { + // Arrange + var options = new ApplicationInsightsSinkRequestOptions(); + + // Act + string id = options.GenerateId(); + + // Assert + Assert.False(string.IsNullOrWhiteSpace(id)); + } + + [Fact] + public void SetGenerateId_WithCustomFunction_Succeeds() + { + // Arrange + var options = new ApplicationInsightsSinkRequestOptions(); + var id = Guid.NewGuid().ToString(); + + // Act + options.GenerateId = () => id; + + // Assert + Assert.Equal(id, options.GenerateId()); + } + + [Fact] + public void SetGenerateId_WithoutFunction_Fails() + { + // Arrange + var options = new ApplicationInsightsSinkRequestOptions(); + + // Act / Assert + Assert.ThrowsAny(() => options.GenerateId = null); + } + } +}