From c4f09d71027ab770dddc1fe7edeb970e71183cf3 Mon Sep 17 00:00:00 2001 From: Doug Bunting <6431421+dougbu@users.noreply.github.com> Date: Thu, 24 Mar 2022 20:25:04 -0700 Subject: [PATCH] Increase a few IIS test timeouts - double all `HttpClient.Timeout` values - increate max. `TimeoutAfter(...)` timeout to 15 minutes (from 10) - double values that weren't 10 minutes - double `TestConnection.Timeout` and `IISExpressDeployer.ShutdownTimeSpan` - problems acquiring logs after shutdown seem common - nearly double `TimeoutExtensions.DefaultTimeoutValue` - remove `[Repeat]` on `CheckFrebDisconnect(...)` because it makes test _more_ flaky - check more events in `EventLogHelpers` nit: Update a couple of timeout-related comments --- .../src/Common/DeploymentResult.cs | 6 +++++- .../src/Deployers/NginxDeployer.cs | 1 + .../RemoteWindowsDeployer/RemoteWindowsDeployer.cs | 6 +++--- .../src/Deployers/SelfHostDeployer.cs | 8 ++++---- src/Hosting/TestHost/src/TestServer.cs | 6 +++++- .../IIS/IIS/perf/Microbenchmarks/PlaintextBenchmark.cs | 3 ++- .../IIS/test/Common.FunctionalTests/CompressionTests.cs | 1 + .../IIS/IIS/test/Common.FunctionalTests/FrebTests.cs | 3 --- .../IIS/IIS/test/Common.FunctionalTests/Http2Tests.cs | 6 +++--- .../Infrastructure/EventLogHelpers.cs | 2 +- .../test/Common.FunctionalTests/Infrastructure/Helpers.cs | 6 +++++- src/Servers/IIS/IIS/test/Common.LongTests/StartupTests.cs | 3 ++- .../test/IIS.FunctionalTests/Http2TrailersResetTests.cs | 4 ++-- .../IIS/IIS/test/IIS.FunctionalTests/Http3Tests.cs | 2 +- .../IIS/IIS/test/IIS.Tests/Utilities/TestServer.cs | 3 ++- .../InProcess/WebSocketTests.cs | 4 ++-- .../test/testassets/IIS.Common.TestLib/TestConnections.cs | 2 +- .../testassets/IIS.Common.TestLib/TimeoutExtensions.cs | 2 +- .../IIS/IISIntegration/test/Tests/IISMiddlewareTests.cs | 8 ++++---- .../IIS/IntegrationTesting.IIS/src/IISDeploymentResult.cs | 3 ++- .../IIS/IntegrationTesting.IIS/src/IISExpressDeployer.cs | 8 ++++---- 21 files changed, 51 insertions(+), 36 deletions(-) diff --git a/src/Hosting/Server.IntegrationTesting/src/Common/DeploymentResult.cs b/src/Hosting/Server.IntegrationTesting/src/Common/DeploymentResult.cs index dc7101c5f512..588c30e58bbc 100644 --- a/src/Hosting/Server.IntegrationTesting/src/Common/DeploymentResult.cs +++ b/src/Hosting/Server.IntegrationTesting/src/Common/DeploymentResult.cs @@ -62,5 +62,9 @@ public DeploymentResult(ILoggerFactory loggerFactory, DeploymentParameters deplo /// /// public HttpClient CreateHttpClient(HttpMessageHandler baseHandler) => - new HttpClient(new LoggingHandler(_loggerFactory, baseHandler)) { BaseAddress = new Uri(ApplicationBaseUri) }; + new HttpClient(new LoggingHandler(_loggerFactory, baseHandler)) + { + BaseAddress = new Uri(ApplicationBaseUri), + Timeout = TimeSpan.FromSeconds(200), + }; } diff --git a/src/Hosting/Server.IntegrationTesting/src/Deployers/NginxDeployer.cs b/src/Hosting/Server.IntegrationTesting/src/Deployers/NginxDeployer.cs index a004b07b121d..9c09a94445e8 100644 --- a/src/Hosting/Server.IntegrationTesting/src/Deployers/NginxDeployer.cs +++ b/src/Hosting/Server.IntegrationTesting/src/Deployers/NginxDeployer.cs @@ -77,6 +77,7 @@ public override async Task DeployAsync() // Target actual address to avoid going through Nginx proxy using (var httpClient = new HttpClient()) { + httpClient.Timeout = TimeSpan.FromSeconds(200); var response = await RetryHelper.RetryRequest(() => { return httpClient.GetAsync(redirectUri); diff --git a/src/Hosting/Server.IntegrationTesting/src/Deployers/RemoteWindowsDeployer/RemoteWindowsDeployer.cs b/src/Hosting/Server.IntegrationTesting/src/Deployers/RemoteWindowsDeployer/RemoteWindowsDeployer.cs index 40b5cd1bcc9f..b7b828937575 100644 --- a/src/Hosting/Server.IntegrationTesting/src/Deployers/RemoteWindowsDeployer/RemoteWindowsDeployer.cs +++ b/src/Hosting/Server.IntegrationTesting/src/Deployers/RemoteWindowsDeployer/RemoteWindowsDeployer.cs @@ -1,4 +1,4 @@ -// Licensed to the .NET Foundation under one or more agreements. +// 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; @@ -254,8 +254,8 @@ private async Task RunScriptAsync(string serverAction) runScriptsOnRemoteServerProcess.StartAndCaptureOutAndErrToLogger(serverAction, Logger); - // Wait a second for the script to run or fail. The StartServer script will only terminate when the Deployer is disposed, - // so we don't want to wait for it to terminate here because it would deadlock. + // Wait a minute for the script to run or fail. The StartServer script will only terminate when the + // Deployer is disposed, so we don't want to wait for it to terminate here because it would deadlock. await Task.Delay(TimeSpan.FromMinutes(1)); if (runScriptsOnRemoteServerProcess.HasExited && runScriptsOnRemoteServerProcess.ExitCode != 0) diff --git a/src/Hosting/Server.IntegrationTesting/src/Deployers/SelfHostDeployer.cs b/src/Hosting/Server.IntegrationTesting/src/Deployers/SelfHostDeployer.cs index bc299b4363f2..1abae50c7931 100644 --- a/src/Hosting/Server.IntegrationTesting/src/Deployers/SelfHostDeployer.cs +++ b/src/Hosting/Server.IntegrationTesting/src/Deployers/SelfHostDeployer.cs @@ -192,10 +192,10 @@ public override async Task DeployAsync() // Host may not write startup messages, in which case assume it started if (DeploymentParameters.StatusMessagesEnabled) { - // The timeout here is large, because we don't know how long the test could need - // We cover a lot of error cases above, but I want to make sure we eventually give up and don't hang the build - // just in case we missed one -anurse - await started.Task.TimeoutAfter(TimeSpan.FromMinutes(10)); + // The timeout here is large, because we don't know how long the test could need. We cover a lot + // of error cases above, but I want to make sure we eventually give up and don't hang the build + // just in case we missed one. + await started.Task.TimeoutAfter(TimeSpan.FromMinutes(15)); } return (url: actualUrl ?? hintUrl, hostExitToken: hostExitTokenSource.Token); diff --git a/src/Hosting/TestHost/src/TestServer.cs b/src/Hosting/TestHost/src/TestServer.cs index c012b7a004b2..ed6ab6eb699e 100644 --- a/src/Hosting/TestHost/src/TestServer.cs +++ b/src/Hosting/TestHost/src/TestServer.cs @@ -152,7 +152,11 @@ public HttpMessageHandler CreateHandler() /// public HttpClient CreateClient() { - return new HttpClient(CreateHandler()) { BaseAddress = BaseAddress }; + return new HttpClient(CreateHandler()) + { + BaseAddress = BaseAddress, + Timeout = TimeSpan.FromSeconds(200), + }; } /// diff --git a/src/Servers/IIS/IIS/perf/Microbenchmarks/PlaintextBenchmark.cs b/src/Servers/IIS/IIS/perf/Microbenchmarks/PlaintextBenchmark.cs index ee38cb158816..a98b53326b05 100644 --- a/src/Servers/IIS/IIS/perf/Microbenchmarks/PlaintextBenchmark.cs +++ b/src/Servers/IIS/IIS/perf/Microbenchmarks/PlaintextBenchmark.cs @@ -27,7 +27,8 @@ public void Setup() // Recreate client, TestServer.Client has additional logging that can hurt performance _client = new HttpClient() { - BaseAddress = _server.HttpClient.BaseAddress + BaseAddress = _server.HttpClient.BaseAddress, + Timeout = TimeSpan.FromSeconds(200), }; } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/CompressionTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/CompressionTests.cs index cc8f46bbb93a..20278b0aa13f 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/CompressionTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/CompressionTests.cs @@ -130,6 +130,7 @@ public async Task DynamicResponsesAreCompressed() var client = new HttpClient(handler) { BaseAddress = _fixture.Client.BaseAddress, + Timeout = TimeSpan.FromSeconds(200), }; client.DefaultRequestHeaders.AcceptEncoding.Add(new StringWithQualityHeaderValue("gzip")); client.DefaultRequestHeaders.AcceptEncoding.Add(new StringWithQualityHeaderValue("identity", 0)); diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/FrebTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/FrebTests.cs index 24cceea63a58..ea01504eca59 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/FrebTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/FrebTests.cs @@ -90,10 +90,7 @@ public async Task CheckFailedRequestEvents() AssertFrebLogs(result, new FrebLogItem("ANCM_INPROC_ASYNC_COMPLETION_COMPLETION", "2")); } - // I think this test is flaky due to freb file not being created quickly enough. - // Adding extra logging, marking as flaky, and repeating should help [ConditionalFact] - [Repeat(10)] [RequiresIIS(IISCapability.FailedRequestTracingModule)] public async Task CheckFrebDisconnect() { diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Http2Tests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Http2Tests.cs index e069cc29765c..34906e32e402 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Http2Tests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Http2Tests.cs @@ -356,7 +356,7 @@ public async Task Reset_Http1_NotSupported() { var handler = new HttpClientHandler(); handler.ServerCertificateCustomValidationCallback = HttpClientHandler.DangerousAcceptAnyServerCertificateValidator; - using HttpClient client = new HttpClient(handler); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(200) }; client.DefaultRequestVersion = HttpVersion.Version11; var response = await client.GetStringAsync(Fixture.Client.BaseAddress + "Reset_Http1_NotSupported"); Assert.Equal("Hello World", response); @@ -370,7 +370,7 @@ public async Task Reset_PriorOSVersions_NotSupported() { var handler = new HttpClientHandler(); handler.ServerCertificateCustomValidationCallback = HttpClientHandler.DangerousAcceptAnyServerCertificateValidator; - using HttpClient client = new HttpClient(handler); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(200) }; client.DefaultRequestVersion = HttpVersion.Version20; var response = await client.GetStringAsync(Fixture.Client.BaseAddress + "Reset_PriorOSVersions_NotSupported"); Assert.Equal("Hello World", response); @@ -390,7 +390,7 @@ private async Task SendRequestAsync(string uri, bool http2 var handler = new HttpClientHandler(); handler.MaxResponseHeadersLength = 128; handler.ServerCertificateCustomValidationCallback = HttpClientHandler.DangerousAcceptAnyServerCertificateValidator; - using var client = new HttpClient(handler); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(200) }; client.DefaultRequestVersion = http2 ? HttpVersion.Version20 : HttpVersion.Version11; return await client.GetAsync(uri); } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/EventLogHelpers.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/EventLogHelpers.cs index a6b41e9e074f..2830ffaed2fa 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/EventLogHelpers.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/EventLogHelpers.cs @@ -88,7 +88,7 @@ private static IEnumerable GetEntries(IISDeploymentResult deploym var processIdString = $"Process Id: {deploymentResult.HostProcess.Id}."; // Event log messages round down to the nearest second, so subtract 5 seconds to make sure we get event logs - var processStartTime = deploymentResult.HostProcess.StartTime.AddSeconds(-5); + var processStartTime = deploymentResult.HostProcess.StartTime.AddSeconds(-10); for (var i = eventLog.Entries.Count - 1; i >= 0; i--) { var eventLogEntry = eventLog.Entries[i]; diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/Helpers.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/Helpers.cs index af3e945d1f54..c4681bfbb869 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/Helpers.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Infrastructure/Helpers.cs @@ -40,7 +40,11 @@ public static async Task StressLoad(HttpClient httpClient, string path, Action SendRequestAsync(string uri, bool http2 var handler = new HttpClientHandler(); handler.MaxResponseHeadersLength = 128; handler.ServerCertificateCustomValidationCallback = HttpClientHandler.DangerousAcceptAnyServerCertificateValidator; - using var client = new HttpClient(handler); + using var client = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(200) }; client.DefaultRequestVersion = http2 ? HttpVersion.Version20 : HttpVersion.Version11; return await client.GetAsync(uri); } diff --git a/src/Servers/IIS/IIS/test/IIS.FunctionalTests/Http3Tests.cs b/src/Servers/IIS/IIS/test/IIS.FunctionalTests/Http3Tests.cs index 41f4fec31179..be5022389b1e 100644 --- a/src/Servers/IIS/IIS/test/IIS.FunctionalTests/Http3Tests.cs +++ b/src/Servers/IIS/IIS/test/IIS.FunctionalTests/Http3Tests.cs @@ -173,6 +173,6 @@ private HttpClient SetUpClient() var handler = new HttpClientHandler(); // Needed on CI, the IIS Express cert we use isn't trusted there. handler.ServerCertificateCustomValidationCallback = HttpClientHandler.DangerousAcceptAnyServerCertificateValidator; - return new HttpClient(handler); + return new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(200) }; } } diff --git a/src/Servers/IIS/IIS/test/IIS.Tests/Utilities/TestServer.cs b/src/Servers/IIS/IIS/test/IIS.Tests/Utilities/TestServer.cs index 3bedbf730b40..a4bd602edce1 100644 --- a/src/Servers/IIS/IIS/test/IIS.Tests/Utilities/TestServer.cs +++ b/src/Servers/IIS/IIS/test/IIS.Tests/Utilities/TestServer.cs @@ -106,7 +106,8 @@ private void Start() HttpClient = new HttpClient(new LoggingHandler(new SocketsHttpHandler(), _loggerFactory.CreateLogger())) { - BaseAddress = BaseUri + BaseAddress = BaseUri, + Timeout = TimeSpan.FromSeconds(200), }; } diff --git a/src/Servers/IIS/IIS/test/IISExpress.FunctionalTests/InProcess/WebSocketTests.cs b/src/Servers/IIS/IIS/test/IISExpress.FunctionalTests/InProcess/WebSocketTests.cs index 5911a68b89ad..65da17c28266 100644 --- a/src/Servers/IIS/IIS/test/IISExpress.FunctionalTests/InProcess/WebSocketTests.cs +++ b/src/Servers/IIS/IIS/test/IISExpress.FunctionalTests/InProcess/WebSocketTests.cs @@ -31,7 +31,7 @@ public WebSocketsTests(IISTestSiteFixture fixture) [ConditionalFact] public async Task RequestWithBody_NotUpgradable() { - using var client = new HttpClient(); + using var client = new HttpClient() { Timeout = TimeSpan.FromSeconds(200) }; using var response = await client.PostAsync(_requestUri + "WebSocketNotUpgradable", new StringContent("Hello World")); response.EnsureSuccessStatusCode(); } @@ -39,7 +39,7 @@ public async Task RequestWithBody_NotUpgradable() [ConditionalFact] public async Task RequestWithoutBody_Upgradable() { - using var client = new HttpClient(); + using var client = new HttpClient() { Timeout = TimeSpan.FromSeconds(200) }; // POST with Content-Length: 0 counts as not having a body. using var response = await client.PostAsync(_requestUri + "WebSocketUpgradable", new StringContent("")); response.EnsureSuccessStatusCode(); diff --git a/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TestConnections.cs b/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TestConnections.cs index f61a24d09911..5e470444ed81 100644 --- a/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TestConnections.cs +++ b/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TestConnections.cs @@ -20,7 +20,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting; /// public class TestConnection : IDisposable { - private static readonly TimeSpan Timeout = TimeSpan.FromMinutes(1); + private static readonly TimeSpan Timeout = TimeSpan.FromMinutes(2); private readonly bool _ownsSocket; private readonly Socket _socket; diff --git a/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TimeoutExtensions.cs b/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TimeoutExtensions.cs index 1031829c1558..6651f4cf5aaa 100644 --- a/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TimeoutExtensions.cs +++ b/src/Servers/IIS/IIS/test/testassets/IIS.Common.TestLib/TimeoutExtensions.cs @@ -10,5 +10,5 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting; public static class TimeoutExtensions { - public static TimeSpan DefaultTimeoutValue = TimeSpan.FromSeconds(300); + public static TimeSpan DefaultTimeoutValue = TimeSpan.FromMinutes(10); } diff --git a/src/Servers/IIS/IISIntegration/test/Tests/IISMiddlewareTests.cs b/src/Servers/IIS/IISIntegration/test/Tests/IISMiddlewareTests.cs index 15fb0ec4d489..d431f8925bc8 100644 --- a/src/Servers/IIS/IISIntegration/test/Tests/IISMiddlewareTests.cs +++ b/src/Servers/IIS/IISIntegration/test/Tests/IISMiddlewareTests.cs @@ -135,7 +135,7 @@ public async Task MiddlewareShutsdownGivenANCMShutdown(string pathBase, string r request.Headers.TryAddWithoutValidation("MS-ASPNETCORE-EVENT", shutdownEvent); var response = await server.CreateClient().SendAsync(request); - await applicationStoppingFired.Task.TimeoutAfter(TimeSpan.FromSeconds(5)); + await applicationStoppingFired.Task.TimeoutAfter(TimeSpan.FromSeconds(10)); Assert.False(requestExecuted.Task.IsCompleted); Assert.Equal(HttpStatusCode.Accepted, response.StatusCode); } @@ -195,7 +195,7 @@ public async Task MiddlewareIgnoresShutdownGivenWrongMethod(HttpMethod method) var response = await server.CreateClient().SendAsync(request); Assert.False(applicationStoppingFired.Task.IsCompleted); - await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(1)); + await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(2)); Assert.Equal(HttpStatusCode.OK, response.StatusCode); } @@ -240,7 +240,7 @@ public async Task MiddlewareIgnoresShutdownGivenWrongPath(string path) var response = await server.CreateClient().SendAsync(request); Assert.False(applicationStoppingFired.Task.IsCompleted); - await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(1)); + await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(2)); Assert.Equal(HttpStatusCode.OK, response.StatusCode); } @@ -285,7 +285,7 @@ public async Task MiddlewareIgnoresShutdownGivenWrongEvent(string shutdownEvent) var response = await server.CreateClient().SendAsync(request); Assert.False(applicationStoppingFired.Task.IsCompleted); - await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(1)); + await requestExecuted.Task.TimeoutAfter(TimeSpan.FromSeconds(2)); Assert.Equal(HttpStatusCode.OK, response.StatusCode); } diff --git a/src/Servers/IIS/IntegrationTesting.IIS/src/IISDeploymentResult.cs b/src/Servers/IIS/IntegrationTesting.IIS/src/IISDeploymentResult.cs index b81c145ee710..043852daa874 100644 --- a/src/Servers/IIS/IntegrationTesting.IIS/src/IISDeploymentResult.cs +++ b/src/Servers/IIS/IntegrationTesting.IIS/src/IISDeploymentResult.cs @@ -33,7 +33,8 @@ public HttpClient CreateClient(HttpMessageHandler messageHandler) { return new HttpClient(new LoggingHandler(messageHandler, Logger)) { - BaseAddress = base.HttpClient.BaseAddress + BaseAddress = base.HttpClient.BaseAddress, + Timeout = TimeSpan.FromSeconds(200), }; } diff --git a/src/Servers/IIS/IntegrationTesting.IIS/src/IISExpressDeployer.cs b/src/Servers/IIS/IntegrationTesting.IIS/src/IISExpressDeployer.cs index 927222da0feb..9c3b101371c9 100644 --- a/src/Servers/IIS/IntegrationTesting.IIS/src/IISExpressDeployer.cs +++ b/src/Servers/IIS/IntegrationTesting.IIS/src/IISExpressDeployer.cs @@ -21,7 +21,7 @@ public class IISExpressDeployer : IISDeployerBase private const string FailedToInitializeBindingsMessage = "Failed to initialize site bindings"; private const string UnableToStartIISExpressMessage = "Unable to start iisexpress."; private const int MaximumAttempts = 5; - private readonly TimeSpan ShutdownTimeSpan = Debugger.IsAttached ? TimeSpan.FromMinutes(60) : TimeSpan.FromMinutes(1); + private readonly TimeSpan ShutdownTimeSpan = Debugger.IsAttached ? TimeSpan.FromMinutes(60) : TimeSpan.FromMinutes(2); private static readonly Regex UrlDetectorRegex = new Regex(@"^\s*Successfully registered URL ""(?[^""]+)"" for site.*$"); private Process _hostProcess; @@ -234,10 +234,10 @@ private string CheckIfPublishIsRequired() } // Wait for the app to start - // The timeout here is large, because we don't know how long the test could need - // We cover a lot of error cases above, but I want to make sure we eventually give up and don't hang the build + // The timeout here is large, because we don't know how long the test could need. We cover a lot + // of error cases above, but I want to make sure we eventually give up and don't hang the build // just in case we missed one -anurse - if (!await started.Task.TimeoutAfter(TimeSpan.FromMinutes(10))) + if (!await started.Task.TimeoutAfter(TimeSpan.FromMinutes(15))) { Logger.LogInformation("iisexpress Process {pid} failed to bind to port {port}, trying again", process.Id, port);