Add SocketsHttpHandler requests-queue-duration metrics

src/libraries/System.Net.Http/src/System/Net/Http/HttpTelemetry.AnyOS.cs

@@ -1,6 +1,7 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
+using System.Diagnostics;
 using System.Diagnostics.Tracing;
 using System.Threading;
 
@@ -21,24 +22,22 @@ internal sealed partial class HttpTelemetry
         private EventCounter? _http30RequestsQueueDurationCounter;
 
         [NonEvent]
-        public void Http11RequestLeftQueue(double timeOnQueueMilliseconds)
+        public void RequestLeftQueue(int versionMajor, TimeSpan duration)
         {
-            _http11RequestsQueueDurationCounter?.WriteMetric(timeOnQueueMilliseconds);
-            RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 1, versionMinor: 1);
-        }
+            Debug.Assert(versionMajor is 1 or 2 or 3);
 
-        [NonEvent]
-        public void Http20RequestLeftQueue(double timeOnQueueMilliseconds)
-        {
-            _http20RequestsQueueDurationCounter?.WriteMetric(timeOnQueueMilliseconds);
-            RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 2, versionMinor: 0);
-        }
+            EventCounter? counter = versionMajor switch
+            {
+                1 => _http11RequestsQueueDurationCounter,
+                2 => _http20RequestsQueueDurationCounter,
+                _ => _http30RequestsQueueDurationCounter
+            };
 
-        [NonEvent]
-        public void Http30RequestLeftQueue(double timeOnQueueMilliseconds)
-        {
-            _http30RequestsQueueDurationCounter?.WriteMetric(timeOnQueueMilliseconds);
-            RequestLeftQueue(timeOnQueueMilliseconds, versionMajor: 3, versionMinor: 0);
+            double timeOnQueueMs = duration.TotalMilliseconds;
+
+            counter?.WriteMetric(timeOnQueueMs);
+
+            RequestLeftQueue(timeOnQueueMs, (byte)versionMajor, versionMinor: versionMajor == 1 ? (byte)1 : (byte)0);
         }
 
         protected override void OnEventCommand(EventCommandEventArgs command)

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http3Connection.cs

@@ -160,7 +160,7 @@ private void CheckForShutdown()
             }
         }
 
-        public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, long queueStartingTimestamp, CancellationToken cancellationToken)
+        public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, bool requestsQueueDurationEnabled, long queueStartingTimestamp, CancellationToken cancellationToken)
         {
             // Allocate an active request
             QuicStream? quicStream = null;
@@ -173,7 +173,7 @@ public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, lon
                     QuicConnection? conn = _connection;
                     if (conn != null)
                     {
-                        if (HttpTelemetry.Log.IsEnabled() && queueStartingTimestamp == 0)
+                        if (requestsQueueDurationEnabled && queueStartingTimestamp == 0)
                         {
                             queueStartingTimestamp = Stopwatch.GetTimestamp();
                         }
@@ -198,9 +198,9 @@ public async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, lon
                 catch (QuicException e) when (e.QuicError != QuicError.OperationAborted) { }
                 finally
                 {
-                    if (HttpTelemetry.Log.IsEnabled() && queueStartingTimestamp != 0)
+                    if (requestsQueueDurationEnabled && queueStartingTimestamp != 0)
                     {
-                        HttpTelemetry.Log.Http30RequestLeftQueue(Stopwatch.GetElapsedTime(queueStartingTimestamp).TotalMilliseconds);
+                        _pool.Settings._metrics!.RequestLeftQueue(Pool, Stopwatch.GetElapsedTime(queueStartingTimestamp), versionMajor: 3);
                     }
                 }
 

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionBase.cs

@@ -47,15 +47,12 @@ public HttpConnectionBase(HttpConnectionPool pool)
                     this is Http2Connection ? "HTTP/2" :
                     "HTTP/3";
 
-                int port = pool.OriginAuthority.Port;
-                int defaultPort = pool.IsSecure ? HttpConnectionPool.DefaultHttpsPort : HttpConnectionPool.DefaultHttpPort;
-
                 _connectionMetrics = new ConnectionMetrics(
                     metrics,
                     protocol,
                     pool.IsSecure ? "https" : "http",
                     pool.OriginAuthority.HostValue,
-                    port == defaultPort ? null : port);
+                    pool.IsDefaultPort ? null : pool.OriginAuthority.Port);
 
                 _connectionMetrics.ConnectionEstablished();
 

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs

@@ -363,6 +363,7 @@ private static SslClientAuthenticationOptions ConstructSslOptions(HttpConnection
         public ICredentials? ProxyCredentials => _poolManager.ProxyCredentials;
         public byte[]? HostHeaderLineBytes => _hostHeaderLineBytes;
         public CredentialCache? PreAuthCredentials { get; }
+        public bool IsDefaultPort => OriginAuthority.Port == (IsSecure ? DefaultHttpsPort : DefaultHttpsPort);
 
         /// <summary>
         /// An ASCII origin string per RFC 6454 Section 6.2, in format &lt;scheme&gt;://&lt;host&gt;[:&lt;port&gt;]
@@ -998,19 +999,20 @@ private async ValueTask<Http3Connection> GetHttp3ConnectionAsync(HttpRequestMess
                     ThrowGetVersionException(request, 3, reasonException);
                 }
 
-                long queueStartingTimestamp = HttpTelemetry.Log.IsEnabled() ? Stopwatch.GetTimestamp() : 0;
+                bool requestsQueueDurationEnabled = HttpTelemetry.Log.IsEnabled() || Settings._metrics!.RequestsQueueDuration.Enabled;
+                long queueStartingTimestamp = requestsQueueDurationEnabled ? Stopwatch.GetTimestamp() : 0;
 
                 ValueTask<Http3Connection> connectionTask = GetHttp3ConnectionAsync(request, authority, cancellationToken);
 
-                if (HttpTelemetry.Log.IsEnabled() && connectionTask.IsCompleted)
+                if (requestsQueueDurationEnabled && connectionTask.IsCompleted)
                 {
                     // We avoid logging RequestLeftQueue if a stream was available immediately (synchronously)
                     queueStartingTimestamp = 0;
                 }
 
                 Http3Connection connection = await connectionTask.ConfigureAwait(false);
 
-                HttpResponseMessage response = await connection.SendAsync(request, queueStartingTimestamp, cancellationToken).ConfigureAwait(false);
+                HttpResponseMessage response = await connection.SendAsync(request, requestsQueueDurationEnabled, queueStartingTimestamp, cancellationToken).ConfigureAwait(false);
 
                 // If an Alt-Svc authority returns 421, it means it can't actually handle the request.
                 // An authority is supposed to be able to handle ALL requests to the origin, so this is a server bug.
@@ -1089,7 +1091,7 @@ public async ValueTask<HttpResponseMessage> SendWithVersionDetectionAndRetryAsyn
                             if (!TryGetPooledHttp2Connection(request, out Http2Connection? connection, out http2ConnectionWaiter) &&
                                 http2ConnectionWaiter != null)
                             {
-                                connection = await http2ConnectionWaiter.WaitForConnectionAsync(async, cancellationToken).ConfigureAwait(false);
+                                connection = await http2ConnectionWaiter.WaitForConnectionAsync(this, async, cancellationToken).ConfigureAwait(false);
                             }
 
                             Debug.Assert(connection is not null || !_http2Enabled);
@@ -1121,7 +1123,7 @@ public async ValueTask<HttpResponseMessage> SendWithVersionDetectionAndRetryAsyn
                             // Use HTTP/1.x.
                             if (!TryGetPooledHttp11Connection(request, async, out HttpConnection? connection, out http11ConnectionWaiter))
                             {
-                                connection = await http11ConnectionWaiter.WaitForConnectionAsync(async, cancellationToken).ConfigureAwait(false);
+                                connection = await http11ConnectionWaiter.WaitForConnectionAsync(this, async, cancellationToken).ConfigureAwait(false);
                             }
 
                             connection.Acquire(); // In case we are doing Windows (i.e. connection-based) auth, we need to ensure that we hold on to this specific connection while auth is underway.
@@ -1199,6 +1201,7 @@ public async ValueTask<HttpResponseMessage> SendWithVersionDetectionAndRetryAsyn
         }
 
         private void CancelIfNecessary<T>(HttpConnectionWaiter<T>? waiter, bool requestCancelled)
+            where T : HttpConnectionBase?
         {
             int timeout = GlobalHttpSettings.SocketsHttpHandler.PendingConnectionTimeoutOnRequestCompletion;
             if (waiter?.ConnectionCancellationTokenSource is null ||
@@ -2430,6 +2433,7 @@ private void Trace(string? message, [CallerMemberName] string? memberName = null
                 message);                    // message
 
         private struct RequestQueue<T>
+            where T : HttpConnectionBase?
         {
             public struct QueueItem
             {
@@ -2599,6 +2603,7 @@ public QueueItem PeekNextRequestForConnectionAttempt()
         }
 
         private sealed class HttpConnectionWaiter<T> : TaskCompletionSourceWithCancellation<T>
+            where T : HttpConnectionBase?
         {
             // When a connection attempt is pending, reference the connection's CTS, so we can tear it down if the initiating request is cancelled
             // or completes on a different connection.
@@ -2607,22 +2612,25 @@ private sealed class HttpConnectionWaiter<T> : TaskCompletionSourceWithCancellat
             // Distinguish connection cancellation that happens because the initiating request is cancelled or completed on a different connection.
             public bool CancelledByOriginatingRequestCompletion { get; set; }
 
-            public async ValueTask<T> WaitForConnectionAsync(bool async, CancellationToken requestCancellationToken)
+            public ValueTask<T> WaitForConnectionAsync(HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
             {
+                return HttpTelemetry.Log.IsEnabled() || pool.Settings._metrics!.RequestsQueueDuration.Enabled
+                    ? WaitForConnectionWithTelemetryAsync(pool, async, requestCancellationToken)
+                    : WaitWithCancellationAsync(async, requestCancellationToken);
+            }
+
+            private async ValueTask<T> WaitForConnectionWithTelemetryAsync(HttpConnectionPool pool, bool async, CancellationToken requestCancellationToken)
+            {
+                Debug.Assert(typeof(T) == typeof(HttpConnection) || typeof(T) == typeof(Http2Connection));
+
                 long startingTimestamp = Stopwatch.GetTimestamp();
                 try
                 {
                     return await WaitWithCancellationAsync(async, requestCancellationToken).ConfigureAwait(false);
                 }
                 finally
                 {
-                    if (HttpTelemetry.Log.IsEnabled())
-                    {
-                        if (typeof(T) == typeof(HttpConnection))
-                            HttpTelemetry.Log.Http11RequestLeftQueue(Stopwatch.GetElapsedTime(startingTimestamp).TotalMilliseconds);
-                        else if (typeof(T) == typeof(Http2Connection))
-                            HttpTelemetry.Log.Http20RequestLeftQueue(Stopwatch.GetElapsedTime(startingTimestamp).TotalMilliseconds);
-                    }
+                    pool.Settings._metrics!.RequestLeftQueue(pool, Stopwatch.GetElapsedTime(startingTimestamp), versionMajor: typeof(T) == typeof(HttpConnection) ? 1 : 2);
                 }
             }
         }

src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Metrics/SocketsHttpHandlerMetrics.cs

@@ -1,6 +1,7 @@
 // Licensed to the .NET Foundation under one or more agreements.
 // The .NET Foundation licenses this file to you under the MIT license.
 
+using System.Diagnostics;
 using System.Diagnostics.Metrics;
 
 namespace System.Net.Http.Metrics
@@ -19,5 +20,42 @@ internal sealed class SocketsHttpHandlerMetrics(Meter meter)
             name: "http-client-connection-duration",
             unit: "s",
             description: "The duration of outbound HTTP connections.");
+
+        public readonly Histogram<double> RequestsQueueDuration = meter.CreateHistogram<double>(
+            name: "http-client-requests-queue-duration",
+            unit: "s",
+            description: "The amount of time requests spent on a queue waiting for an available connection.");
+
+        public void RequestLeftQueue(HttpConnectionPool pool, TimeSpan duration, int versionMajor)
+        {
+            Debug.Assert(versionMajor is 1 or 2 or 3);
+
+            if (RequestsQueueDuration.Enabled)
+            {
+                TagList tags = default;
+
+                tags.Add("protocol", versionMajor switch
+                {
+                    1 => "HTTP/1.1",
+                    2 => "HTTP/2",
+                    _ => "HTTP/3"
+                });
+
+                tags.Add("scheme", pool.IsSecure ? "https" : "http");
+                tags.Add("host", pool.OriginAuthority.HostValue);
+
+                if (!pool.IsDefaultPort)
+                {
+                    tags.Add("port", pool.OriginAuthority.Port);
+                }
+
+                RequestsQueueDuration.Record(duration.TotalSeconds, tags);
+            }
+
+            if (HttpTelemetry.Log.IsEnabled())
+            {
+                HttpTelemetry.Log.RequestLeftQueue(versionMajor, duration);
+            }
+        }
     }
 }