Clean up event log strings for ANCM (#4515)

shirhatti · jkotalik · commit 17e5be6fbce4 · 2019-01-16T16:18:01.000-08:00
diff --git a/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/EventLog.cpp b/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/EventLog.cpp
@@ -21,7 +21,7 @@ EventLog::LogEventNoTrace(
     }
     // Static locals to avoid getting the process ID and string multiple times.
     // Effectively have the same semantics as global variables, except initialized
-    // on first occurence.
+    // on first occurrence.
     static const auto processIdString = GetProcessIdString();
     static const auto versionInfoString = GetVersionInfoString();
     
diff --git a/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/aspnetcore_msg.mc b/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/aspnetcore_msg.mc
@@ -63,7 +63,7 @@ Language=English
 .
 
 Messageid=1007
-SymbolicName=ASPNETCORE_EVENT_LOAD_CLR_FALIURE
+SymbolicName=ASPNETCORE_EVENT_LOAD_CLR_FAILURE
 Language=English
 %1
 .
diff --git a/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/resources.h b/src/Servers/IIS/AspNetCoreModuleV2/CommonLib/resources.h
@@ -14,37 +14,36 @@
 #define ASPNETCORE_EVENT_PROCESS_START_SUCCESS_MSG           L"Application '%s' started process '%d' successfully and process '%d' is listening on port '%d'."
 #define ASPNETCORE_EVENT_RAPID_FAIL_COUNT_EXCEEDED_MSG       L"Maximum rapid fail count per minute of '%d' exceeded."
 #define ASPNETCORE_EVENT_PROCESS_START_ERROR_MSG             L"Application '%s' with physical root '%s' failed to start process with commandline '%s' at stage '%s', ErrorCode = '0x%x', assigned port %d, retryCounter '%d'."
-#define ASPNETCORE_EVENT_PROCESS_START_FAILURE_MSG           L"Application '%s' with physical root '%s' failed to start process with commandline '%s' with multiple retries. The last try of listening port is '%d'. See previous warnings for details."
-#define ASPNETCORE_EVENT_PROCESS_START_STATUS_ERROR_MSG      L"Application '%s' with physical root '%s' failed to start process with commandline '%s' , ErrorCode = '0x%x', processId '%d', processStatus '%d'."
+#define ASPNETCORE_EVENT_PROCESS_START_FAILURE_MSG           L"Application '%s' with physical root '%s' failed to start process with commandline '%s' with multiple retries. Failed to bind to port '%d'. See previous warnings for details."
+#define ASPNETCORE_EVENT_PROCESS_START_STATUS_ERROR_MSG      L"Application '%s' with physical root '%s' failed to start process with commandline '%s', ErrorCode = '0x%x', processId '%d', processStatus '%d'."
 #define ASPNETCORE_EVENT_PROCESS_START_PORTSETUP_ERROR_MSG   L"Application '%s' with physical root '%s' failed to choose listen port '%d' given port range '%d - %d', ErrorCode = '0x%x'. If environment variable 'ASPNETCORE_PORT' was set, try removing it such that a random port is selected instead."
 #define ASPNETCORE_EVENT_PROCESS_START_WRONGPORT_ERROR_MSG   L"Application '%s' with physical root '%s' created process with commandline '%s' but failed to listen on the given port '%d'"
-#define ASPNETCORE_EVENT_PROCESS_START_NOTREADY_ERROR_MSG    L"Application '%s' with physical root '%s' created process with commandline '%s' but either crashed or did not respond or did not listen on the given port '%d', ErrorCode = '0x%x'"
+#define ASPNETCORE_EVENT_PROCESS_START_NOTREADY_ERROR_MSG    L"Application '%s' with physical root '%s' created process with commandline '%s' but either crashed, did not respond, or did not listen on the given port '%d', ErrorCode = '0x%x'"
 #define ASPNETCORE_EVENT_PROCESS_SHUTDOWN_MSG                L"Application '%s' with physical root '%s' shut down process with Id '%d' listening on port '%d'"
-#define ASPNETCORE_EVENT_INVALID_STDOUT_LOG_FILE_MSG         L"Warning: Could not create stdoutLogFile %s, ErrorCode = '0x%x'."
-#define ASPNETCORE_EVENT_GRACEFUL_SHUTDOWN_FAILURE_MSG       L"Failed to gracefully shutdown process '%d'."
-#define ASPNETCORE_EVENT_SENT_SHUTDOWN_HTTP_REQUEST_MSG      L"Sent shutdown HTTP message to process '%d' and received http status '%d'."
+#define ASPNETCORE_EVENT_INVALID_STDOUT_LOG_FILE_MSG         L"Could not create stdoutLogFile %s, ErrorCode = '0x%x'."
+#define ASPNETCORE_EVENT_GRACEFUL_SHUTDOWN_FAILURE_MSG       L"Failed to gracefully shutdown process with Id '%d'."
+#define ASPNETCORE_EVENT_SENT_SHUTDOWN_HTTP_REQUEST_MSG      L"Sent shutdown HTTP message to process with Id '%d' and received http status '%d'."
 #define ASPNETCORE_EVENT_APP_SHUTDOWN_FAILURE_MSG            L"Failed to gracefully shutdown application '%s'."
-#define ASPNETCORE_EVENT_LOAD_CLR_FALIURE_MSG                L"Application '%s' with physical root '%s' failed to load clr and managed application. %s"
+#define ASPNETCORE_EVENT_LOAD_CLR_FAILURE_MSG                L"Application '%s' with physical root '%s' failed to load coreclr. Exception message:\r\n%s"
 #define ASPNETCORE_EVENT_APP_SHUTDOWN_SUCCESSFUL_MSG         L"Application '%s' has shutdown."
-#define ASPNETCORE_EVENT_DUPLICATED_INPROCESS_APP_MSG        L"Only one inprocess application is allowed per IIS application pool. Please assign the application '%s' to a different IIS application pool."
+#define ASPNETCORE_EVENT_DUPLICATED_INPROCESS_APP_MSG        L"Only one in-process application is allowed per IIS application pool. Please assign the application '%s' to a different IIS application pool."
 #define ASPNETCORE_EVENT_MIXED_HOSTING_MODEL_ERROR_MSG       L"Mixed hosting model is not supported. Application '%s' configured with different hostingModel value '%d' other than the one of running application(s)."
-#define ASPNETCORE_CONFIGURATION_LOAD_ERROR_MSG              L"Could not load configuration. Exception message: %s"
+#define ASPNETCORE_CONFIGURATION_LOAD_ERROR_MSG              L"Could not load configuration. Exception message:\r\n%s"
 #define ASPNETCORE_EVENT_ADD_APPLICATION_ERROR_MSG           L"Failed to start application '%s', ErrorCode '0x%x'."
-#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_STDOUT_MSG    L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, exit code = '%d'. Last 4KB characters of captured stdout and stderr logs:\r\n%s"
-#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_MSG           L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, exit code = '%d'. Please check the stderr logs for more information."
-#define ASPNETCORE_EVENT_APP_IN_SHUTDOWN_MSG                 L"Application shutting down."
-#define ASPNETCORE_EVENT_RECYCLE_APPOFFLINE_MSG              L"Application '%s' was recycled after detecting the app_offline file."
-#define ASPNETCORE_EVENT_MONITOR_APPOFFLINE_ERROR_MSG        L"Monitoring app_offline.htm failed for application '%s', ErrorCode '0x%x'. "
+#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_STDOUT_MSG    L"Application '%s' with physical root '%s' has exited from Program.Main with exit code = '%d'. Last 30KB characters of captured stdout and stderr logs:\r\n%s"
+#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_MSG           L"Application '%s' with physical root '%s' has exited from Program.Main with exit code = '%d'. Please check the stderr logs for more information."
+#define ASPNETCORE_EVENT_RECYCLE_APPOFFLINE_MSG              L"Application '%s' was recycled after detecting app_offline.htm."
+#define ASPNETCORE_EVENT_MONITOR_APPOFFLINE_ERROR_MSG        L"Failed to monitor app_offline.htm for application '%s', ErrorCode '0x%x'. "
 #define ASPNETCORE_EVENT_RECYCLE_CONFIGURATION_MSG           L"Application '%s' was recycled due to configuration change"
-#define ASPNETCORE_EVENT_RECYCLE_FAILURE_CONFIGURATION_MSG   L"Failed to recycle application due to a configuration change at '%s'. Recycling worker process."
+#define ASPNETCORE_EVENT_RECYCLE_FAILURE_CONFIGURATION_MSG   L"Failed to recycle application after a configuration change at '%s'. Recycling worker process."
 #define ASPNETCORE_EVENT_MODULE_DISABLED_MSG                 L"AspNetCore Module is disabled"
 #define ASPNETCORE_EVENT_HOSTFXR_DLL_INVALID_VERSION_MSG     L"Hostfxr version used does not support 'hostfxr_get_native_search_directories', update the version of hostfxr to a higher version. Path to hostfxr: '%s'."
 #define ASPNETCORE_EVENT_HOSTFXR_DLL_UNABLE_TO_LOAD_MSG      L"Unable to load '%s'. This might be caused by a bitness mismatch between IIS application pool and published application."
-#define ASPNETCORE_EVENT_HOSTFXR_FAILURE_MSG                 L"Invoking hostfxr to find the inprocess request handler failed without finding any native dependencies. This most likely means the app is misconfigured, please check the versions of Microsoft.NetCore.App and Microsoft.AspNetCore.App that are targeted by the application and are installed on the machine."
+#define ASPNETCORE_EVENT_HOSTFXR_FAILURE_MSG                 L"Unable to locate application dependencies. Ensure that the versions of Microsoft.NetCore.App and Microsoft.AspNetCore.App targeted by the application are installed."
 #define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_MSG      L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x'. Please check the stderr logs for more information."
-#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_STDOUT_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x'. Last 4KB characters of captured stdout and stderr logs:\r\n%s"
-#define ASPNETCORE_EVENT_INPROCESS_RH_ERROR_MSG              L"Could not find inprocess request handler. Captured output from invoking hostfxr: %s"
+#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_STDOUT_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x'. Last 30KB characters of captured stdout and stderr logs:\r\n%s"
+#define ASPNETCORE_EVENT_INPROCESS_RH_ERROR_MSG              L"Could not find 'aspnetcorev2_inprocess.dll'. Exception message:\r\n%s"
 #define ASPNETCORE_EVENT_INPROCESS_RH_REFERENCE_MSG          L"Could not find the assembly '%s' referenced for the in-process application. Please confirm the Microsoft.AspNetCore.Server.IIS package is referenced in your application."
 #define ASPNETCORE_EVENT_OUT_OF_PROCESS_RH_MISSING_MSG       L"Could not find the assembly '%s' for out-of-process application. Please confirm the assembly is installed correctly for IIS or IISExpress."
-#define ASPNETCORE_EVENT_INPROCESS_START_SUCCESS_MSG         L"Application '%s' started the coreclr in-process successfully."
-#define ASPNETCORE_EVENT_INPROCESS_START_ERROR_MSG           L"Application '%s' wasn't able to start. %s"
+#define ASPNETCORE_EVENT_INPROCESS_START_SUCCESS_MSG         L"Application '%s' started successfully."
+#define ASPNETCORE_EVENT_INPROCESS_START_ERROR_MSG           L"Application '%s' failed to start. Exception message:\r\n%s"
diff --git a/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp b/src/Servers/IIS/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp
@@ -303,8 +303,8 @@ IN_PROCESS_APPLICATION::ExecuteApplication()
     catch (InvalidOperationException& ex)
     {
         EventLog::Error(
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE,
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE_MSG,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE_MSG,
             QueryApplicationId().c_str(),
             QueryApplicationPhysicalPath().c_str(),
             ex.as_wstring().c_str());
@@ -314,8 +314,8 @@ IN_PROCESS_APPLICATION::ExecuteApplication()
     catch (std::runtime_error& ex)
     {
         EventLog::Error(
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE,
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE_MSG,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE_MSG,
             QueryApplicationId().c_str(),
             QueryApplicationPhysicalPath().c_str(),
             GetUnexpectedExceptionMessage(ex).c_str());
@@ -363,8 +363,8 @@ HRESULT IN_PROCESS_APPLICATION::Start(
     catch (InvalidOperationException& ex)
     {
         EventLog::Error(
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE,
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE_MSG,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE_MSG,
             pHttpApplication.GetApplicationId(),
             pHttpApplication.GetApplicationPhysicalPath(),
             ex.as_wstring().c_str());
@@ -374,8 +374,8 @@ HRESULT IN_PROCESS_APPLICATION::Start(
     catch (std::runtime_error& ex)
     {
         EventLog::Error(
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE,
-            ASPNETCORE_EVENT_LOAD_CLR_FALIURE_MSG,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE,
+            ASPNETCORE_EVENT_LOAD_CLR_FAILURE_MSG,
             pHttpApplication.GetApplicationId(),
             pHttpApplication.GetApplicationPhysicalPath(),
             GetUnexpectedExceptionMessage(ex).c_str());
diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/ConfigurationChangeTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/ConfigurationChangeTests.cs
@@ -83,7 +83,7 @@ public async Task OutOfProcessToInProcessHostingModelSwitchWorks()
             await deploymentResult.HttpClient.RetryRequestAsync("/HelloWorld", r => r.StatusCode == HttpStatusCode.InternalServerError);
 
             StopServer();
-            EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Could not find the assembly 'aspnetcorev2_inprocess.dll'", Logger);
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.CouldNotFindHandler(), Logger);
         }
 
         [ConditionalTheory]
diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Inprocess/EventLogTests.cs
@@ -28,7 +28,7 @@ public async Task CheckStartupEventLogMessage()
 
             StopServer();
 
-            EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Application '.+' started the coreclr in-process successfully.");
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessStarted(deploymentResult));
         }
 
         [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
@@ -61,7 +61,7 @@ public async Task InvalidProcessPath_ExpectServerError(string path, string argum
 
             StopServer();
 
-            EventLogHelpers.VerifyEventLogEvent(deploymentResult, $@"Application '{Regex.Escape(deploymentResult.ContentRoot)}\\' wasn't able to start. {subError}");
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.UnableToStart(deploymentResult, subError));
 
             Assert.Contains("HTTP Error 500.0 - ANCM In-Process Handler Load Failure", await response.Content.ReadAsStringAsync());
         }
diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/MultiApplicationTests.cs
@@ -51,7 +51,7 @@ public async Task FailsAndLogsWhenRunningTwoInProcessApps()
             Assert.Equal(200, (int)result1.StatusCode);
             Assert.Equal(500, (int)result2.StatusCode);
             StopServer();
-            EventLogHelpers.VerifyEventLogEvent(result, "Only one inprocess application is allowed per IIS application pool");
+            EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.OnlyOneAppPerAppPool());
         }
 
         [ConditionalTheory]
diff --git a/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs b/src/Servers/IIS/IIS/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs

Original file line number	Diff line number	Diff line change
`@@ -21,7 +21,7 @@ EventLog::LogEventNoTrace(`
`21`	`21`	`}`
`22`	`22`	`// Static locals to avoid getting the process ID and string multiple times.`
`23`	`23`	`// Effectively have the same semantics as global variables, except initialized`
`24`		`- // on first occurence.`
	`24`	`+ // on first occurrence.`
`25`	`25`	`static const auto processIdString = GetProcessIdString();`
`26`	`26`	`static const auto versionInfoString = GetVersionInfoString();`
`27`	`27`
Original file line number	Diff line number	Diff line change
`@@ -63,7 +63,7 @@ Language=English`
`63`	`63`	`.`
`64`	`64`
`65`	`65`	`Messageid=1007`
`66`		`-SymbolicName=ASPNETCORE_EVENT_LOAD_CLR_FALIURE`
	`66`	`+SymbolicName=ASPNETCORE_EVENT_LOAD_CLR_FAILURE`
`67`	`67`	`Language=English`
`68`	`68`	`%1`
`69`	`69`	`.`
Original file line number	Diff line number	Diff line change
`@@ -83,7 +83,7 @@ public async Task OutOfProcessToInProcessHostingModelSwitchWorks()`
`83`	`83`	`await deploymentResult.HttpClient.RetryRequestAsync("/HelloWorld", r => r.StatusCode == HttpStatusCode.InternalServerError);`
`84`	`84`
`85`	`85`	`StopServer();`
`86`		`- EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Could not find the assembly 'aspnetcorev2_inprocess.dll'", Logger);`
	`86`	`+ EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.CouldNotFindHandler(), Logger);`
`87`	`87`	`}`
`88`	`88`
`89`	`89`	`[ConditionalTheory]`
Original file line number	Diff line number	Diff line change
`@@ -28,7 +28,7 @@ public async Task CheckStartupEventLogMessage()`
`28`	`28`
`29`	`29`	`StopServer();`
`30`	`30`
`31`		`- EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Application '.+' started the coreclr in-process successfully.");`
	`31`	`+ EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessStarted(deploymentResult));`
`32`	`32`	`}`
`33`	`33`
`34`	`34`	`[ConditionalFact]`
Original file line number	Diff line number	Diff line change
`@@ -61,7 +61,7 @@ public async Task InvalidProcessPath_ExpectServerError(string path, string argum`
`61`	`61`
`62`	`62`	`StopServer();`
`63`	`63`
`64`		`- EventLogHelpers.VerifyEventLogEvent(deploymentResult, $@"Application '{Regex.Escape(deploymentResult.ContentRoot)}\\' wasn't able to start. {subError}");`
	`64`	`+ EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.UnableToStart(deploymentResult, subError));`
`65`	`65`
`66`	`66`	`Assert.Contains("HTTP Error 500.0 - ANCM In-Process Handler Load Failure", await response.Content.ReadAsStringAsync());`
`67`	`67`	`}`
Original file line number	Diff line number	Diff line change
`@@ -51,7 +51,7 @@ public async Task FailsAndLogsWhenRunningTwoInProcessApps()`
`51`	`51`	`Assert.Equal(200, (int)result1.StatusCode);`
`52`	`52`	`Assert.Equal(500, (int)result2.StatusCode);`
`53`	`53`	`StopServer();`
`54`		`- EventLogHelpers.VerifyEventLogEvent(result, "Only one inprocess application is allowed per IIS application pool");`
	`54`	`+ EventLogHelpers.VerifyEventLogEvent(result, EventLogHelpers.OnlyOneAppPerAppPool());`
`55`	`55`	`}`
`56`	`56`
`57`	`57`	`[ConditionalTheory]`