Observe Retry-After delay on HTTP request retry

src/NuGet.Core/NuGet.Protocol/EnhancedHttpRetryHelper.cs

@@ -33,6 +33,11 @@ internal class EnhancedHttpRetryHelper
         /// </summary>
         public const bool DefaultRetry429 = true;
 
+        /// <summary>
+        /// The default value indicating whether or not to observe Retry-After headers on responses.
+        /// </summary>
+        public const bool DefaultObserveRetryAfter = true;
+
         /// <summary>
         /// The environment variable used to change the delay value.
         /// </summary>
@@ -53,6 +58,16 @@ internal class EnhancedHttpRetryHelper
         /// </summary>
         public const string Retry429EnvironmentVariableName = "NUGET_RETRY_HTTP_429";
 
+        /// <summary>
+        /// The envionment variable to disable observing Retry-After responses.
+        /// </summary>
+        public const string ObserveRetryAfterEnvironmentVariableName = "NUGET_OBSERVE_RETRY_AFTER";
+
+        /// <summary>
+        /// The environment variable used to set maximum Retry-After delay period
+        /// </summary>
+        public const string MaximumRetryAfterDurationEnvironmentVariableName = "NUGET_MAX_RETRY_AFTER_DELAY_SECONDS";
+
         private readonly IEnvironmentVariableReader _environmentVariableReader;
 
         private bool? _isEnabled = null;
@@ -63,6 +78,10 @@ internal class EnhancedHttpRetryHelper
 
         private bool? _retry429 = null;
 
+        private bool? _observeRetryAfter = null;
+
+        private TimeSpan? _maxRetyAfterDelay = null;
+
         /// <summary>
         /// Initializes a new instance of the <see cref="EnhancedHttpRetryHelper" /> class.
         /// </summary>
@@ -93,6 +112,25 @@ public EnhancedHttpRetryHelper(IEnvironmentVariableReader environmentVariableRea
         /// </summary>
         internal bool Retry429 => _retry429 ??= GetBoolFromEnvironmentVariable(Retry429EnvironmentVariableName, defaultValue: true, _environmentVariableReader);
 
+        /// <summary>
+        /// Gets a value indicating whether or not to observe the Retry-After header on HTTP responses.
+        /// </summary>
+        internal bool ObserveRetryAfter => _observeRetryAfter ??= GetBoolFromEnvironmentVariable(ObserveRetryAfterEnvironmentVariableName, defaultValue: DefaultObserveRetryAfter, _environmentVariableReader);
+
+        internal TimeSpan MaxRetryAfterDelay
+        {
+            get
+            {
+                if (_maxRetyAfterDelay == null)
+                {
+                    int maxRetryAfterDelay = GetIntFromEnvironmentVariable(MaximumRetryAfterDurationEnvironmentVariableName, defaultValue: (int)TimeSpan.FromHours(1).TotalSeconds, _environmentVariableReader);
+                    _maxRetyAfterDelay = TimeSpan.FromSeconds(maxRetryAfterDelay);
+                }
+
+                return _maxRetyAfterDelay.Value;
+            }
+        }
+
         /// <summary>
         /// Gets a <see cref="bool" /> value from the specified environment variable.
         /// </summary>

src/NuGet.Core/NuGet.Protocol/HttpSource/HttpRetryHandler.cs

@@ -1,11 +1,14 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
+#nullable enable
+
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
 using System.Globalization;
 using System.Net.Http;
+using System.Net.Http.Headers;
 using System.Threading;
 using System.Threading.Tasks;
 using NuGet.Common;
@@ -71,16 +74,20 @@ public async Task<HttpResponseMessage> SendAsync(
             }
 
             var tries = 0;
-            HttpResponseMessage response = null;
-            var success = false;
+            HttpResponseMessage? response = null;
+            TimeSpan? retryAfter = null;
 
-            while (tries < request.MaxTries && !success)
+            while (true)
             {
                 // There are many places where another variable named "MaxTries" is set to 1,
                 // so the Delay() never actually occurs.
                 // When opted in to "enhanced retry", do the delay and have it increase exponentially where applicable
                 // (i.e. when "tries" is allowed to be > 1)
-                if (tries > 0 || (_enhancedHttpRetryHelper.IsEnabled && request.IsRetry))
+                if (retryAfter != null && _enhancedHttpRetryHelper.ObserveRetryAfter)
+                {
+                    await Task.Delay(retryAfter.Value, cancellationToken);
+                }
+                else if (tries > 0 || (_enhancedHttpRetryHelper.IsEnabled && request.IsRetry))
                 {
                     // "Enhanced" retry: In the case where this is actually a 2nd-Nth try, back off exponentially with some random.
                     // In many cases due to the external retry loop, this will be always be 1 * request.RetryDelay.TotalMilliseconds + 0-200 ms
@@ -100,14 +107,13 @@ public async Task<HttpResponseMessage> SendAsync(
                 }
 
                 tries++;
-                success = true;
 
                 using (var requestMessage = request.RequestFactory())
                 {
                     var stopwatches = new List<Stopwatch>(2);
                     var bodyStopwatch = new Stopwatch();
                     stopwatches.Add(bodyStopwatch);
-                    Stopwatch headerStopwatch = null;
+                    Stopwatch? headerStopwatch = null;
                     if (request.CompletionOption == HttpCompletionOption.ResponseHeadersRead)
                     {
                         headerStopwatch = new Stopwatch();
@@ -118,7 +124,7 @@ public async Task<HttpResponseMessage> SendAsync(
 #else
                     requestMessage.Properties[StopwatchPropertyName] = stopwatches;
 #endif
-                    var requestUri = requestMessage.RequestUri;
+                    var requestUri = requestMessage.RequestUri!;
 
                     try
                     {
@@ -197,20 +203,50 @@ public async Task<HttpResponseMessage> SendAsync(
                             response.Content = newContent;
                         }
 
-                        log.LogInformation("  " + string.Format(
-                            CultureInfo.InvariantCulture,
-                            Strings.Http_ResponseLog,
-                            response.StatusCode,
-                            requestUri,
-                            bodyStopwatch.ElapsedMilliseconds));
+                        retryAfter = GetRetryAfter(response.Headers.RetryAfter);
+                        if (retryAfter != null)
+                        {
+                            log.LogInformation("  " + string.Format(
+                                CultureInfo.InvariantCulture,
+                                Strings.Http_ResponseLogWithRetryAfter,
+                                response.StatusCode,
+                                requestUri,
+                                bodyStopwatch.ElapsedMilliseconds,
+                                retryAfter.Value.TotalSeconds));
+
+                            if (retryAfter.Value.TotalMilliseconds < 0)
+                            {
+                                retryAfter = null;
+                            }
+                            else if (retryAfter.Value > _enhancedHttpRetryHelper.MaxRetryAfterDelay)
+                            {
+                                retryAfter = _enhancedHttpRetryHelper.MaxRetryAfterDelay;
+                            }
+                        }
+                        else
+                        {
+                            log.LogInformation("  " + string.Format(
+                                CultureInfo.InvariantCulture,
+                                Strings.Http_ResponseLog,
+                                response.StatusCode,
+                                requestUri,
+                                bodyStopwatch.ElapsedMilliseconds));
+                        }
 
                         int statusCode = (int)response.StatusCode;
                         // 5xx == server side failure
                         // 408 == request timeout
                         // 429 == too many requests
                         if (statusCode >= 500 || ((statusCode == 408 || statusCode == 429) && _enhancedHttpRetryHelper.Retry429))
                         {
-                            success = false;
+                            if (tries == request.MaxTries)
+                            {
+                                return response;
+                            }
+                        }
+                        else
+                        {
+                            return response;
                         }
                     }
                     catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested)
@@ -234,8 +270,6 @@ public async Task<HttpResponseMessage> SendAsync(
                     }
                     catch (Exception e)
                     {
-                        success = false;
-
                         response?.Dispose();
 
                         ProtocolDiagnostics.RaiseEvent(new ProtocolDiagnosticHttpEvent(
@@ -267,8 +301,23 @@ public async Task<HttpResponseMessage> SendAsync(
                     }
                 }
             }
+        }
+
+        private static TimeSpan? GetRetryAfter(RetryConditionHeaderValue? retryAfter)
+        {
+            if (retryAfter?.Delta != null)
+            {
+                return retryAfter.Delta;
+            }
+
+            if (retryAfter?.Date != null)
+            {
+                DateTimeOffset retryAfterDate = retryAfter.Date.Value.ToUniversalTime();
+                var now = DateTimeOffset.UtcNow;
+                return retryAfterDate - now;
+            }
 
-            return response;
+            return null;
         }
     }
 }

src/NuGet.Core/NuGet.Protocol/PublicAPI/net472/PublicAPI.Shipped.txt

@@ -459,8 +459,8 @@ NuGet.Protocol.HttpRequestMessageFactory
 NuGet.Protocol.HttpResponseMessageExtensions
 NuGet.Protocol.HttpRetryHandler
 NuGet.Protocol.HttpRetryHandler.HttpRetryHandler() -> void
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, string source, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, string! source, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
 NuGet.Protocol.HttpRetryHandlerRequest
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.get -> System.Collections.Generic.IList<System.Collections.Generic.KeyValuePair<string, System.Collections.Generic.IEnumerable<string>>>
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.set -> void

src/NuGet.Core/NuGet.Protocol/PublicAPI/netcoreapp5.0/PublicAPI.Shipped.txt

@@ -459,8 +459,8 @@ NuGet.Protocol.HttpRequestMessageFactory
 NuGet.Protocol.HttpResponseMessageExtensions
 NuGet.Protocol.HttpRetryHandler
 NuGet.Protocol.HttpRetryHandler.HttpRetryHandler() -> void
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, string source, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, string! source, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
 NuGet.Protocol.HttpRetryHandlerRequest
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.get -> System.Collections.Generic.IList<System.Collections.Generic.KeyValuePair<string, System.Collections.Generic.IEnumerable<string>>>
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.set -> void

src/NuGet.Core/NuGet.Protocol/PublicAPI/netstandard2.0/PublicAPI.Shipped.txt

@@ -459,8 +459,8 @@ NuGet.Protocol.HttpRequestMessageFactory
 NuGet.Protocol.HttpResponseMessageExtensions
 NuGet.Protocol.HttpRetryHandler
 NuGet.Protocol.HttpRetryHandler.HttpRetryHandler() -> void
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
-~NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest request, string source, NuGet.Common.ILogger log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage>
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
+NuGet.Protocol.HttpRetryHandler.SendAsync(NuGet.Protocol.HttpRetryHandlerRequest! request, string! source, NuGet.Common.ILogger! log, System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task<System.Net.Http.HttpResponseMessage!>!
 NuGet.Protocol.HttpRetryHandlerRequest
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.get -> System.Collections.Generic.IList<System.Collections.Generic.KeyValuePair<string, System.Collections.Generic.IEnumerable<string>>>
 ~NuGet.Protocol.HttpRetryHandlerRequest.AddHeaders.set -> void

src/NuGet.Core/NuGet.Protocol/Strings.resx

@@ -482,4 +482,10 @@ The "ms" should be localized to the abbreviation for milliseconds.</comment>
     <value>You are running the '{0}' operation with an 'HTTP' source, '{1}'. Non-HTTPS access will be removed in a future version. Consider migrating to an 'HTTPS' source.</value>
     <comment>0 - The command name. Ex. Push/Delete. 1 - server uri.</comment>
   </data>
+  <data name="Http_ResponseLogWithRetryAfter" xml:space="preserve">
+    <value>{0} {1} {2}ms (retry after: {3}s)</value>
+    <comment>Parameters in order: non-localizable HTTP status, non-localizable HTTP request URI, request duration in milliseconds, retry after duration in milliseconds
+The "ms" should be localized to the abbreviation for milliseconds.
+The "s" should be localized to the abbreviation for seconds.</comment>
+  </data>
 </root>