Skip to content

Commit

Permalink
feat: add dependency id to az search (#345)
Browse files Browse the repository at this point in the history 
* feat: add dependency id to az search

* pr-style: remove unnecessary blank line

* pr-fix: add dependency ID to unit test assertions
  • Loading branch information
@stijnmoreels
stijnmoreels authored Mar 22, 2022
1 parent 465670d commit f5c11a2
Show file tree
Hide file tree
Showing 3 changed files with 239 additions and 8 deletions.
65 changes: 65 additions & 0 deletions src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1272,6 +1272,37 @@ public static void LogAzureSearchDependency(
LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, measurement.StartTime, measurement.Elapsed, context);
}

/// <summary>
/// Logs an Azure Search Dependency.
/// </summary>
/// <param name="logger">The logger to track the telemetry.</param>
/// <param name="searchServiceName">The name of the Azure Search service.</param>
/// <param name="operationName">The name of the operation to execute on the Azure Search service.</param>
/// <param name="isSuccessful">The indication whether or not the operation was successful.</param>
/// <param name="measurement">The measuring the latency to call the dependency.</param>
/// <param name="dependencyId">The ID of the dependency to link as parent ID.</param>
/// <param name="context">The context that provides more insights on the dependency that was measured.</param>
/// <exception cref="ArgumentNullException">Thrown when the <paramref name="logger"/> or <paramref name="measurement"/> is <c>null</c>.</exception>
/// <exception cref="ArgumentException">Thrown when the <paramref name="searchServiceName"/> or <paramref name="operationName"/> is blank.</exception>
public static void LogAzureSearchDependency(
this ILogger logger,
string searchServiceName,
string operationName,
bool isSuccessful,
DurationMeasurement measurement,
string dependencyId,
Dictionary<string, object> 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<string, object>();

LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, measurement.StartTime, measurement.Elapsed, dependencyId, context);
}

/// <summary>
/// Logs an Azure Search Dependency.
/// </summary>
Expand Down Expand Up @@ -1300,10 +1331,44 @@ public static void LogAzureSearchDependency(

context = context ?? new Dictionary<string, object>();

LogAzureSearchDependency(logger, searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId: null, context);
}

/// <summary>
/// Logs an Azure Search Dependency.
/// </summary>
/// <param name="logger">The logger to track the telemetry.</param>
/// <param name="searchServiceName">Name of the Azure Search service</param>
/// <param name="operationName">Name of the operation to execute on the Azure Search service</param>
/// <param name="isSuccessful">Indication whether or not the operation was successful</param>
/// <param name="startTime">Point in time when the interaction with the HTTP dependency was started</param>
/// <param name="duration">Duration of the operation</param>
/// <param name="dependencyId">The ID of the dependency to link as parent ID.</param>
/// <param name="context">Context that provides more insights on the dependency that was measured</param>
/// <exception cref="ArgumentNullException">Thrown when the <paramref name="logger"/> is <c>null</c>.</exception>
/// <exception cref="ArgumentException">Thrown when the <paramref name="searchServiceName"/> or <paramref name="operationName"/> is blank.</exception>
public static void LogAzureSearchDependency(
this ILogger logger,
string searchServiceName,
string operationName,
bool isSuccessful,
DateTimeOffset startTime,
TimeSpan duration,
string dependencyId,
Dictionary<string, object> 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<string, object>();

logger.LogWarning(DependencyFormat, new DependencyLogEntry(
dependencyType: "Azure Search",
dependencyName: searchServiceName,
dependencyData: operationName,
dependencyId: dependencyId,
targetName: searchServiceName,
duration: duration,
startTime: startTime,
Expand Down
25 changes: 19 additions & 6 deletions ...ability.Tests.Integration/Serilog/Sinks/ApplicationInsights/AzureSearchDependencyTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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())
{
Expand All @@ -40,7 +41,7 @@ public async Task LogAzureSearchDependency_SinksToApplicationInsights_ResultsInA
Dictionary<string, object> telemetryContext = CreateTestTelemetryContext();

// Act
logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, telemetryContext);
logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId, telemetryContext);
}

// Assert
Expand All @@ -54,27 +55,39 @@ 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;
});
});
}

AssertX.Any(GetLogEventsFromMemory(), logEvent => {
AssertSerilogLogProperties(dependencyType, operationName, searchServiceName, dependencyName);
}

private void AssertSerilogLogProperties(
string dependencyType,
string operationName,
string searchServiceName,
string dependencyName)
{
IEnumerable<LogEvent> 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));
Expand Down
157 changes: 155 additions & 2 deletions src/Arcus.Observability.Tests.Unit/Telemetry/ILoggerExtensionsTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand All @@ -1160,7 +1160,84 @@ public void LogAzureSearchDependencyWithDependencyMeasurement_WithNegativeDurati
// Act / Assert
Assert.ThrowsAny<ArgumentException>(() => 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<ArgumentException>(
() => 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<ArgumentException>(
() => 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<ArgumentException>(() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, startTime, duration, dependencyId));
}

[Fact]
public void LogAzureSearchDependencyWithDependencyMeasurement_ValidArguments_Succeeds()
{
Expand Down Expand Up @@ -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)
Expand All @@ -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<ArgumentException>(
() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement, dependencyId));
}

[Theory]
[ClassData(typeof(Blanks))]
public void LogAzureSearchDependencyWithDurationMeasurement_WithoutOperationName_Fails(string operationName)
Expand All @@ -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<ArgumentException>(
() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement, dependencyId));
}

[Fact]
public void LogAzureSearchDependencyWithDurationMeasurement_WithoutMeasurement_Fails()
{
Expand All @@ -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<ArgumentException>(
() => logger.LogAzureSearchDependency(searchServiceName, operationName, isSuccessful, measurement: (DurationMeasurement) null, dependencyId));
}

[Fact]
public void LogServiceBusDependency_ValidArguments_Succeeds()
{
Expand Down

0 comments on commit f5c11a2

Please sign in to comment.