Add measures and tags with mediator object to the HttpClientLatencyLogEnricher

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/HttpClientLatencyTelemetryExtensions.cs

@@ -33,6 +33,9 @@ public static IServiceCollection AddHttpClientLatencyTelemetry(this IServiceColl
         _ = services.AddSingleton<HttpRequestLatencyListener>();
         _ = services.AddSingleton<HttpClientLatencyContext>();
         _ = services.AddTransient<HttpLatencyTelemetryHandler>();
+        _ = services.AddSingleton<HttpLatencyMediator>();
+        _ = services.RegisterMeasureNames(HttpMeasures.Measures);
+        _ = services.RegisterTagNames(HttpTags.Tags);
         _ = services.AddHttpClientLogEnricher<HttpClientLatencyLogEnricher>();
 
         return services.ConfigureAll<HttpClientFactoryOptions>(

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpClientLatencyLogEnricher.cs

@@ -23,62 +23,140 @@ internal sealed class HttpClientLatencyLogEnricher : IHttpClientLogEnricher
 {
     private static readonly ObjectPool<StringBuilder> _builderPool = PoolFactory.SharedStringBuilderPool;
     private readonly HttpClientLatencyContext _latencyContext;
-
+    private readonly HttpLatencyMediator _httpLatencyMediator;
     private readonly CheckpointToken _enricherInvoked;
 
-    public HttpClientLatencyLogEnricher(HttpClientLatencyContext latencyContext, ILatencyContextTokenIssuer tokenIssuer)
+    public HttpClientLatencyLogEnricher(
+        HttpClientLatencyContext latencyContext,
+        ILatencyContextTokenIssuer tokenIssuer,
+        HttpLatencyMediator httpLatencyMediator)
     {
         _latencyContext = latencyContext;
+        _httpLatencyMediator = httpLatencyMediator;
         _enricherInvoked = tokenIssuer.GetCheckpointToken(HttpCheckpoints.EnricherInvoked);
     }
 
-    public void Enrich(IEnrichmentTagCollector collector, HttpRequestMessage request, HttpResponseMessage? response, Exception? exception)
+    public void Enrich(IEnrichmentTagCollector collector, HttpRequestMessage? request, HttpResponseMessage? response, Exception? exception)
     {
         if (response != null)
         {
             var lc = _latencyContext.Get();
-            lc?.AddCheckpoint(_enricherInvoked);
-
-            StringBuilder stringBuilder = _builderPool.Get();
-
-            // Add serverName, checkpoints to outgoing http logs.
-            AppendServerName(response.Headers, stringBuilder);
-            _ = stringBuilder.Append(',');
 
             if (lc != null)
             {
-                AppendCheckpoints(lc, stringBuilder);
+                // Add the checkpoint
+                lc.AddCheckpoint(_enricherInvoked);
+
+                // Use the mediator to record all metrics
+                _httpLatencyMediator.RecordEnd(lc, response);
             }
 
-            collector.Add("LatencyInfo", stringBuilder.ToString());
+            StringBuilder stringBuilder = _builderPool.Get();
+
+            try
+            {
+                /* Add version, serverName, checkpoints, and measures to outgoing http logs.
+                 * Schemas: 1) ServerName,CheckpointName,CheckpointValue
+                 *          2) v1.0,ServerName,TagName,TagValue,CheckpointName,CheckpointValue,MetricName,MetricValue
+                 */
+
+                // Add version
+                _ = stringBuilder.Append("v1.0");
+                _ = stringBuilder.Append(',');
+
+                // Add server name
+                AppendServerName(response.Headers, stringBuilder);
+                _ = stringBuilder.Append(',');
+
+                // Add tags, checkpoints, and measures
+                if (lc != null)
+                {
+                    AppendTags(lc, stringBuilder);
+                    _ = stringBuilder.Append(',');
+
+                    AppendCheckpoints(lc, stringBuilder);
+                    _ = stringBuilder.Append(',');
 
-            _builderPool.Return(stringBuilder);
+                    AppendMeasures(lc, stringBuilder);
+                }
+
+                collector.Add("LatencyInfo", stringBuilder.ToString());
+            }
+            finally
+            {
+                _builderPool.Return(stringBuilder);
+            }
         }
     }
 
     private static void AppendServerName(HttpHeaders headers, StringBuilder stringBuilder)
     {
         if (headers.TryGetValues(TelemetryConstants.ServerApplicationNameHeader, out var values))
         {
-            _ = stringBuilder.Append(values!.First());
+            _ = stringBuilder.Append(values.First());
         }
     }
 
     private static void AppendCheckpoints(ILatencyContext latencyContext, StringBuilder stringBuilder)
     {
+        const int MillisecondsPerSecond = 1000;
+
         var latencyData = latencyContext.LatencyData;
-        for (int i = 0; i < latencyData.Checkpoints.Length; i++)
+        var checkpointCount = latencyData.Checkpoints.Length;
+
+        for (int i = 0; i < checkpointCount; i++)
         {
             _ = stringBuilder.Append(latencyData.Checkpoints[i].Name);
             _ = stringBuilder.Append('/');
         }
 
         _ = stringBuilder.Append(',');
-        for (int i = 0; i < latencyData.Checkpoints.Length; i++)
+
+        for (int i = 0; i < checkpointCount; i++)
+        {
+            var cp = latencyData.Checkpoints[i];
+            _ = stringBuilder.Append((long)Math.Round(((double)cp.Elapsed / cp.Frequency) * MillisecondsPerSecond));
+            _ = stringBuilder.Append('/');
+        }
+    }
+
+    private static void AppendMeasures(ILatencyContext latencyContext, StringBuilder stringBuilder)
+    {
+        var latencyData = latencyContext.LatencyData;
+        var measureCount = latencyData.Measures.Length;
+
+        for (int i = 0; i < measureCount; i++)
+        {
+            _ = stringBuilder.Append(latencyData.Measures[i].Name);
+            _ = stringBuilder.Append('/');
+        }
+
+        _ = stringBuilder.Append(',');
+
+        for (int i = 0; i < measureCount; i++)
+        {
+            _ = stringBuilder.Append(latencyData.Measures[i].Value);
+            _ = stringBuilder.Append('/');
+        }
+    }
+
+    private static void AppendTags(ILatencyContext latencyContext, StringBuilder stringBuilder)
+    {
+        var latencyData = latencyContext.LatencyData;
+        var tagCount = latencyData.Tags.Length;
+
+        for (int i = 0; i < tagCount; i++)
+        {
+            _ = stringBuilder.Append(latencyData.Tags[i].Name);
+            _ = stringBuilder.Append('/');
+        }
+
+        _ = stringBuilder.Append(',');
+
+        for (int i = 0; i < tagCount; i++)
         {
-            var ms = ((double)latencyData.Checkpoints[i].Elapsed / latencyData.Checkpoints[i].Frequency) * 1000;
-            _ = stringBuilder.Append(ms);
+            _ = stringBuilder.Append(latencyData.Tags[i].Value);
             _ = stringBuilder.Append('/');
         }
     }
-}
+}

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyMediator.cs

@@ -0,0 +1,39 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+#if NET
+using System.Net.Http;
+using Microsoft.Extensions.Diagnostics.Latency;
+
+namespace Microsoft.Extensions.Http.Latency.Internal;
+
+/// <summary>
+/// Mediator for HTTP latency operations that coordinates recording HTTP metrics in a latency context.
+/// </summary>
+internal sealed class HttpLatencyMediator
+{
+    private readonly MeasureToken _gcPauseTime;
+    private readonly TagToken _httpVersionTag;
+
+    public HttpLatencyMediator(ILatencyContextTokenIssuer tokenIssuer)
+    {
+        _gcPauseTime = tokenIssuer.GetMeasureToken(HttpMeasures.GCPauseTime);
+        _httpVersionTag = tokenIssuer.GetTagToken(HttpTags.HttpVersion);
+    }
+
+    public void RecordStart(ILatencyContext latencyContext)
+    {
+        latencyContext.RecordMeasure(_gcPauseTime, (long)System.GC.GetTotalPauseDuration().TotalMilliseconds * -1L);
+    }
+
+    public void RecordEnd(ILatencyContext latencyContext, HttpResponseMessage? response = null)
+    {
+        latencyContext.AddMeasure(_gcPauseTime, (long)System.GC.GetTotalPauseDuration().TotalMilliseconds);
+
+        if (response != null)
+        {
+            latencyContext.SetTag(_httpVersionTag, response.Version.ToString());
+        }
+    }
+}
+#endif

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyMediator.netfx.cs

@@ -0,0 +1,27 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+#if !NET
+
+using System.Net.Http;
+using Microsoft.Extensions.Diagnostics.Latency;
+
+namespace Microsoft.Extensions.Http.Latency.Internal;
+
+internal sealed class HttpLatencyMediator
+{
+    private readonly TagToken _httpVersionTag;
+
+    public HttpLatencyMediator(ILatencyContextTokenIssuer tokenIssuer)
+    {
+        _httpVersionTag = tokenIssuer.GetTagToken(HttpTags.HttpVersion);
+    }
+
+    public void RecordEnd(ILatencyContext latencyContext, HttpResponseMessage? response = null)
+    {
+        if (response != null)
+        {
+            latencyContext?.SetTag(_httpVersionTag, response.Version.ToString());
+        }
+    }
+}
+#endif

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpLatencyTelemetryHandler.cs

@@ -21,14 +21,20 @@ internal sealed class HttpLatencyTelemetryHandler : DelegatingHandler
     private readonly ILatencyContextProvider _latencyContextProvider;
     private readonly CheckpointToken _handlerStart;
     private readonly string _applicationName;
+#if NET
+    private readonly HttpLatencyMediator _latencyMediator;
+#endif
 
     public HttpLatencyTelemetryHandler(HttpRequestLatencyListener latencyListener, ILatencyContextTokenIssuer tokenIssuer, ILatencyContextProvider latencyContextProvider,
-        IOptions<HttpClientLatencyTelemetryOptions> options, IOptions<ApplicationMetadata> appMetadata)
+        IOptions<HttpClientLatencyTelemetryOptions> options, IOptions<ApplicationMetadata> appMetadata, HttpLatencyMediator latencyTelemetryMediator)
     {
         _latencyListener = latencyListener;
         _latencyContextProvider = latencyContextProvider;
         _handlerStart = tokenIssuer.GetCheckpointToken(HttpCheckpoints.HandlerRequestStart);
         _applicationName = appMetadata.Value.ApplicationName;
+#if NET
+        _latencyMediator = latencyTelemetryMediator;
+#endif
 
         if (options.Value.EnableDetailedLatencyBreakdown)
         {
@@ -42,6 +48,10 @@ protected async override Task<HttpResponseMessage> SendAsync(HttpRequestMessage
         context.AddCheckpoint(_handlerStart);
         _latencyListener.LatencyContext.Set(context);
 
+#if NET
+        _latencyMediator.RecordStart(context);
+#endif
+
         _ = request.Headers.TryAddWithoutValidation(TelemetryConstants.ClientApplicationNameHeader, _applicationName);
 
         return await base.SendAsync(request, cancellationToken).ConfigureAwait(false);

src/Libraries/Microsoft.Extensions.Http.Diagnostics/Latency/Internal/HttpMeasures.cs

@@ -0,0 +1,16 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+namespace Microsoft.Extensions.Http.Latency.Internal;
+
+internal static class HttpMeasures
+{
+    public const string GCPauseTime = "gcp";
+    public const string ConnectionInitiated = "coni";
+
+    public static readonly string[] Measures =
+    [
+        GCPauseTime,
+        ConnectionInitiated
+    ];
+}