Add event logs for some startup failure cases (#1081)

src/AspNetCoreModuleV2/AspNetCore/aspnetcore_shim_config.cpp

@@ -3,6 +3,7 @@
 
 #include "aspnetcore_shim_config.h"
 
+#include "EventLog.h"
 #include "config_utility.h"
 #include "hostfxr_utility.h"
 #include "ahutil.h"
@@ -49,6 +50,7 @@ ASPNETCORE_SHIM_CONFIG::Populate(
     else
     {
         // block unknown hosting value
+        EVENTLOG(g_hEventLog, UNKNOWN_HOSTING_MODEL_ERROR, strHostingModel.QueryStr());
         RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_NOT_SUPPORTED));
     }
 

src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj

@@ -195,6 +195,7 @@
     <ClInclude Include="application.h" />
     <ClInclude Include="config_utility.h" />
     <ClInclude Include="Environment.h" />
+    <ClInclude Include="EventLog.h" />
     <ClInclude Include="exceptions.h" />
     <ClInclude Include="GlobalVersionUtility.h" />
     <ClInclude Include="fx_ver.h" />

src/AspNetCoreModuleV2/CommonLib/aspnetcore_msg.mc

@@ -231,6 +231,12 @@ Language=English
 %1
 .
 
+Messageid=1034
+SymbolicName=ASPNETCORE_EVENT_UNKNOWN_HOSTING_MODEL_ERROR
+Language=English
+%1
+.
+
 ;
 ;#endif     // _ASPNETCORE_MODULE_MSG_H_
 ;

src/AspNetCoreModuleV2/CommonLib/hostfxr_utility.cpp

@@ -141,7 +141,9 @@ HOSTFXR_UTILITY::GetHostFxrParameters(
         auto fullProcessPath = GetAbsolutePathToDotnet(applicationPhysicalPath, processPath);
         if (!fullProcessPath.has_value())
         {
-            return E_FAIL;
+            hr = HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND);
+            EVENTLOG(hEventLog, INVALID_PROCESS_PATH, processPath.c_str(), hr);
+            return hr;
         }
 
         processPath = fullProcessPath.value();
@@ -149,7 +151,8 @@ HOSTFXR_UTILITY::GetHostFxrParameters(
         auto hostFxrPath = GetAbsolutePathToHostFxr(processPath, hEventLog);
         if (!hostFxrPath.has_value())
         {
-            return E_FAIL;
+            hr = HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND);
+            return hr;
         }
 
         RETURN_IF_FAILED(HOSTFXR_UTILITY::ParseHostfxrArguments(
@@ -368,6 +371,8 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
     // Only do it if no path is specified
     if (requestedPath.has_parent_path())
     {
+        WLOG_INFOF(L"Absolute path to dotnet.exe was not found at %s", requestedPath.c_str());
+
         return std::nullopt;
     }
 

src/AspNetCoreModuleV2/CommonLib/resources.h

@@ -29,6 +29,8 @@
 #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_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_EVENT_UNKNOWN_HOSTING_MODEL_ERROR_MSG     L"Unknown hosting model '%s'. Please specify either hostingModel=\"inprocess\" or hostingModel=\"outofprocess\" in the web.config file."
+#define ASPNETCORE_EVENT_UNKNOWN_HOSTING_MODEL_ERROR_LEVEL   EVENTLOG_ERROR_TYPE
 #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, ErrorCode = '0x%x. 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, ErrorCode = '0x%x. Please check the stderr logs for more information."
@@ -49,7 +51,7 @@
 #define ASPNETCORE_EVENT_APPLICATION_EXE_NOT_FOUND_MSG       L"Could not find application executable in '%s'. ErrorCode = '0x%x'."
 #define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_MSG      L"Application '%s' with physical root '%s' hit unexpected managed exception, ErrorCode = '0x%x. Please check the stderr logs for more information."
 #define ASPNETCORE_EVENT_INVALID_PROCESS_PATH_LEVEL          EVENTLOG_ERROR_TYPE
-#define ASPNETCORE_EVENT_INVALID_PROCESS_PATH_MSG            L"Invalid or unknown processPath provided in web.config: processPath = %s, ErrorCode = '0x%x'."
+#define ASPNETCORE_EVENT_INVALID_PROCESS_PATH_MSG            L"Invalid or unknown processPath provided in web.config: processPath = '%s', ErrorCode = '0x%x'."
 #define ASPNETCORE_EVENT_INPROCESS_RH_MISSING_MSG            L"Could not find the assembly '%s' for 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."

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISApplication.cs

@@ -71,26 +71,12 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting
 
                 ConfigureAppHostConfig(contentRoot);
 
-                if (_deploymentParameters.ApplicationType == ApplicationType.Portable)
-                {
-                    ModifyAspNetCoreSectionInWebConfig("processPath", DotNetCommands.GetDotNetExecutable(_deploymentParameters.RuntimeArchitecture));
-                }
-
                 _serverManager.CommitChanges();
 
                 await WaitUntilSiteStarted(apppool);
             }
         }
 
-        private void ModifyAspNetCoreSectionInWebConfig(string key, string value)
-        {
-            var webConfigFile = Path.Combine(_deploymentParameters.PublishedApplicationRootPath, "web.config");
-            var config = XDocument.Load(webConfigFile);
-            var element = config.Descendants("aspNetCore").FirstOrDefault();
-            element.SetAttributeValue(key, value);
-            config.Save(webConfigFile);
-        }
-
         private async Task WaitUntilSiteStarted(ApplicationPool appPool)
         {
             var sw = Stopwatch.StartNew();

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployer.cs

@@ -61,6 +61,15 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 // For now, only support using published output
                 DeploymentParameters.PublishApplicationBeforeDeployment = true;
 
+
+                if (DeploymentParameters.ApplicationType == ApplicationType.Portable)
+                {
+                    DefaultWebConfigActions.Add(
+                        WebConfigHelpers.AddOrModifyAspNetCoreSection(
+                            "processPath",
+                            DotNetCommands.GetDotNetExecutable(DeploymentParameters.RuntimeArchitecture)));
+                }
+
                 if (DeploymentParameters.PublishApplicationBeforeDeployment)
                 {
                     DotnetPublish();

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployerBase.cs

@@ -2,6 +2,7 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
 using System.IO;
 using System.Linq;
@@ -15,6 +16,8 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
     {
         public IISDeploymentParameters IISDeploymentParameters { get; }
 
+        protected List<Action<XElement>> DefaultWebConfigActions { get; } = new List<Action<XElement>>();
+
         public IISDeployerBase(IISDeploymentParameters deploymentParameters, ILoggerFactory loggerFactory)
             : base(deploymentParameters, loggerFactory)
         {
@@ -36,6 +39,12 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             var path = Path.Combine(DeploymentParameters.PublishedApplicationRootPath, "web.config");
             var webconfig = XDocument.Load(path);
             var xElement = webconfig.Descendants("system.webServer").Single();
+
+            foreach (var action in DefaultWebConfigActions)
+            {
+                action.Invoke(xElement);
+            }
+
             foreach (var action in IISDeploymentParameters.WebConfigActionList)
             {
                 action.Invoke(xElement);
@@ -44,6 +53,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             webconfig.Save(path);
         }
 
+
         public string RunServerConfigActions(string serverConfigString)
         {
             if (IISDeploymentParameters == null)

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeploymentParameterExtensions.cs

@@ -2,8 +2,6 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
-using System.Collections.Generic;
-using System.IO;
 using System.Linq;
 using System.Xml.Linq;
 
@@ -22,23 +20,6 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             parameters.ServerConfigActionList.Add(action);
         }
 
-        public static void ModifyWebConfig(this IISDeploymentParameters parameters, Action<XElement> transform)
-        {
-            parameters.WebConfigActionList.Add(transform);
-        }
-
-        public static void ModifyAspNetCoreSectionInWebConfig(this IISDeploymentParameters parameters, string key, string value)
-            => ModifyAttributeInWebConfig(parameters, key, value, section: "aspNetCore");
-
-
-        public static void ModifyAttributeInWebConfig(this IISDeploymentParameters parameters, string key, string value, string section)
-        {
-            parameters.WebConfigActionList.Add((element) =>
-            {
-                element.Descendants(section).SingleOrDefault().SetAttributeValue(key, value);
-            });
-        }
-
         public static void AddHttpsToServerConfig(this IISDeploymentParameters parameters)
         {
             parameters.ServerConfigActionList.Add(
@@ -64,17 +45,5 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                         .SetAttributeValue("enabled", "true");
                 });
         }
-
-        public static void ModifyHandlerSectionInWebConfig(this IISDeploymentParameters parameters, string key, string value)
-        {
-            parameters.WebConfigActionList.Add(element =>
-            {
-                element.Descendants("handlers")
-                        .FirstOrDefault()
-                        .Descendants("add")
-                        .FirstOrDefault()
-                        .SetAttributeValue(key, value);
-            });
-        }
     }
 }

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISExpressDeployer.cs

@@ -280,9 +280,13 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             if (DeploymentParameters.PublishApplicationBeforeDeployment)
             {
                 // For published apps, prefer the content in the web.config, but update it.
-                IISDeploymentParameters.ModifyAspNetCoreSectionInWebConfig(key: "hostingModel",
+                DefaultWebConfigActions.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection(
-                    value: DeploymentParameters.HostingModel == HostingModel.InProcess ? "inprocess" : "");
+                    key: "hostingModel",
-                IISDeploymentParameters.ModifyHandlerSectionInWebConfig(key: "modules", value: DeploymentParameters.AncmVersion.ToString());
+                    value: DeploymentParameters.HostingModel == HostingModel.InProcess ? "inprocess" : ""));
+
+                DefaultWebConfigActions.Add(WebConfigHelpers.AddOrModifyHandlerSection(
+                    key: "modules",
+                    value: DeploymentParameters.AncmVersion.ToString()));
                 ModifyDotNetExePathInWebConfig();
                 serverConfig = RemoveRedundantElements(serverConfig);
                 RunWebConfigActions();
@@ -464,7 +468,8 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 {
                     throw new Exception($"Unable to find '{executableName}'.'");
                 }
-                IISDeploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", executableName);
+                DefaultWebConfigActions.Add(
+                    WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", executableName));
             }
         }
 

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/WebConfigHelpers.cs

@@ -0,0 +1,35 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using System.Linq;
+using System.Xml.Linq;
+
+namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
+{
+    public static class WebConfigHelpers
+    {
+        public static Action<XElement> AddOrModifyAspNetCoreSection(string key, string value)
+            => AddAction(key, value, section: "aspNetCore");
+
+        public static Action<XElement> AddAction(string key, string value, string section)
+        {
+            return (element) =>
+            {
+                element.Descendants(section).SingleOrDefault().SetAttributeValue(key, value);
+            };
+        }
+
+        public static Action<XElement> AddOrModifyHandlerSection(string key, string value)
+        {
+            return element =>
+            {
+                element.Descendants("handlers")
+                        .FirstOrDefault()
+                        .Descendants("add")
+                        .FirstOrDefault()
+                        .SetAttributeValue(key, value);
+            };
+        }
+    }
+}

test/Common.FunctionalTests/Inprocess/EventLogTests.cs

@@ -1,4 +1,6 @@
-using System;
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
 using System.Net;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities;

test/Common.FunctionalTests/Inprocess/LoggingTests.cs

@@ -23,10 +23,12 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         {
             var deploymentParameters = Helpers.GetBaseDeploymentParameters(publish: true);
 
-            deploymentParameters.ModifyAspNetCoreSectionInWebConfig("stdoutLogEnabled", "true");
+            deploymentParameters.WebConfigActionList.Add(
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogEnabled", "true"));
 
             var pathToLogs = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());
-            deploymentParameters.ModifyAspNetCoreSectionInWebConfig("stdoutLogFile", Path.Combine(pathToLogs, "std"));
+            deploymentParameters.WebConfigActionList.Add(
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogFile", Path.Combine(pathToLogs, "std")));
 
             var deploymentResult = await DeployAsync(deploymentParameters);
 
@@ -63,8 +65,10 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         {
             var deploymentParameters = Helpers.GetBaseDeploymentParameters(publish: true);
 
-            deploymentParameters.ModifyAspNetCoreSectionInWebConfig("stdoutLogEnabled", "true");
+            deploymentParameters.WebConfigActionList.Add(
-            deploymentParameters.ModifyAspNetCoreSectionInWebConfig("stdoutLogFile", Path.Combine("Q:", "std"));
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogEnabled", "true"));
+            deploymentParameters.WebConfigActionList.Add(
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogFile", Path.Combine("Q:", "std")));
 
             var deploymentResult = await DeployAsync(deploymentParameters);
 

test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs

@@ -2,11 +2,9 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
-using System.Collections.Generic;
 using System.Net;
 using System.Threading.Tasks;
 using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities;
-using Microsoft.AspNetCore.Server.IntegrationTesting.IIS;
 using Microsoft.AspNetCore.Testing.xunit;
 using Xunit;
 

test/IISExpress.FunctionalTests/InProcess/StartupTests.cs

@@ -31,7 +31,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 deploymentParameters =>
                 {
                     deploymentParameters.EnvironmentVariables["DotnetPath"] = _dotnetLocation;
-                    deploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", "%DotnetPath%");
+                    deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", "%DotnetPath%"));
                 }
             );
         }
@@ -43,13 +43,16 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task InvalidProcessPath_ExpectServerError(string path)
         {
             var deploymentParameters = GetBaseDeploymentParameters();
-            deploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", path);
+            deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", path));
+
 
             var deploymentResult = await DeployAsync(deploymentParameters);
 
             var response = await deploymentResult.RetryingHttpClient.GetAsync("HelloWorld");
 
             Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode);
+
+            EventLogHelpers.VerifyEventLogEvent(TestSink, @"Invalid or unknown processPath provided in web\.config: processPath = '.+', ErrorCode = '0x80070002'\.");
         }
 
         [ConditionalFact]
@@ -60,7 +63,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             await AssertStarts(
                 deploymentParameters =>
                 {
-                    deploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", dotnetLocationWithoutExtension);
+                    deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", dotnetLocationWithoutExtension));
                 }
             );
         }
@@ -72,7 +75,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             await AssertStarts(
                 deploymentParameters =>
                 {
-                    deploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", dotnetLocationWithoutExtension);
+                    deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", dotnetLocationWithoutExtension));
                 }
             );
         }
@@ -86,7 +89,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 deploymentParameters =>
                 {
                     deploymentParameters.EnvironmentVariables["PATH"] = Path.GetDirectoryName(_dotnetLocation);
-                    deploymentParameters.ModifyAspNetCoreSectionInWebConfig("processPath", path);
+                    deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("processPath", path));
                 }
             );
 
@@ -144,6 +147,21 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             Assert.Contains(TestSink.Writes, context => context.Message.Contains("Application is running inside IIS process but is not configured to use IIS server"));
         }
 
+        [ConditionalFact]
+        public async Task CheckInvalidHostingModelParameter()
+        {
+            var deploymentParameters = GetBaseDeploymentParameters();
+            deploymentParameters.WebConfigActionList.Add(WebConfigHelpers.AddOrModifyAspNetCoreSection("hostingModel", "bogus"));
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            var response = await deploymentResult.RetryingHttpClient.GetAsync("HelloWorld");
+
+            Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode);
+
+            EventLogHelpers.VerifyEventLogEvent(TestSink, "Unknown hosting model 'bogus'. Please specify either hostingModel=\"inprocess\" or hostingModel=\"outofprocess\" in the web.config file.");
+        }
+
         // Defaults to inprocess specific deployment parameters
         public static IISDeploymentParameters GetBaseDeploymentParameters(string site = "InProcessWebSite")
         {