From a673be3b9a2464cb20351f381e189a43beb6f426 Mon Sep 17 00:00:00 2001 From: Pavel Krymets Date: Thu, 14 Mar 2019 11:59:45 -0700 Subject: [PATCH] Log all event log entries when assert fails (#8491) --- .../Common.FunctionalTests/AppOfflineTests.cs | 2 +- .../Inprocess/EventLogTests.cs | 6 +++--- .../Inprocess/LogPipeTests.cs | 2 +- .../Inprocess/StartupExceptionTests.cs | 4 ++-- .../Inprocess/StartupTests.cs | 4 ++-- .../Common.FunctionalTests/LogFileTests.cs | 8 ++++---- .../MultiApplicationTests.cs | 4 ++-- .../Utilities/EventLogHelpers.cs | 18 +++++------------- .../Inprocess/StdOutRedirectionTests.cs | 10 +++++----- .../ServicesTests.cs | 4 ++-- 10 files changed, 27 insertions(+), 35 deletions(-) diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/AppOfflineTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/AppOfflineTests.cs index ab5e39748e..9a46ef82be 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/AppOfflineTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/AppOfflineTests.cs @@ -223,7 +223,7 @@ namespace Microsoft.AspNetCore.Server.IIS.FunctionalTests // Shutdown should be graceful here! EventLogHelpers.VerifyEventLogEvent(deploymentResult, - EventLogHelpers.InProcessShutdown()); + EventLogHelpers.InProcessShutdown(), Logger); } [ConditionalFact] diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs index 194a1fca83..168e7bc642 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs @@ -22,13 +22,13 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests public async Task CheckStartupEventLogMessage() { var deploymentParameters = _fixture.GetBaseDeploymentParameters(); - + var deploymentResult = await DeployAsync(deploymentParameters); await deploymentResult.AssertStarts(); StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessStarted(deploymentResult)); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessStarted(deploymentResult), Logger); } [ConditionalFact] @@ -40,7 +40,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Application '.+' has shutdown."); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Application '.+' has shutdown.", Logger); } } } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/LogPipeTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/LogPipeTests.cs index ff52881d52..47fd6fa425 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/LogPipeTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/LogPipeTests.cs @@ -77,7 +77,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode); StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)")); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)"), Logger); } } } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs index a5eaf1bda0..6d544cf8cd 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs @@ -34,7 +34,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests await AssertFailsToStart(deploymentResult); var expectedString = new string('a', 30000); Assert.Contains(TestSink.Writes, context => context.Message.Contains(expectedString)); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", expectedString)); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", expectedString), Logger); } [ConditionalTheory] @@ -56,7 +56,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests var expectedString = new string('a', 30000); Assert.Contains(expectedString, contents); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", expectedString)); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", expectedString), Logger); } [ConditionalFact] diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs index 78eef04c73..9803dfeed9 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/StartupTests.cs @@ -62,7 +62,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.UnableToStart(deploymentResult, subError)); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.UnableToStart(deploymentResult, subError), Logger); Assert.Contains("HTTP Error 500.0 - ANCM In-Process Handler Load Failure", await response.Content.ReadAsStringAsync()); } @@ -167,7 +167,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, "AspNetCore Module is disabled"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "AspNetCore Module is disabled", Logger); } } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/LogFileTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/LogFileTests.cs index 9f6353fa1f..f4f9b53b00 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/LogFileTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/LogFileTests.cs @@ -78,7 +78,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests if (variant.HostingModel == HostingModel.InProcess) { // Error is getting logged twice, from shim and handler - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.CouldNotStartStdoutFileRedirection("Q:\\std", deploymentResult), allowMultiple: true); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.CouldNotStartStdoutFileRedirection("Q:\\std", deploymentResult), Logger, allowMultiple: true); } } @@ -169,7 +169,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests deploymentParameters.HandlerSettings["debugLevel"] = "file,eventlog"; var deploymentResult = await StartAsync(deploymentParameters); StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, @"\[aspnetcorev2.dll\] Initializing logs for .*?Description: IIS ASP.NET Core Module V2"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, @"\[aspnetcorev2.dll\] Initializing logs for .*?Description: IIS ASP.NET Core Module V2", Logger); } [ConditionalTheory] @@ -197,11 +197,11 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests if (variant.HostingModel == HostingModel.InProcess) { - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)")); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)"), Logger); } else { - EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.OutOfProcessFailedToStart(deploymentResult)); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.OutOfProcessFailedToStart(deploymentResult), Logger); } } diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs index 1745fac1cd..f1f0bf163a 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs @@ -51,7 +51,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests Assert.Equal(200, (int)result1.StatusCode); Assert.Equal(500, (int)result2.StatusCode); StopServer(); - EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.OnlyOneAppPerAppPool()); + EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.OnlyOneAppPerAppPool(), Logger); } [ConditionalTheory] @@ -72,7 +72,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests Assert.Equal(200, (int)result1.StatusCode); Assert.Equal(500, (int)result2.StatusCode); StopServer(); - EventLogHelpers.VerifyEventLogEvent(result, "Mixed hosting model is not supported."); + EventLogHelpers.VerifyEventLogEvent(result, "Mixed hosting model is not supported.", Logger); } private void SetHostingModel(string directory, HostingModel model) diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs index 0bd9c196db..92874f15c8 100644 --- a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs +++ b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs @@ -15,30 +15,22 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests { public class EventLogHelpers { - public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, string expectedRegexMatchString, bool allowMultiple = false) - { - Assert.True(deploymentResult.HostProcess.HasExited); - - var entries = GetEntries(deploymentResult); - AssertEntry(expectedRegexMatchString, entries, allowMultiple); - } - - public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, string expectedRegexMatchString, ILogger logger) + public static void VerifyEventLogEvent(IISDeploymentResult deploymentResult, string expectedRegexMatchString, ILogger logger, bool allowMultiple = false) { Assert.True(deploymentResult.HostProcess.HasExited); var entries = GetEntries(deploymentResult); try { - AssertEntry(expectedRegexMatchString, entries); + AssertEntry(expectedRegexMatchString, entries, allowMultiple); } - catch (Exception ex) + catch (Exception) { foreach (var entry in entries) { - logger.LogInformation(entry.Message); + logger.LogInformation("'{Message}', generated {Generated}, written {Written}", entry.Message, entry.TimeGenerated, entry.TimeWritten); } - throw ex; + throw; } } diff --git a/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/Inprocess/StdOutRedirectionTests.cs b/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/Inprocess/StdOutRedirectionTests.cs index 0c69b551e5..80b7881d2e 100644 --- a/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/Inprocess/StdOutRedirectionTests.cs +++ b/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/Inprocess/StdOutRedirectionTests.cs @@ -40,7 +40,7 @@ namespace IIS.FunctionalTests.Inprocess StopServer(); EventLogHelpers.VerifyEventLogEvent(deploymentResult, - "The specified framework 'Microsoft.NETCore.App', version '2.9.9' was not found."); + "The specified framework 'Microsoft.NETCore.App', version '2.9.9' was not found.", Logger); } [ConditionalFact] @@ -63,7 +63,7 @@ namespace IIS.FunctionalTests.Inprocess var contents = Helpers.ReadAllTextFromFile(Helpers.GetExpectedLogName(deploymentResult, _logFolderPath), Logger); var expectedString = "The specified framework 'Microsoft.NETCore.App', version '2.9.9' was not found."; - EventLogHelpers.VerifyEventLogEvent(deploymentResult, expectedString); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, expectedString, Logger); Assert.Contains(expectedString, contents); } @@ -89,7 +89,7 @@ namespace IIS.FunctionalTests.Inprocess var fileInDirectory = Directory.GetFiles(_logFolderPath).Single(); var contents = Helpers.ReadAllTextFromFile(fileInDirectory, Logger); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr", Logger); Assert.Contains("Invoked hostfxr", contents); } @@ -114,7 +114,7 @@ namespace IIS.FunctionalTests.Inprocess StopServer(); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr", Logger); } [ConditionalTheory] @@ -143,7 +143,7 @@ namespace IIS.FunctionalTests.Inprocess var fileInDirectory = Directory.GetFiles(_logFolderPath).First(); var contents = Helpers.ReadAllTextFromFile(fileInDirectory, Logger); - EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Invoked hostfxr", Logger); Assert.Contains("Invoked hostfxr", contents); } } diff --git a/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/ServicesTests.cs b/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/ServicesTests.cs index 6659d38d35..6b777aae57 100644 --- a/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/ServicesTests.cs +++ b/src/Servers/IIS/IIS/test/IIS.Shared.FunctionalTests/ServicesTests.cs @@ -44,7 +44,7 @@ namespace IIS.FunctionalTests await Helpers.Retry(async () => await File.ReadAllTextAsync(Path.Combine(result.ContentRoot, "Started.txt")), TimeoutExtensions.DefaultTimeoutValue); StopServer(); - EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.Started(result)); + EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.Started(result), Logger); } } @@ -73,7 +73,7 @@ namespace IIS.FunctionalTests await Helpers.Retry(async () => await File.ReadAllTextAsync(Path.Combine(result.ContentRoot, "Started.txt")), TimeoutExtensions.DefaultTimeoutValue); StopServer(); - EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.Started(result)); + EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.Started(result), Logger); } }