diff --git a/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs b/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs index 81f6f4d5..1d60c6cb 100644 --- a/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs +++ b/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs @@ -1272,6 +1272,37 @@ public static void LogAzureSearchDependency( LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, measurement.StartTime, measurement.Elapsed, context); } + /// + /// Logs an Azure Search Dependency. + /// + /// The logger to track the telemetry. + /// The name of the Azure Search service. + /// The name of the operation to execute on the Azure Search service. + /// The indication whether or not the operation was successful. + /// The measuring the latency to call the dependency. + /// The ID of the dependency to link as parent ID. + /// The context that provides more insights on the dependency that was measured. + /// Thrown when the or is null. + /// Thrown when the or is blank. + public static void LogAzureSearchDependency( + this ILogger logger, + string searchServiceName, + string operationName, + bool isSuccessful, + DurationMeasurement measurement, + string dependencyId, + Dictionary context = null) + { + Guard.NotNull(logger, nameof(logger), "Requires a logger instance to track the Azure Search dependency"); + Guard.NotNullOrWhitespace(searchServiceName, nameof(searchServiceName), "Requires a non-blank name for the Azure Search service to track the Azure Service dependency"); + Guard.NotNullOrWhitespace(operationName, nameof(operationName), "Requires a non-blank name for the Azure Search service to track the Azure Service dependency"); + Guard.NotNull(measurement, nameof(measurement), "Requires a dependency measurement instance to track the latency of the Azure Search resource when tracking the Azure Search dependency"); + + context = context ?? new Dictionary(); + + LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, measurement.StartTime, measurement.Elapsed, dependencyId, context); + } + /// /// Logs an Azure Search Dependency. /// @@ -1300,10 +1331,44 @@ public static void LogAzureSearchDependency( context = context ?? new Dictionary(); + LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId: null, context); + } + + /// + /// Logs an Azure Search Dependency. + /// + /// The logger to track the telemetry. + /// Name of the Azure Search service + /// Name of the operation to execute on the Azure Search service + /// Indication whether or not the operation was successful + /// Point in time when the interaction with the HTTP dependency was started + /// Duration of the operation + /// The ID of the dependency to link as parent ID. + /// Context that provides more insights on the dependency that was measured + /// Thrown when the is null. + /// Thrown when the or is blank. + public static void LogAzureSearchDependency( + this ILogger logger, + string searchServiceName, + string operationName, + bool isSuccessful, + DateTimeOffset startTime, + TimeSpan duration, + string dependencyId, + Dictionary context = null) + { + Guard.NotNull(logger, nameof(logger), "Requires a logger instance to track telemetry"); + Guard.NotNullOrWhitespace(searchServiceName, nameof(searchServiceName), "Requires a non-blank name for the Azure Search service to track the Azure Service dependency"); + Guard.NotNullOrWhitespace(operationName, nameof(operationName), "Requires a non-blank name for the Azure Search service to track the Azure Service dependency"); + Guard.NotLessThan(duration, TimeSpan.Zero, nameof(duration), "Requires a positive time duration of the Azure Search operation"); + + context = context ?? new Dictionary(); + logger.LogWarning(DependencyFormat, new DependencyLogEntry( dependencyType: "Azure Search", dependencyName: searchServiceName, dependencyData: operationName, + dependencyId: dependencyId, targetName: searchServiceName, duration: duration, startTime: startTime, diff --git a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/AzureSearchDependencyTests.cs b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/AzureSearchDependencyTests.cs index 5294701a..b7b6b874 100644 --- a/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/AzureSearchDependencyTests.cs +++ b/src/Arcus.Observability.Tests.Integration/Serilog/Sinks/ApplicationInsights/AzureSearchDependencyTests.cs @@ -29,6 +29,7 @@ public async Task LogAzureSearchDependency_SinksToApplicationInsights_ResultsInA string searchServiceName = BogusGenerator.Commerce.Product(); string operationName = BogusGenerator.Commerce.ProductName(); string dependencyName = searchServiceName; + string dependencyId = BogusGenerator.Lorem.Word(); using (ILoggerFactory loggerFactory = CreateLoggerFactory()) { @@ -40,7 +41,7 @@ public async Task LogAzureSearchDependency_SinksToApplicationInsights_ResultsInA Dictionary telemetryContext = CreateTestTelemetryContext(); // Act - logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, telemetryContext); + logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId, telemetryContext); } // Assert @@ -54,6 +55,7 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => Assert.Contains(results.Value, result => { return result.Dependency.Type == dependencyType + && result.Dependency.Id == dependencyId && result.Dependency.Target == searchServiceName && result.Dependency.Data == operationName && result.Dependency.Name == dependencyName; @@ -61,20 +63,31 @@ await RetryAssertUntilTelemetryShouldBeAvailableAsync(async () => }); } - AssertX.Any(GetLogEventsFromMemory(), logEvent => { + AssertSerilogLogProperties(dependencyType, operationName, searchServiceName, dependencyName); + } + + private void AssertSerilogLogProperties( + string dependencyType, + string operationName, + string searchServiceName, + string dependencyName) + { + IEnumerable logEvents = GetLogEventsFromMemory(); + AssertX.Any(logEvents, logEvent => + { StructureValue logEntry = logEvent.Properties.GetAsStructureValue(ContextProperties.DependencyTracking.DependencyLogEntry); Assert.NotNull(logEntry); - var actualDependencyType = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyType)); + LogEventProperty actualDependencyType = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyType)); Assert.Equal(dependencyType, actualDependencyType.Value.ToDecentString()); - var actualDependencyData = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyData)); + LogEventProperty actualDependencyData = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyData)); Assert.Equal(operationName, actualDependencyData.Value.ToDecentString()); - var actualTargetName = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.TargetName)); + LogEventProperty actualTargetName = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.TargetName)); Assert.Equal(searchServiceName, actualTargetName.Value.ToDecentString()); - var actualDependencyName = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyName)); + LogEventProperty actualDependencyName = Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.DependencyName)); Assert.Equal(dependencyName, actualDependencyName.Value.ToDecentString()); Assert.Single(logEntry.Properties, prop => prop.Name == nameof(DependencyLogEntry.Context)); diff --git a/src/Arcus.Observability.Tests.Unit/Telemetry/ILoggerExtensionsTests.cs b/src/Arcus.Observability.Tests.Unit/Telemetry/ILoggerExtensionsTests.cs index e8f2bbe5..8e8e9987 100644 --- a/src/Arcus.Observability.Tests.Unit/Telemetry/ILoggerExtensionsTests.cs +++ b/src/Arcus.Observability.Tests.Unit/Telemetry/ILoggerExtensionsTests.cs @@ -1147,7 +1147,7 @@ public void LogAzureSearchDependency_ValidArguments_Succeeds() } [Fact] - public void LogAzureSearchDependencyWithDependencyMeasurement_WithNegativeDuration_Fails() + public void LogAzureSearchDependency_WithNegativeDuration_Fails() { // Arrange var logger = new TestLogger(); @@ -1160,7 +1160,84 @@ public void LogAzureSearchDependencyWithDependencyMeasurement_WithNegativeDurati // Act / Assert Assert.ThrowsAny(() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration)); } - + + [Fact] + public void LogAzureSearchDependencyWithDependencyId_ValidArguments_Succeeds() + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Lorem.Word(); + string operationName = _bogusGenerator.Lorem.Word(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DateTimeOffset startTime = _bogusGenerator.Date.RecentOffset(); + TimeSpan duration = _bogusGenerator.Date.Timespan(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act + logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId); + + // Assert + DependencyLogEntry dependency = logger.GetMessageAsDependency(); + Assert.Equal(searchServiceName, dependency.DependencyName); + Assert.Equal(operationName, dependency.DependencyData); + Assert.Equal(isSuccessful, dependency.IsSuccessful); + Assert.Equal(startTime.ToString(FormatSpecifiers.InvariantTimestampFormat), dependency.StartTime); + Assert.Equal(duration, dependency.Duration); + Assert.Equal(dependencyId, dependency.DependencyId); + Assert.Equal("Azure Search", dependency.DependencyType); + Assert.Equal(searchServiceName, dependency.TargetName); + } + + [Theory] + [ClassData(typeof(Blanks))] + public void LogAzureSearchDependencyWithDependencyId_WithoutSearchServiceName_Fails(string searchServiceName) + { + // Arrange + var logger = new TestLogger(); + string operationName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DateTimeOffset startTime = _bogusGenerator.Date.RecentOffset(); + TimeSpan duration = GeneratePositiveDuration(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny( + () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId)); + } + + [Theory] + [ClassData(typeof(Blanks))] + public void LogAzureSearchDependencyWithDependencyId_WithoutOperationName_Fails(string operationName) + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DateTimeOffset startTime = _bogusGenerator.Date.RecentOffset(); + TimeSpan duration = GeneratePositiveDuration(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny( + () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId)); + } + + [Fact] + public void LogAzureSearchDependencyWithDependencyId_WithNegativeDuration_Fails() + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Commerce.Product(); + string operationName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DateTimeOffset startTime = _bogusGenerator.Date.RecentOffset(); + TimeSpan duration = GeneratePositiveDuration().Negate(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny(() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId)); + } + [Fact] public void LogAzureSearchDependencyWithDependencyMeasurement_ValidArguments_Succeeds() { @@ -1217,6 +1294,33 @@ public void LogAzureSearchDependencyWithDurationMeasurement_ValidArguments_Succe Assert.Contains("Azure Search " + dependencyName, logMessage); } + [Fact] + public void LogAzureSearchDependencyWithDependencyIdWithDurationMeasurement_ValidArguments_Succeeds() + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Lorem.Word(); + string operationName = _bogusGenerator.Lorem.Word(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + string dependencyId = _bogusGenerator.Lorem.Word(); + DurationMeasurement measurement = DurationMeasurement.Start(); + measurement.Dispose(); + + // Act + logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement, dependencyId); + + // Assert + DependencyLogEntry dependency = logger.GetMessageAsDependency(); + Assert.Equal(searchServiceName, dependency.DependencyName); + Assert.Equal(operationName, dependency.DependencyData); + Assert.Equal(isSuccessful, dependency.IsSuccessful); + Assert.Equal(measurement.StartTime.ToString(FormatSpecifiers.InvariantTimestampFormat), dependency.StartTime); + Assert.Equal(measurement.Elapsed, dependency.Duration); + Assert.Equal(dependencyId, dependency.DependencyId); + Assert.Equal("Azure Search", dependency.DependencyType); + Assert.Equal(searchServiceName, dependency.TargetName); + } + [Theory] [ClassData(typeof(Blanks))] public void LogAzureSearchDependencyWithDurationMeasurement_WithoutSearchServiceName_Fails(string searchServiceName) @@ -1233,6 +1337,23 @@ public void LogAzureSearchDependencyWithDurationMeasurement_WithoutSearchService () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement)); } + [Theory] + [ClassData(typeof(Blanks))] + public void LogAzureSearchDependencyWithDependencyIdWithDurationMeasurement_WithoutSearchServiceName_Fails(string searchServiceName) + { + // Arrange + var logger = new TestLogger(); + string operationName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DurationMeasurement measurement = DurationMeasurement.Start(); + measurement.Dispose(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny( + () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement, dependencyId)); + } + [Theory] [ClassData(typeof(Blanks))] public void LogAzureSearchDependencyWithDurationMeasurement_WithoutOperationName_Fails(string operationName) @@ -1249,6 +1370,23 @@ public void LogAzureSearchDependencyWithDurationMeasurement_WithoutOperationName () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement)); } + [Theory] + [ClassData(typeof(Blanks))] + public void LogAzureSearchDependencyWithDependencyIdWithDurationMeasurement_WithoutOperationName_Fails(string operationName) + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + DurationMeasurement measurement = DurationMeasurement.Start(); + measurement.Dispose(); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny( + () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement, dependencyId)); + } + [Fact] public void LogAzureSearchDependencyWithDurationMeasurement_WithoutMeasurement_Fails() { @@ -1263,6 +1401,21 @@ public void LogAzureSearchDependencyWithDurationMeasurement_WithoutMeasurement_F () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement: (DurationMeasurement) null)); } + [Fact] + public void LogAzureSearchDependencyWithDependencyIdWithDurationMeasurement_WithoutMeasurement_Fails() + { + // Arrange + var logger = new TestLogger(); + string searchServiceName = _bogusGenerator.Commerce.ProductName(); + string operationName = _bogusGenerator.Commerce.ProductName(); + bool isSuccessful = _bogusGenerator.PickRandom(true, false); + string dependencyId = _bogusGenerator.Lorem.Word(); + + // Act / Assert + Assert.ThrowsAny( + () => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement: (DurationMeasurement) null, dependencyId)); + } + [Fact] public void LogServiceBusDependency_ValidArguments_Succeeds() {