From f34e87042c544b4c084466689d911079141433d9 Mon Sep 17 00:00:00 2001 From: Andrew Stanton-Nurse Date: Fri, 9 Jun 2017 11:26:06 -0700 Subject: [PATCH] extend timeout and more logging (#183) --- test/AutobahnTestApp/Program.cs | 18 ++++++- test/AutobahnTestApp/Startup.cs | 18 +++---- .../Autobahn/AutobahnTester.cs | 48 ++++++++++++++++++- .../AutobahnTests.cs | 41 +++++++++------- 4 files changed, 97 insertions(+), 28 deletions(-) diff --git a/test/AutobahnTestApp/Program.cs b/test/AutobahnTestApp/Program.cs index 2ec9a97b96..ddd340a6e0 100644 --- a/test/AutobahnTestApp/Program.cs +++ b/test/AutobahnTestApp/Program.cs @@ -1,6 +1,7 @@ -using System; +using System; using System.IO; using System.Net; +using System.Runtime.Loader; using Microsoft.AspNetCore.Hosting; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; @@ -11,6 +12,7 @@ namespace AutobahnTestApp { public static void Main(string[] args) { + var scenarioName = "Unknown"; var config = new ConfigurationBuilder() .AddCommandLine(args) .Build(); @@ -24,6 +26,7 @@ namespace AutobahnTestApp if (string.Equals(builder.GetSetting("server"), "Microsoft.AspNetCore.Server.HttpSys", System.StringComparison.Ordinal)) { + scenarioName = "HttpSysServer"; Console.WriteLine("Using HttpSys server"); builder.UseHttpSys(); } @@ -31,6 +34,7 @@ namespace AutobahnTestApp { // ANCM is hosting the process. // The port will not yet be configured at this point, but will also not require HTTPS. + scenarioName = "AspNetCoreModule"; Console.WriteLine("Detected ANCM, using Kestrel"); builder.UseKestrel(); } @@ -55,15 +59,27 @@ namespace AutobahnTestApp { if (uri.Scheme.Equals("https", StringComparison.OrdinalIgnoreCase)) { + scenarioName = "Kestrel(SSL)"; var certPath = Path.Combine(AppContext.BaseDirectory, "TestResources", "testCert.pfx"); Console.WriteLine($"Using SSL with certificate: {certPath}"); listenOptions.UseHttps(certPath, "testPassword"); } + else + { + scenarioName = "Kestrel(NonSSL)"; + } }); }); } var host = builder.Build(); + + AppDomain.CurrentDomain.UnhandledException += (_, a) => + { + Console.WriteLine($"Unhandled exception (Scenario: {scenarioName}): {a.ExceptionObject.ToString()}"); + }; + + Console.WriteLine($"Starting Server for Scenario: {scenarioName}"); host.Run(); } } diff --git a/test/AutobahnTestApp/Startup.cs b/test/AutobahnTestApp/Startup.cs index 671d503968..f244e76358 100644 --- a/test/AutobahnTestApp/Startup.cs +++ b/test/AutobahnTestApp/Startup.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Net.WebSockets; using System.Threading; using System.Threading.Tasks; @@ -22,8 +22,10 @@ namespace AutobahnTestApp if (context.WebSockets.IsWebSocketRequest) { logger.LogInformation("Received WebSocket request"); - var webSocket = await context.WebSockets.AcceptWebSocketAsync(); - await Echo(webSocket); + using (var webSocket = await context.WebSockets.AcceptWebSocketAsync()) + { + await Echo(webSocket, context.RequestAborted); + } } else { @@ -35,16 +37,16 @@ namespace AutobahnTestApp } - private async Task Echo(WebSocket webSocket) + private async Task Echo(WebSocket webSocket, CancellationToken cancellationToken) { var buffer = new byte[1024 * 4]; - var result = await webSocket.ReceiveAsync(new ArraySegment(buffer), CancellationToken.None); + var result = await webSocket.ReceiveAsync(new ArraySegment(buffer), cancellationToken); while (!result.CloseStatus.HasValue) { - await webSocket.SendAsync(new ArraySegment(buffer, 0, result.Count), result.MessageType, result.EndOfMessage, CancellationToken.None); - result = await webSocket.ReceiveAsync(new ArraySegment(buffer), CancellationToken.None); + await webSocket.SendAsync(new ArraySegment(buffer, 0, result.Count), result.MessageType, result.EndOfMessage, cancellationToken); + result = await webSocket.ReceiveAsync(new ArraySegment(buffer), cancellationToken); } - await webSocket.CloseAsync(result.CloseStatus.Value, result.CloseStatusDescription, CancellationToken.None); + await webSocket.CloseAsync(result.CloseStatus.Value, result.CloseStatusDescription, cancellationToken); } } } diff --git a/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/Autobahn/AutobahnTester.cs b/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/Autobahn/AutobahnTester.cs index 52fdae6b7a..18b3dd49a5 100644 --- a/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/Autobahn/AutobahnTester.cs +++ b/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/Autobahn/AutobahnTester.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Collections.Generic; using System.IO; using System.Linq; @@ -16,6 +16,7 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn public class AutobahnTester : IDisposable { private readonly List _deployers = new List(); + private readonly List _deployments = new List(); private readonly List _expectations = new List(); private readonly ILoggerFactory _loggerFactory; private readonly ILogger _logger; @@ -35,6 +36,10 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn var specFile = Path.GetTempFileName(); try { + // Start pinging the servers to see that they're still running + var pingCts = new CancellationTokenSource(); + var pinger = new Timer(state => Pinger((CancellationToken)state), pingCts.Token, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(10)); + Spec.WriteJson(specFile); // Run the test (write something to the console so people know this will take a while...) @@ -44,6 +49,8 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn { throw new Exception("wstest failed"); } + + pingCts.Cancel(); } finally { @@ -63,6 +70,42 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn } } + // Async void! It's OK here because we are running in a timer. We're just using async void to chain continuations. + // There's nobody to await this, hence async void. + private async void Pinger(CancellationToken token) + { + try + { + while (!token.IsCancellationRequested) + { + try + { + foreach (var deployment in _deployments) + { + if (token.IsCancellationRequested) + { + return; + } + + var resp = await deployment.HttpClient.GetAsync("/ping", token); + if (!resp.IsSuccessStatusCode) + { + _logger.LogWarning("Non-successful response when pinging {url}: {statusCode} {reasonPhrase}", deployment.ApplicationBaseUri, resp.StatusCode, resp.ReasonPhrase); + } + } + } + catch (OperationCanceledException) + { + // We don't want to throw when the token fires, just stop. + } + } + } + catch (Exception ex) + { + _logger.LogError(ex, "Error while pinging servers"); + } + } + public void Verify(AutobahnResult result) { var failures = new StringBuilder(); @@ -104,6 +147,7 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn var deployer = ApplicationDeployerFactory.Create(parameters, _loggerFactory); var result = await deployer.DeployAsync(); _deployers.Add(deployer); + _deployments.Add(result); cancellationToken.ThrowIfCancellationRequested(); var handler = new HttpClientHandler(); @@ -114,7 +158,7 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn // See https://github.com/dotnet/corefx/issues/9728 handler.ServerCertificateCustomValidationCallback = (_, __, ___, ____) => true; } - var client = new HttpClient(handler); + var client = result.CreateHttpClient(handler); // Make sure the server works var resp = await RetryHelper.RetryRequest(() => diff --git a/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/AutobahnTests.cs b/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/AutobahnTests.cs index d24d36764d..6ef652be4f 100644 --- a/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/AutobahnTests.cs +++ b/test/Microsoft.AspNetCore.WebSockets.ConformanceTest/AutobahnTests.cs @@ -1,4 +1,4 @@ -using System; +using System; using System.Diagnostics; using System.IO; using System.Runtime.InteropServices; @@ -7,6 +7,7 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Server.IntegrationTesting; using Microsoft.AspNetCore.Testing.xunit; using Microsoft.AspNetCore.WebSockets.ConformanceTest.Autobahn; +using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Testing; using Xunit.Abstractions; @@ -14,6 +15,8 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest { public class AutobahnTests : LoggedTest { + private static readonly TimeSpan TestTimeout = TimeSpan.FromMinutes(3); + public AutobahnTests(ITestOutputHelper output) : base(output) { } @@ -26,6 +29,7 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest { using (StartLog(out var loggerFactory)) { + var logger = loggerFactory.CreateLogger(); var reportDir = Environment.GetEnvironmentVariable("AUTOBAHN_SUITES_REPORT_DIR"); var outDir = !string.IsNullOrEmpty(reportDir) ? reportDir : @@ -44,28 +48,31 @@ namespace Microsoft.AspNetCore.WebSockets.ConformanceTest .ExcludeCase("9.*", "12.*", "13.*"); var cts = new CancellationTokenSource(); - cts.CancelAfter(TimeSpan.FromMinutes(5)); // These tests generally complete in just over 1 minute. + cts.CancelAfter(TestTimeout); // These tests generally complete in just over 1 minute. - AutobahnResult result; - using (var tester = new AutobahnTester(loggerFactory, spec)) + using (cts.Token.Register(() => logger.LogError("Test run is taking longer than maximum duration of {timeoutMinutes:0.00} minutes. Aborting...", TestTimeout.TotalMinutes))) { - await tester.DeployTestAndAddToSpec(ServerType.Kestrel, ssl: false, environment: "ManagedSockets", cancellationToken: cts.Token); - - // Windows-only WebListener tests, and Kestrel SSL tests (due to: https://github.com/aspnet/WebSockets/issues/102) - if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) + AutobahnResult result; + using (var tester = new AutobahnTester(loggerFactory, spec)) { - await tester.DeployTestAndAddToSpec(ServerType.Kestrel, ssl: true, environment: "ManagedSockets", cancellationToken: cts.Token); + await tester.DeployTestAndAddToSpec(ServerType.Kestrel, ssl: false, environment: "ManagedSockets", cancellationToken: cts.Token); - if (IsWindows8OrHigher()) + // Windows-only WebListener tests, and Kestrel SSL tests (due to: https://github.com/aspnet/WebSockets/issues/102) + if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) { - // WebListener occasionally gives a non-strict response on 3.2. IIS Express seems to have the same behavior. Wonder if it's related to HttpSys? - // For now, just allow the non-strict response, it's not a failure. - await tester.DeployTestAndAddToSpec(ServerType.WebListener, ssl: false, environment: "ManagedSockets", cancellationToken: cts.Token); - } - } + await tester.DeployTestAndAddToSpec(ServerType.Kestrel, ssl: true, environment: "ManagedSockets", cancellationToken: cts.Token); - result = await tester.Run(cts.Token); - tester.Verify(result); + if (IsWindows8OrHigher()) + { + // WebListener occasionally gives a non-strict response on 3.2. IIS Express seems to have the same behavior. Wonder if it's related to HttpSys? + // For now, just allow the non-strict response, it's not a failure. + await tester.DeployTestAndAddToSpec(ServerType.WebListener, ssl: false, environment: "ManagedSockets", cancellationToken: cts.Token); + } + } + + result = await tester.Run(cts.Token); + tester.Verify(result); + } } // If it hasn't been cancelled yet, cancel the token just to be sure