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

* feat: add dependency ID to az key vault dependency tracking * pr-docs: complete missing dependency ID tracking feature docs * pr-fix: remove operation ID assignment in ai dependency tracking converter * Update docs/preview/02-Features/writing-different-telemetry-types.md Co-authored-by: Frederik Gheysels <frederik.gheysels@telenet.be> * pr-fix: update with more clear explanation of the request tracking * pr-fix: update with serialized json in unit tests * Update writing-different-telemetry-types.md Co-authored-by: Frederik Gheysels <frederik.gheysels@telenet.be>
arcus-azure · Jan 18, 2022 · 20dfe4f · 20dfe4f
1 parent b0a2eb7
commit 20dfe4f
Show file tree

Hide file tree

Showing 10 changed files with 469 additions and 65 deletions.
diff --git a/docs/preview/02-Features/writing-different-telemetry-types.md b/docs/preview/02-Features/writing-different-telemetry-types.md
@@ -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
 
@@ -388,6 +389,36 @@ 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.
+
+To link the request (incoming) with the dependency (outgoing), the request needs to include this dependency ID in its tracking (dependency ID = request's parent ID) so that we now which dependency triggered the request.
+For more information, see how to do this in a Web API and Azure Service Bus context.
+
+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.

diff --git a/src/Arcus.Observability.Telemetry.Core/ContextProperties.cs b/src/Arcus.Observability.Telemetry.Core/ContextProperties.cs
@@ -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";

diff --git a/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs b/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs
@@ -493,7 +493,84 @@ public static class ILoggerExtensions
                 "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");
+
+            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>(
+                () => !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>
@@ -505,6 +582,7 @@ public static class ILoggerExtensions
         /// <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>
@@ -518,6 +596,7 @@ public static class ILoggerExtensions
             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");
@@ -539,6 +618,7 @@ public static class ILoggerExtensions
                 dependencyData: secretName, 
                 targetName: vaultUri, 
                 duration: duration, 
+                dependencyId: dependencyId,
                 startTime: startTime, 
                 resultCode: null,
                 isSuccessful: isSuccessful, 

diff --git a/src/Arcus.Observability.Telemetry.Core/Logging/DependencyLogEntry.cs b/src/Arcus.Observability.Telemetry.Core/Logging/DependencyLogEntry.cs
@@ -52,6 +52,56 @@ public class 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>
@@ -104,8 +154,8 @@ public class 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})";
         }
     }
 }
diff --git a/...ty.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/DependencyTelemetryConverter.cs b/...ty.Telemetry.Serilog.Sinks.ApplicationInsights/Converters/DependencyTelemetryConverter.cs
@@ -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));
@@ -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);

diff --git a/...ility.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs b/...ility.Tests.Integration/Serilog/Sinks/ApplicationInsights/ApplicationInsightsSinkTests.cs
@@ -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;