From 3246e0ab0ca7a7a9cdee9907d27e22f25bd19ade Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Sun, 6 Aug 2023 22:04:44 +0800 Subject: [PATCH] Support infinite idle connection timeout values (#2231) --- .../SocketConnectivitySubchannelTransport.cs | 2 +- src/Grpc.Net.Client/GrpcChannel.cs | 23 +++++++++- .../Balancer/ConnectionTests.cs | 45 ++++++++++++++++--- test/FunctionalTests/FunctionalTestBase.cs | 8 ++-- .../Grpc.Net.Client.Tests/GrpcChannelTests.cs | 32 ++++++++++--- 5 files changed, 92 insertions(+), 18 deletions(-) diff --git a/src/Grpc.Net.Client/Balancer/Internal/SocketConnectivitySubchannelTransport.cs b/src/Grpc.Net.Client/Balancer/Internal/SocketConnectivitySubchannelTransport.cs index 0528f0306..4a28c8b50 100644 --- a/src/Grpc.Net.Client/Balancer/Internal/SocketConnectivitySubchannelTransport.cs +++ b/src/Grpc.Net.Client/Balancer/Internal/SocketConnectivitySubchannelTransport.cs @@ -332,7 +332,7 @@ public async ValueTask GetStreamAsync(BalancerAddress address, Cancellat var closeSocket = false; - if (DateTime.UtcNow > socketCreatedTime.Value.Add(_socketIdleTimeout)) + if (_socketIdleTimeout != Timeout.InfiniteTimeSpan && DateTime.UtcNow > socketCreatedTime.Value.Add(_socketIdleTimeout)) { SocketConnectivitySubchannelTransportLog.ClosingSocketFromIdleTimeoutOnCreateStream(_logger, _subchannel.Id, address, _socketIdleTimeout); closeSocket = true; diff --git a/src/Grpc.Net.Client/GrpcChannel.cs b/src/Grpc.Net.Client/GrpcChannel.cs index 84fa0ea69..159f6de6e 100644 --- a/src/Grpc.Net.Client/GrpcChannel.cs +++ b/src/Grpc.Net.Client/GrpcChannel.cs @@ -255,7 +255,7 @@ private static HttpHandlerContext CalculateHandlerContext(ILogger logger, Uri ad type = HttpHandlerType.SocketsHttpHandler; connectTimeout = socketsHttpHandler.ConnectTimeout; - connectionIdleTimeout = socketsHttpHandler.PooledConnectionIdleTimeout; + connectionIdleTimeout = GetConnectionIdleTimeout(socketsHttpHandler); // Check if the SocketsHttpHandler is being shared by channels. // It has already been setup by another channel (i.e. ConnectCallback is set) then @@ -300,6 +300,27 @@ private static HttpHandlerContext CalculateHandlerContext(ILogger logger, Uri ad } return new HttpHandlerContext(HttpHandlerType.Custom); + +#if NET5_0_OR_GREATER + static TimeSpan? GetConnectionIdleTimeout(SocketsHttpHandler socketsHttpHandler) + { + // Check if either TimeSpan is InfiniteTimeSpan, and return the other one. + if (socketsHttpHandler.PooledConnectionIdleTimeout == Timeout.InfiniteTimeSpan) + { + return socketsHttpHandler.PooledConnectionLifetime; + } + + if (socketsHttpHandler.PooledConnectionLifetime == Timeout.InfiniteTimeSpan) + { + return socketsHttpHandler.PooledConnectionIdleTimeout; + } + + // Return the bigger TimeSpan. + return socketsHttpHandler.PooledConnectionIdleTimeout > socketsHttpHandler.PooledConnectionLifetime + ? socketsHttpHandler.PooledConnectionIdleTimeout + : socketsHttpHandler.PooledConnectionLifetime; + } +#endif } #if NET5_0_OR_GREATER diff --git a/test/FunctionalTests/Balancer/ConnectionTests.cs b/test/FunctionalTests/Balancer/ConnectionTests.cs index 22754901f..61d55c173 100644 --- a/test/FunctionalTests/Balancer/ConnectionTests.cs +++ b/test/FunctionalTests/Balancer/ConnectionTests.cs @@ -141,8 +141,9 @@ async Task UnaryMethod(HelloRequest request, ServerCallContext conte await ExceptionAssert.ThrowsAsync(() => connectTask).DefaultTimeout(); } - [Test] - public async Task Active_UnaryCall_ConnectionIdleTimeout_SocketRecreated() + [TestCase(0)] // TimeSpan.Zero + [TestCase(1000)] // 1 second + public async Task Active_UnaryCall_ConnectionIdleTimeout_SocketRecreated(int milliseconds) { // Ignore errors SetExpectedErrorsFilter(writeContext => @@ -158,7 +159,7 @@ Task UnaryMethod(HelloRequest request, ServerCallContext context) // Arrange using var endpoint = BalancerHelpers.CreateGrpcEndpoint(50051, UnaryMethod, nameof(UnaryMethod), loggerFactory: LoggerFactory); - var connectionIdleTimeout = TimeSpan.FromSeconds(1); + var connectionIdleTimeout = TimeSpan.FromMilliseconds(milliseconds); var channel = await BalancerHelpers.CreateChannel( LoggerFactory, new PickFirstConfig(), @@ -168,7 +169,8 @@ Task UnaryMethod(HelloRequest request, ServerCallContext context) Logger.LogInformation("Connecting channel."); await channel.ConnectAsync(); - await Task.Delay(connectionIdleTimeout); + // Wait for timeout plus a little extra to avoid issues from imprecise timers. + await Task.Delay(connectionIdleTimeout + TimeSpan.FromMilliseconds(50)); var client = TestClientFactory.Create(channel, endpoint.Method); var response = await client.UnaryCall(new HelloRequest { Name = "Test!" }).ResponseAsync.DefaultTimeout(); @@ -176,10 +178,43 @@ Task UnaryMethod(HelloRequest request, ServerCallContext context) // Assert Assert.AreEqual("Test!", response.Message); - AssertHasLog(LogLevel.Debug, "ClosingSocketFromIdleTimeoutOnCreateStream", "Subchannel id '1' socket 127.0.0.1:50051 is being closed because it exceeds the idle timeout of 00:00:01."); + AssertHasLog(LogLevel.Debug, "ClosingSocketFromIdleTimeoutOnCreateStream"); AssertHasLog(LogLevel.Trace, "ConnectingOnCreateStream", "Subchannel id '1' doesn't have a connected socket available. Connecting new stream socket for 127.0.0.1:50051."); } + public async Task Active_UnaryCall_InfiniteConnectionIdleTimeout_SocketNotClosed() + { + SetExpectedErrorsFilter(writeContext => + { + return true; + }); + + Task UnaryMethod(HelloRequest request, ServerCallContext context) + { + return Task.FromResult(new HelloReply { Message = request.Name }); + } + + // Arrange + using var endpoint = BalancerHelpers.CreateGrpcEndpoint(50051, UnaryMethod, nameof(UnaryMethod), loggerFactory: LoggerFactory); + + var channel = await BalancerHelpers.CreateChannel( + LoggerFactory, + new PickFirstConfig(), + new[] { endpoint.Address }, + connectionIdleTimeout: Timeout.InfiniteTimeSpan).DefaultTimeout(); + + Logger.LogInformation("Connecting channel."); + await channel.ConnectAsync(); + + var client = TestClientFactory.Create(channel, endpoint.Method); + var response = await client.UnaryCall(new HelloRequest { Name = "Test!" }).ResponseAsync.DefaultTimeout(); + + // Assert + Assert.AreEqual("Test!", response.Message); + + Assert.IsFalse(Logs.Any(l => l.EventId.Name == "ClosingSocketFromIdleTimeoutOnCreateStream"), "Shouldn't have a ClosingSocketFromIdleTimeoutOnCreateStream log."); + } + [Test] public async Task Active_UnaryCall_ServerCloseOnKeepAlive_SocketRecreatedOnRequest() { diff --git a/test/FunctionalTests/FunctionalTestBase.cs b/test/FunctionalTests/FunctionalTestBase.cs index 7136a6b17..e4fe0acc6 100644 --- a/test/FunctionalTests/FunctionalTestBase.cs +++ b/test/FunctionalTests/FunctionalTestBase.cs @@ -119,21 +119,21 @@ protected void AssertHasLogRpcConnectionError(StatusCode statusCode, string deta AssertHasLog(LogLevel.Information, "RpcConnectionError", $"Error status code '{statusCode}' with detail '{detail}' raised."); } - protected void AssertHasLog(LogLevel logLevel, string name, string message, Func? exceptionMatch = null) + protected void AssertHasLog(LogLevel logLevel, string name, string? message = null, Func? exceptionMatch = null) { if (HasLog(logLevel, name, message, exceptionMatch)) { return; } - Assert.Fail($"No match. Log level = {logLevel}, name = {name}, message = '{message}'."); + Assert.Fail($"No match. Log level = {logLevel}, name = {name}, message = '{message ?? "(null)"}'."); } - protected bool HasLog(LogLevel logLevel, string name, string message, Func? exceptionMatch = null) + protected bool HasLog(LogLevel logLevel, string name, string? message = null, Func? exceptionMatch = null) { return Logs.Any(r => { - var match = r.LogLevel == logLevel && r.EventId.Name == name && r.Message == message; + var match = r.LogLevel == logLevel && r.EventId.Name == name && (r.Message == message || message == null); if (exceptionMatch != null) { match = match && r.Exception != null && exceptionMatch(r.Exception); diff --git a/test/Grpc.Net.Client.Tests/GrpcChannelTests.cs b/test/Grpc.Net.Client.Tests/GrpcChannelTests.cs index 2e2e376ef..47ea88743 100644 --- a/test/Grpc.Net.Client.Tests/GrpcChannelTests.cs +++ b/test/Grpc.Net.Client.Tests/GrpcChannelTests.cs @@ -222,17 +222,35 @@ public void Build_ConnectTimeout_ReadFromSocketsHttpHandler() Assert.AreEqual(TimeSpan.FromSeconds(1), channel.ConnectTimeout); } - [Test] - public void Build_ConnectionIdleTimeout_ReadFromSocketsHttpHandler() + [TestCase(-1, -1, -1)] + [TestCase(0, 0, 0)] + [TestCase(0, -1, 0)] + [TestCase(-1, 0, 0)] + [TestCase(1000, -1, 1000)] + [TestCase(-1, 1000, 1000)] + [TestCase(500, 1000, 1000)] + [TestCase(1000, 500, 1000)] + public void Build_ConnectionIdleTimeout_ReadFromSocketsHttpHandler( + int? pooledConnectionIdleTimeoutMs, + int? pooledConnectionLifetimeMs, + int expectedConnectionIdleTimeoutMs) { - // Arrange & Act - var channel = GrpcChannel.ForAddress("https://localhost", CreateGrpcChannelOptions(o => o.HttpHandler = new SocketsHttpHandler + // Arrange + var handler = new SocketsHttpHandler(); + if (pooledConnectionIdleTimeoutMs != null) { - PooledConnectionIdleTimeout = TimeSpan.FromSeconds(1) - })); + handler.PooledConnectionIdleTimeout = TimeSpan.FromMilliseconds(pooledConnectionIdleTimeoutMs.Value); + } + if (pooledConnectionLifetimeMs != null) + { + handler.PooledConnectionLifetime = TimeSpan.FromMilliseconds(pooledConnectionLifetimeMs.Value); + } + + // Act + var channel = GrpcChannel.ForAddress("https://localhost", CreateGrpcChannelOptions(o => o.HttpHandler = handler)); // Assert - Assert.AreEqual(TimeSpan.FromSeconds(1), channel.ConnectionIdleTimeout); + Assert.AreEqual(TimeSpan.FromMilliseconds(expectedConnectionIdleTimeoutMs), channel.ConnectionIdleTimeout); } #endif