feat: add request measurement for requests (#270)

* feat: add request measurement for requests * Update docs/preview/02-Features/writing-different-telemetry-types.md Co-authored-by: Frederik Gheysels <frederik.gheysels@telenet.be> Co-authored-by: Frederik Gheysels <frederik.gheysels@telenet.be>
arcus-azure · Jan 26, 2022 · 3ae1b79 · 3ae1b79
1 parent 03f6ff8
commit 3ae1b79
Show file tree

Hide file tree

Showing 4 changed files with 118 additions and 53 deletions.
diff --git a/docs/preview/02-Features/writing-different-telemetry-types.md b/docs/preview/02-Features/writing-different-telemetry-types.md
@@ -330,9 +330,10 @@ logger.LogDependency("SendGrid", dependencyData, isSuccessful: true, startTime:
 // Output: {"DependencyType": "SendGrid", "DependencyData": "http://my.sendgrid.uri/", "Duration": "00:00:01.2396312", "StartTime": "03/23/2020 09:32:02 +00:00", "IsSuccessful": true, "Context": {}}
 ```
 
-### Making it easier to measure dependencies
+### Making it easier to measure telemetry
 
-Measuring dependencies means you need to keep track of how long the action took and when it started.
+Measuring dependencies or requests means you need to keep track of how long the action took and when it started.
+The `Arcus.Observability.Telemetry.Core` library provides an easy way to accomplish this.
 
 Here's a small example:
 
@@ -351,27 +352,32 @@ object dependencyData = "https://my.sendgrid.uri/";
 logger.LogDependency("SendGrid", dependencyData, isSuccessful: true, startTime: startTime, duration: durationMeasurement.Elapsed, context: telemetryContext);
 ```
 
-However, by using `DependencyMeasurement.Start()` we take care of the measuring aspect:
+#### Making it easier to measure dependencies
+
+By using `DependencyMeasurement.Start()` we take care of the measuring aspect:
 
 ```csharp
 using Arcus.Observability.Telemetry.Core;
 using Microsoft.Extensions.Logging;
 
 // Start measuring
-using (var measurement = DependencyMeasurement.Start())
+using (var measurement = DependencyMeasurement.Start(dependencyData: "Call_SendGrid"))
 {
     // Do Action
 
     // Track dependency
     string dependencyName = "SendGrid";
     object dependencyData = "https://my.sendgrid.uri/";
-    logger.LogDependency(dependencyName, dependencyData, isSuccessful: true, startTime: measurement, context: telemetryContext);
+    logger.LogDependency(dependencyName, dependencyData, isSuccessful: true, measurement, telemetryContext);
 }
 ```
 
-Failures during the interaction with the tracked dependency can be controlled by passing `isSuccessful`:
+Failures during the interaction with the dependency can be controlled by passing `isSuccessful`:
 
 ```csharp
+using Arcus.Observability.Telemetry.Core;
+using Microsoft.Extensions.Logging;
+
 string dependencyName = "SendGrid";
 object dependencyData = "https://my.sendgrid.uri";
 
@@ -380,12 +386,34 @@ try
     // Interact with SendGrid...
     // Done!
 
-    logger.LogDependency(dependencyName, dependencyData, isSuccessful: true, startTime: measurement, context: telemetryContext);
+    logger.LogDependency(dependencyName, dependencyData, isSuccessful: true, measurement, telemetryContext);
 }
 catch (Exception exception)
 {
     logger.LogError(exception, "Failed to interact with SendGrid");
-    logger.LogDependency(dependencyName, dependencyData, isSuccessful: false, startTime: measurement, context: telemetryContext);
+    logger.LogDependency(dependencyName, dependencyData, isSuccessful: false, measurement, telemetryContext);
+}
+```
+
+#### Making it easier to measure requests
+
+By using `RequestMeasurement.Start()` we take care of the measuring aspect:
+
+```csharp
+using Arcus.Observability.Telemetry.Core;
+using Microsoft.AspNetCore.Http;
+using Microsoft.Extensions.Logging;
+
+HttpRequest request = ...
+HttpResponse response = ...
+
+// Start measuring
+using (var measurement = RequestMeasurement.Start())
+{
+    // Process message
+
+    // Track request
+    logger.LogRequest(request, response, measurement.Elapsed, telemetryContext);
 }
 ```
 
@@ -395,7 +423,7 @@ Service-to-service correlation requires linkage between tracked dependencies (ou
 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.
+For more information, see how to do this in a Web API and [Azure Service Bus](#incoming-azure-service-bus-requests) context.
 
 Tracking the outgoing dependency:
 
@@ -471,7 +499,7 @@ using Microsoft.Extensions.Logging;
 bool isSuccessful = false;
 
 // Start measuring.
-using (var measurement = DependencyMeasurement.Start())
+using (var measurement = RequestMeasurement.Start())
 {
     try
     {

diff --git a/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs b/src/Arcus.Observability.Telemetry.Core/Extensions/ILoggerExtensions.cs
@@ -213,7 +213,7 @@ public static class ILoggerExtensions
             string subscriptionName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             Dictionary<string, object> context = null)
         {
             Guard.NotNull(logger, nameof(logger), "Requires an logger instance to track telemetry");
@@ -250,7 +250,7 @@ public static class ILoggerExtensions
             string subscriptionName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             Dictionary<string, object> context = null)
         {
             Guard.NotNull(logger, nameof(logger), "Requires an logger instance to track telemetry");
@@ -365,7 +365,7 @@ public static class ILoggerExtensions
             string queueName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             Dictionary<string, object> context = null)
         {
             Guard.NotNull(logger, nameof(logger), "Requires an logger instance to track telemetry");
@@ -374,8 +374,6 @@ public static class ILoggerExtensions
             Guard.NotNullOrWhitespace(queueName, nameof(queueName), "Requires an Azure Service Bus queue name to track the queue request");
             Guard.NotNull(measurement, nameof(measurement), "Requires an instance to measure the Azure Service Bus queue request process latency duration");
 
-            // TODO: the dependency date from the measurement instance is not used when tracking the request.
-
             LogServiceBusQueueRequestWithSuffix(logger, serviceBusNamespace, serviceBusNamespaceSuffix, queueName, operationName, isSuccessful, measurement.Elapsed, measurement.StartTime, context);
         }
 
@@ -397,16 +395,14 @@ public static class ILoggerExtensions
             string queueName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             Dictionary<string, object> context = null)
         {
             Guard.NotNull(logger, nameof(logger), "Requires an logger instance to track telemetry");
             Guard.NotNullOrWhitespace(serviceBusNamespace, nameof(serviceBusNamespace), "Requires an Azure Service Bus namespace to track the queue request");
             Guard.NotNullOrWhitespace(queueName, nameof(queueName), "Requires an Azure Service Bus queue name to track the queue request");
             Guard.NotNull(measurement, nameof(measurement), "Requires an instance to measure the Azure Service Bus queue request process latency duration");
 
-            // TODO: the dependency date from the measurement instance is not used when tracking the request.
-
             LogServiceBusQueueRequest(logger, serviceBusNamespace, queueName, operationName, isSuccessful, measurement.Elapsed, measurement.StartTime, context);
         }
 
@@ -498,7 +494,7 @@ public static class ILoggerExtensions
             string entityName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             ServiceBusEntityType entityType,
             Dictionary<string, object> context = null)
         {
@@ -508,8 +504,6 @@ public static class ILoggerExtensions
             Guard.NotNullOrWhitespace(entityName, nameof(entityName), "Requires an Azure Service Bus name to track the request");
             Guard.NotNull(measurement, nameof(measurement), "Requires an instance to measure the Azure Service Bus request process latency duration");
 
-            // TODO: the dependency date from the measurement instance is not used when tracking the request.
-
             LogServiceBusRequestWithSuffix(logger, serviceBusNamespace, serviceBusNamespaceSuffix, entityName, operationName, isSuccessful, measurement.Elapsed, measurement.StartTime, entityType, context);
         }
 
@@ -532,7 +526,7 @@ public static class ILoggerExtensions
             string entityName,
             string operationName,
             bool isSuccessful,
-            DependencyMeasurement measurement,
+            RequestMeasurement measurement,
             ServiceBusEntityType entityType,
             Dictionary<string, object> context = null)
         {
@@ -541,8 +535,6 @@ public static class ILoggerExtensions
             Guard.NotNullOrWhitespace(entityName, nameof(entityName), "Requires an Azure Service Bus name to track the request");
             Guard.NotNull(measurement, nameof(measurement), "Requires an instance to measure the Azure Service Bus request process latency duration");
 
-            // TODO: the dependency date from the measurement instance is not used when tracking the request.
-
             LogServiceBusRequest(logger, serviceBusNamespace, entityName, operationName, isSuccessful, measurement.Elapsed, measurement.StartTime, entityType, context);
         }
 

diff --git a/src/Arcus.Observability.Telemetry.Core/RequestMeasurement.cs b/src/Arcus.Observability.Telemetry.Core/RequestMeasurement.cs
@@ -0,0 +1,45 @@
+using System;
+using System.Diagnostics;
+
+namespace Arcus.Observability.Telemetry.Core
+{
+    /// <summary>
+    /// Represents an instance to measure easily requests in an application.
+    /// </summary>
+    public class RequestMeasurement : IDisposable
+    {
+        private readonly Stopwatch _stopwatch;
+
+        private RequestMeasurement()
+        {
+            _stopwatch = Stopwatch.StartNew();
+            StartTime = DateTimeOffset.UtcNow;
+        }
+
+        /// <summary>
+        /// Starts measuring a request until the measurement is disposed.
+        /// </summary>
+        public static RequestMeasurement Start()
+        {
+            return new RequestMeasurement();
+        }
+
+        /// <summary>
+        /// Gets the time when the request measurement was started.
+        /// </summary>
+        public DateTimeOffset StartTime { get; }
+
+        /// <summary>
+        /// Gets the total elapsed time measured for the request.
+        /// </summary>
+        public TimeSpan Elapsed => _stopwatch.Elapsed;
+
+        /// <summary>
+        /// Performs application-defined tasks associated with freeing, releasing, or resetting unmanaged resources.
+        /// </summary>
+        public void Dispose()
+        {
+            _stopwatch.Stop();
+        }
+    }
+}