Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: add dependency ID to az key vault dependency tracking #251

30 changes: 29 additions & 1 deletion docs/preview/02-Features/writing-different-telemetry-types.md
Original file line number Diff line number Diff line change
Expand Up @@ -42,11 +42,12 @@ We provide support for the following dependencies:
- [Azure Search](#measuring-azure-search-dependencies)
- [Azure Service Bus](#measuring-azure-service-bus-dependencies)
- [Azure Table Storage](#measuring-azure-table-storage-dependencies)
- [Custom](#measuring-custom-dependencies)
- [HTTP](#measuring-http-dependencies)
- [SQL](#measuring-sql-dependencies)
- [Custom](#measuring-custom-dependencies)

Since measuring dependencies can add some noise in your code, we've introduced `DependencyMeasurement` to make it simpler. ([docs](#making-it-easier-to-measure-dependencies))
Linking service-to-service correlation can be hard, this can be made easier with including dependency ID's. ([docs](#making-it-easier-to-link-services))

### Measuring Azure Blob Storage dependencies

Expand Down Expand Up @@ -388,6 +389,33 @@ catch (Exception exception)
}
```

### Making it easier to link services

Service-to-service correlation requires linkage between tracked dependencies (outgoing) and requests (incoming).
Tracking any kind of dependency with the library has the possibility to provide an dependency ID. This ID will be needed later when the incoming request is tracked (dependency ID = request's parent ID).
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
Tracking any kind of dependency with the library has the possibility to provide an dependency ID. This ID will be needed later when the incoming request is tracked (dependency ID = request's parent ID).
Tracking any kind of dependency with the library has the possibility to provide a dependency ID. This dependency ID will be needed later when the incoming request is tracked (dependency ID = request's parent ID).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure how to interpret the last sentence ? The (dependency) ID is needed later when the incoming request is tracked. You mean that the dependencyId is used in the logging of the downstream dependency to correlate the request id with the dependency id ?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, something like that. Maybe we should specify that the 'later' part is in the other dependency.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I updated the last sentence with a more thorough explanation. We also need to update the links but that can only be done when #250 is done.


Tracking the outgoing dependency:

```csharp
var durationMeasurement = new StopWatch();

// Start measuring
durationMeasurement.Start();
var startTime = DateTimeOffset.UtcNow;

var trackingId = "75D298F7-99FF-4BB8-8019-230974EB6D1E";

logger.AzureKeyVaultDependency(
vaultUri: "https://my-secret-store.vault.azure.net",
secretName: "ServiceBus-ConnectionString",
isSuccessful: true,
startTime: startTime,
duration: durationMeasurement.Elapsed,
dependencyId: trackingId);

// Output: {"DependencyType": "Azure key vault", "DependencyId": "75D298F7-99FF-4BB8-8019-230974EB6D1E", "DependencyData": "ServiceBus-ConnectionString", "TargetName": "https://my-secret-store.vault.azure.net", "Duration": "00:00:00.2521801", "StartTime": "03/23/2020 09:56:31 +00:00", "IsSuccessful": true, "Context": {}}
```

## Events

Events allow you to report custom events which are a great way to track business-related events.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@ public static class Correlation
public static class DependencyTracking
{
public const string DependencyLogEntry = "Dependency";
public const string DependencyId = "DependencyId";
public const string DependencyType = "DependencyType";
public const string TargetName = "DependencyTargetName";
public const string DependencyName = "DependencyName";
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -493,7 +493,84 @@ public static void LogAzureKeyVaultDependency(
"Requires the Azure Key Vault host to be in the right format, see https://docs.microsoft.com/en-us/azure/key-vault/general/about-keys-secrets-certificates#objects-identifiers-and-versioning");

context = context ?? new Dictionary<string, object>();
LogAzureKeyVaultDependency(logger, vaultUri, secretName, isSuccessful, measurement.StartTime, measurement.Elapsed, context);
LogAzureKeyVaultDependency(logger, vaultUri, secretName, isSuccessful, measurement, dependencyId: null, context);
}

/// <summary>
/// Logs an Azure Key Vault dependency.
/// </summary>
/// <param name="logger">The logger to use.</param>
/// <param name="vaultUri">The URI pointing to the Azure Key Vault resource.</param>
/// <param name="secretName">The secret that is being used within the Azure Key Vault resource.</param>
/// <param name="isSuccessful">Indication whether or not the operation was successful</param>
/// <param name="measurement">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">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="vaultUri"/> or <paramref name="secretName"/> is blank.</exception>
/// <exception cref="FormatException">Thrown when the <paramref name="secretName"/> is not in the correct format.</exception>
/// <exception cref="UriFormatException">Thrown when the <paramref name="vaultUri"/> is not in the correct format.</exception>
public static void LogAzureKeyVaultDependency(
this ILogger logger,
string vaultUri,
string secretName,
bool isSuccessful,
DependencyMeasurement measurement,
string dependencyId,
Dictionary<string, object> context = null)
{
Guard.NotNull(logger, nameof(logger), "Requires an logger instance to write the Azure Key Vault dependency");
Guard.NotNullOrWhitespace(vaultUri, nameof(vaultUri), "Requires a non-blank URI for the Azure Key Vault");
Guard.NotNullOrWhitespace(secretName, nameof(secretName), "Requires a non-blank secret name for the Azure Key Vault");
Guard.NotNull(measurement, nameof(measurement), "Requires a dependency measurement instance to track the latency of the Azure Key Vault when tracking an Azure Key Vault dependency");
Guard.For<FormatException>(
() => !SecretNameRegex.IsMatch(secretName),
"Requires a Azure Key Vault secret name in the correct format, see https://docs.microsoft.com/en-us/azure/key-vault/general/about-keys-secrets-certificates#objects-identifiers-and-versioning");
Guard.For<UriFormatException>(
() => !KeyVaultUriRegex.IsMatch(vaultUri),
"Requires the Azure Key Vault host to be in the right format, see https://docs.microsoft.com/en-us/azure/key-vault/general/about-keys-secrets-certificates#objects-identifiers-and-versioning");
stijnmoreels marked this conversation as resolved.
Show resolved Hide resolved

context = context ?? new Dictionary<string, object>();
LogAzureKeyVaultDependency(logger, vaultUri, secretName, isSuccessful, measurement.StartTime, measurement.Elapsed, dependencyId, context);
}

/// <summary>
/// Logs an Azure Key Vault dependency.
/// </summary>
/// <param name="logger">The logger to use.</param>
/// <param name="vaultUri">The URI pointing to the Azure Key Vault resource.</param>
/// <param name="secretName">The secret that is being used within the Azure Key Vault resource.</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="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="vaultUri"/> or <paramref name="secretName"/> is blank.</exception>
/// <exception cref="ArgumentOutOfRangeException">Thrown when the <paramref name="duration"/> is a negative time range.</exception>
/// <exception cref="FormatException">Thrown when the <paramref name="secretName"/> is not in the correct format.</exception>
/// <exception cref="UriFormatException">Thrown when the <paramref name="vaultUri"/> is not in the correct format.</exception>
public static void LogAzureKeyVaultDependency(
this ILogger logger,
string vaultUri,
string secretName,
bool isSuccessful,
DateTimeOffset startTime,
TimeSpan duration,
Dictionary<string, object> context = null)
{
Guard.NotNull(logger, nameof(logger), "Requires an logger instance to write the Azure Key Vault dependency");
Guard.NotNullOrWhitespace(vaultUri, nameof(vaultUri), "Requires a non-blank URI for the Azure Key Vault");
Guard.NotNullOrWhitespace(secretName, nameof(secretName), "Requires a non-blank secret name for the Azure Key Vault");
Guard.For<FormatException>(
() => !SecretNameRegex.IsMatch(secretName),
"Requires a Azure Key Vault secret name in the correct format, see https://docs.microsoft.com/en-us/azure/key-vault/general/about-keys-secrets-certificates#objects-identifiers-and-versioning");
Guard.For<UriFormatException>(
stijnmoreels marked this conversation as resolved.
Show resolved Hide resolved
() => !KeyVaultUriRegex.IsMatch(vaultUri),
"Requires the Azure Key Vault host to be in the right format, see https://docs.microsoft.com/en-us/azure/key-vault/general/about-keys-secrets-certificates#objects-identifiers-and-versioning");
Guard.NotLessThan(duration, TimeSpan.Zero, nameof(duration), "Requires a positive time duration of the Azure Key Vault operation");

context = context ?? new Dictionary<string, object>();
LogAzureKeyVaultDependency(logger, vaultUri, secretName, isSuccessful, startTime, duration, dependencyId: null, context);
}

/// <summary>
Expand All @@ -505,6 +582,7 @@ public static void LogAzureKeyVaultDependency(
/// <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="vaultUri"/> or <paramref name="secretName"/> is blank.</exception>
Expand All @@ -518,6 +596,7 @@ public static void LogAzureKeyVaultDependency(
bool isSuccessful,
DateTimeOffset startTime,
TimeSpan duration,
string dependencyId,
Dictionary<string, object> context = null)
{
Guard.NotNull(logger, nameof(logger), "Requires an logger instance to write the Azure Key Vault dependency");
Expand All @@ -539,6 +618,7 @@ public static void LogAzureKeyVaultDependency(
dependencyData: secretName,
targetName: vaultUri,
duration: duration,
dependencyId: dependencyId,
startTime: startTime,
resultCode: null,
isSuccessful: isSuccessful,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,56 @@ public DependencyLogEntry(
Context[ContextProperties.General.TelemetryType] = TelemetryType.Dependency;
}

/// <summary>
/// Initializes a new instance of the <see cref="DependencyLogEntry"/> class.
/// </summary>
/// <param name="dependencyType">The custom type of dependency.</param>
/// <param name="dependencyName">The name of the dependency.</param>
/// <param name="dependencyData">The custom data of dependency.</param>
/// <param name="targetName">The name of dependency target.</param>
/// <param name="resultCode">The code of the result of the interaction with the dependency.</param>
/// <param name="isSuccessful">The indication whether or not the operation was successful.</param>
/// <param name="startTime">The point in time when the interaction with the HTTP dependency was started.</param>
/// <param name="dependencyId">The ID of the dependency to link as parent ID.</param>
/// <param name="duration">The duration of the operation.</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="dependencyData"/> is <c>null</c>.</exception>
/// <exception cref="ArgumentException">Thrown when the <paramref name="dependencyData"/> is blank.</exception>
/// <exception cref="ArgumentOutOfRangeException">Thrown when the <paramref name="duration"/> is a negative time range.</exception>
public DependencyLogEntry(
string dependencyType,
string dependencyName,
object dependencyData,
string targetName,
string dependencyId,
TimeSpan duration,
DateTimeOffset startTime,
int? resultCode,
bool isSuccessful,
IDictionary<string, object> context)
{
Guard.NotNullOrWhitespace(dependencyType, nameof(dependencyType), "Requires a non-blank custom dependency type when tracking the custom dependency");
Guard.NotLessThan(duration, TimeSpan.Zero, nameof(duration), "Requires a positive time duration of the dependency operation");

DependencyId = dependencyId;
DependencyType = dependencyType;
DependencyName = dependencyName;
DependencyData = dependencyData;
TargetName = targetName;
ResultCode = resultCode;
IsSuccessful = isSuccessful;

StartTime = startTime.ToString(FormatSpecifiers.InvariantTimestampFormat);
Duration = duration;
Context = context;
Context[ContextProperties.General.TelemetryType] = TelemetryType.Dependency;
}

/// <summary>
/// Gets the ID of the dependency to link as parent ID.
/// </summary>
public string DependencyId { get; }

/// <summary>
/// Gets the custom type of the dependency.
/// </summary>
Expand Down Expand Up @@ -104,8 +154,8 @@ public DependencyLogEntry(
public override string ToString()
{
string contextFormatted = $"{{{String.Join("; ", Context.Select(item => $"[{item.Key}, {item.Value}]"))}}}";
return $"{DependencyType} {DependencyName} {DependencyData} named {TargetName} in {Duration} at {StartTime} " +
$"(Successful: {IsSuccessful} - ResultCode: {ResultCode} - Context: {contextFormatted})";
return $"{DependencyType} {DependencyName} {DependencyData} named {TargetName} with ID {DependencyId} in {Duration} at {StartTime} " +
$"(IsSuccessful: {IsSuccessful} - ResultCode: {ResultCode} - Context: {contextFormatted})";
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ protected override DependencyTelemetry CreateTelemetryEntry(LogEvent logEvent, I
Guard.NotNull(logEvent.Properties, nameof(logEvent), "Requires a Serilog event with a set of properties to create an Azure Application Insights Dependency telemetry instance");

StructureValue logEntry = logEvent.Properties.GetAsStructureValue(ContextProperties.DependencyTracking.DependencyLogEntry);
string dependencyId = logEntry.Properties.GetAsRawString(nameof(DependencyLogEntry.DependencyId));
string dependencyType = logEntry.Properties.GetAsRawString(nameof(DependencyLogEntry.DependencyType));
string dependencyName = logEntry.Properties.GetAsRawString(nameof(DependencyLogEntry.DependencyName));
string target = logEntry.Properties.GetAsRawString(nameof(DependencyLogEntry.TargetName));
Expand All @@ -34,12 +35,10 @@ protected override DependencyTelemetry CreateTelemetryEntry(LogEvent logEvent, I
string resultCode = logEntry.Properties.GetAsRawString(nameof(DependencyLogEntry.ResultCode));
bool outcome = logEntry.Properties.GetAsBool(nameof(DependencyLogEntry.IsSuccessful));
IDictionary<string, string> context = logEntry.Properties.GetAsDictionary(nameof(DependencyLogEntry.Context));

string operationId = logEvent.Properties.GetAsRawString(ContextProperties.Correlation.OperationId);


var dependencyTelemetry = new DependencyTelemetry(dependencyType, target, dependencyName, data, startTime, duration, resultCode, success: outcome)
{
Id = operationId
Id = dependencyId
};

dependencyTelemetry.Properties.AddRange(context);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,8 @@ namespace Arcus.Observability.Tests.Integration.Serilog.Sinks.ApplicationInsight
public class ApplicationInsightsSinkTests : IntegrationTest
{
protected const string OnlyLastHourFilter = "timestamp gt now() sub duration'PT1H'";

protected const string PastHalfHourTimeSpan = "PT30M";

private readonly ITestOutputHelper _outputWriter;
private readonly InMemoryLogSink _memoryLogSink;
private readonly string _instrumentationKey;
Expand Down
Loading