diff --git a/src/StackExchange.Redis/PhysicalBridge.cs b/src/StackExchange.Redis/PhysicalBridge.cs index 2ead01179..7cf39edeb 100644 --- a/src/StackExchange.Redis/PhysicalBridge.cs +++ b/src/StackExchange.Redis/PhysicalBridge.cs @@ -582,11 +582,11 @@ internal void OnFullyEstablished(PhysicalConnection connection, string source) private int connectStartTicks; private long connectTimeoutRetryCount = 0; + /// Milliseconds since the current (or most recent) connection attempt began. + private int ConnectElapsedMilliseconds() => unchecked(Environment.TickCount - Volatile.Read(ref connectStartTicks)); + private bool DueForConnectRetry() - { - int connectTimeMilliseconds = unchecked(Environment.TickCount - Volatile.Read(ref connectStartTicks)); - return Multiplexer.RawConfig.ReconnectRetryPolicy.ShouldRetry(Volatile.Read(ref connectTimeoutRetryCount), connectTimeMilliseconds); - } + => Multiplexer.RawConfig.ReconnectRetryPolicy.ShouldRetry(Volatile.Read(ref connectTimeoutRetryCount), ConnectElapsedMilliseconds()); internal void OnHeartbeat(bool ifConnectedOnly) { @@ -618,7 +618,13 @@ internal void OnHeartbeat(bool ifConnectedOnly) switch (state) { case State.Connecting: - if (DueForConnectRetry()) + // The retry policy spaces attempts; it must not cut one short while it is still inside its + // ConnectTimeout budget. The default policy (ExponentialRetry at half the connect timeout) + // would otherwise abandon an attempt after 2.5s - less than name resolution alone takes + // when a DNS server is not answering - and then report it as a connect timeout (#2894). + // The socket connect carries its own ConnectTimeout cancellation; this check is what bounds + // TLS and anything after it. + if (ConnectElapsedMilliseconds() >= Multiplexer.RawConfig.ConnectTimeout && DueForConnectRetry()) { Interlocked.Increment(ref connectTimeoutRetryCount); var ex = ExceptionFactory.UnableToConnect(Multiplexer, "ConnectTimeout", Name); diff --git a/tests/StackExchange.Redis.Tests/ConnectionAttemptUnitTests.cs b/tests/StackExchange.Redis.Tests/ConnectionAttemptUnitTests.cs index cb675fb29..cfeb65177 100644 --- a/tests/StackExchange.Redis.Tests/ConnectionAttemptUnitTests.cs +++ b/tests/StackExchange.Redis.Tests/ConnectionAttemptUnitTests.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Collections.Concurrent; using System.ComponentModel; using System.Linq; @@ -118,6 +118,51 @@ public async Task TimedOutAttemptCarriesTheTimeout() } } + [Fact] + public async Task AttemptIsNotAbandonedBeforeConnectTimeout() + { + // never answers the TLS handshake, so every attempt lives until the library gives up on it. The retry policy + // here says "retry after 50ms", but an attempt must still get its full ConnectTimeout: the default policy's + // 2.5s first interval was killing attempts whose name resolution alone took longer than that (#2894) + var listener = new TcpListener(IPAddress.Loopback, 0); // not IDisposable on net481 + listener.Start(); + try + { + const int connectTimeout = 1500; + var options = new ConfigurationOptions + { + EndPoints = { (IPEndPoint)listener.LocalEndpoint }, + Ssl = true, + AbortOnConnectFail = false, + ConnectTimeout = connectTimeout, + HeartbeatInterval = TimeSpan.FromMilliseconds(100), + ReconnectRetryPolicy = new LinearRetry(50), + }; + var attempts = Observe(options); + + await using var conn = await ConnectionMultiplexer.ConnectAsync(options); + + // an abandoned attempt is followed at once by the next, so the gap between consecutive timeouts on one + // connection is how long an attempt was allowed to live + static bool IsInteractiveTimeout(ConnectionAttemptCompletedEventArgs a) + => a.ConnectionType == ConnectionType.Interactive && a.FailureType == ConnectionFailureType.UnableToConnect; + await WaitForAsync(() => attempts.Count(IsInteractiveTimeout) >= 3, timeoutMilliseconds: 20000); + var timedOut = attempts.Where(IsInteractiveTimeout).OrderBy(a => a.SequenceNumber).Take(3).ToArray(); + for (int i = 1; i < timedOut.Length; i++) + { + var lifetime = timedOut[i].CompletedTimeUtc - timedOut[i - 1].CompletedTimeUtc; + output.WriteLine($"attempt lifetime: {lifetime.TotalMilliseconds:0}ms"); + Assert.True( + lifetime >= TimeSpan.FromMilliseconds(connectTimeout - 250), + $"attempt abandoned after {lifetime.TotalMilliseconds:0}ms, inside the {connectTimeout}ms connect timeout"); + } + } + finally + { + listener.Stop(); + } + } + [Fact] public async Task AbandonedAttemptIsNotReportedAsAFailureToConnect() {