Aspnetcore: 2.2.0 IIS Hosting Bundle 500.30 error when setting web.config ASPNETCORE_ENVIRONMENT

[pholly]

Describe the bug

We get a HTTP Error 500.30 - ANCM In-Process Start Failure after upgrading to asp.net core 2.2

To Reproduce

Steps to reproduce the behavior:

1. Install the latest Windows 2.2.0 hosting bundle (aspnetcore.dll 12.2.18316) on Windows server
2. Create an asp.net core 2.2 web app with inprocess hosting
3. Add a web.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <!-- To customize the asp.net core module uncomment and edit the following section. 
  For more info see https://go.microsoft.com/fwlink/?linkid=838655 -->
  <system.webServer>
    <handlers>
      <remove name="aspNetCore" />
      <add name="aspNetCore" path="*" verb="*" modules="AspNetCoreModuleV2" resourceType="Unspecified" />
    </handlers>
    <aspNetCore processPath="%LAUNCHER_PATH%" arguments="%LAUNCHER_ARGS%" stdoutLogEnabled="false" stdoutLogFile=".\logs\stdout" hostingModel="InProcess"/>
  </system.webServer>
</configuration>

1. Run the site using IIS Express
2. Verify environment variables were added to your web.config:

<aspNetCore processPath="%LAUNCHER_PATH%" arguments="%LAUNCHER_ARGS%" stdoutLogEnabled="false" stdoutLogFile=".\logs\stdout" hostingModel="InProcess">
      <environmentVariables>
        <environmentVariable name="ASPNETCORE_HTTPS_PORT" value="44368" />
        <environmentVariable name="ASPNETCORE_ENVIRONMENT" value="Development" />
      </environmentVariables>
    </aspNetCore>

1. On the server, create the site in IIS and then set an ASPNETCORE_ENVIRONMENT variable in machine-wide IIS applicationhost.config for the site
2. Publish to the server and hit the site
3. See the error
4. I verified that if I remove the web.config environmentVariable named ASPNETCORE_ENVIRONMENT the site loads. Adding other web.config environment variables does not cause any problems.

Expected behavior

The site should start

Additional context

We set our ASPNETCORE_ENVIRONMENT environment variables for our sites in IIS applicationhost.config. I got the error for a site with "STAGING" set in applicationhost.config. I verified that even if I set the same value to "STAGING" in web.config the site will not start.

We use shared applicationhost.config, but I don't think that's pertinent.

The issue could obviously be duplicated without running the site in IIS Express first - as long as the ASPNETCORE_ENVIRONMENT variable is in web.config the site will not be able to startup on the server if that variable is also set in applicationhost.config. I have not confirmed that the site works if there is no ASPNETCORE_ENVIRONMENT variable set for the site in applicationhost.config.

If there is no web.config in the Visual Studio project or if a default one is added which is all commented out a web.config is not created or modified when running the site in IIS Express.

This did not error in asp.net core 2.1.

I enabled logging in web.config and added a logs folder and a stdout logfile was created but it was empty.

I worked around this by removing the environment variable from web.config before publishing.

Cross-reference: https://github.com/aspnet/Docs/issues/10046

[pholly]

@guardrex showed me how to enable ancm debug logging (https://docs.microsoft.com/aspnet/core/host-and-deploy/iis/troubleshoot#enable-the-aspnet-core-module-debug-log).

Log:

[aspnetcorev2.dll] Initializing logs for 'C:\Program Files\IIS\Asp.Net Core Module\V2\aspnetcorev2.dll'. Process Id: 6900.. File Version: 12.2.18316.0. Description: IIS ASP.NET Core Module V2. Commit: ce8cf65589734f82b0536c543aba5bd60d0a5a98.
[aspnetcorev2.dll] Resolving hostfxr parameters for application: '.\LibraryApi.exe' arguments: '' path: 'D:\inetpub\wwwroot\apistage.municode.com\site\'
[aspnetcorev2.dll] Known dotnet.exe location: ''
[aspnetcorev2.dll] Process path '.\LibraryApi.exe' is not dotnet, treating application as standalone or portable with bootstrapper
[aspnetcorev2.dll] Checking application.dll at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\LibraryApi.dll'
[aspnetcorev2.dll] Checking hostfxr.dll at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll'
[aspnetcorev2.dll] hostfxr.dll found app local at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll', treating application as standalone
[aspnetcorev2.dll] Parsed hostfxr options: dotnet location: '' hostfxr path: 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll' arguments:
[aspnetcorev2.dll] Argument[0] = 'D:\inetpub\wwwroot\apistage.municode.com\site\.\LibraryApi.exe'
[aspnetcorev2.dll] Loading request handler:  'C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App\2.2.0\aspnetcorev2_inprocess.dll'
[aspnetcorev2.dll] Creating handler application
[aspnetcorev2_inprocess.dll] Initializing logs for 'C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App\2.2.0\aspnetcorev2_inprocess.dll'. Process Id: 6900.. File Version: 12.2.18316.0. Description: IIS ASP.NET Core Module V2 Request Handler. Commit: ce8cf65589734f82b0536c543aba5bd60d0a5a98.
[aspnetcorev2_inprocess.dll] Waiting for initialization
[aspnetcorev2_inprocess.dll] Starting in-process worker thread
[aspnetcorev2_inprocess.dll] Resolving hostfxr parameters for application: '.\LibraryApi.exe' arguments: '' path: 'D:\inetpub\wwwroot\apistage.municode.com\site\'
[aspnetcorev2_inprocess.dll] Known dotnet.exe location: ''
[aspnetcorev2_inprocess.dll] Process path '.\LibraryApi.exe' is not dotnet, treating application as standalone or portable with bootstrapper
[aspnetcorev2_inprocess.dll] Checking application.dll at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\LibraryApi.dll'
[aspnetcorev2_inprocess.dll] Checking hostfxr.dll at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll'
[aspnetcorev2_inprocess.dll] hostfxr.dll found app local at 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll', treating application as standalone
[aspnetcorev2_inprocess.dll] Parsed hostfxr options: dotnet location: '' hostfxr path: 'D:\inetpub\wwwroot\apistage.municode.com\site\.\hostfxr.dll' arguments:
[aspnetcorev2_inprocess.dll] Argument[0] = 'D:\inetpub\wwwroot\apistage.municode.com\site\.\LibraryApi.exe'
[aspnetcorev2_inprocess.dll] Failed HRESULT returned: 0x800700b7 at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:415 
[aspnetcorev2_inprocess.dll] Throwing ResultException for HRESULT 0x800700b7 at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:197 
[aspnetcorev2_inprocess.dll] Event Log: 'Application '/LM/W3SVC/3/ROOT' with physical root 'D:\inetpub\wwwroot\apistage.municode.com\site\' failed to load clr and managed application. Unexpected exception: HRESULT 0x800700b7 returned at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:197 ' 
End Event Log Message.
[aspnetcorev2_inprocess.dll] Exception 'HRESULT 0x800700b7 returned at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:197 ' caught at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:302 
[aspnetcorev2_inprocess.dll] Stopping in-process worker thread
[aspnetcorev2_inprocess.dll] Stopping CLR
[aspnetcorev2_inprocess.dll] Event Log: 'Application '/LM/W3SVC/3/ROOT' with physical root 'D:\inetpub\wwwroot\apistage.municode.com\site\' failed to load clr and managed application. CLR worker thread exited prematurely' 
End Event Log Message.
[aspnetcorev2_inprocess.dll] Exception 'InvalidOperationException' caught at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\inprocessapplication.cpp:350 
[aspnetcorev2_inprocess.dll] Failed HRESULT returned: 0x8007023e at c:\b\w\e37dd45d8cd1eaf4\src\iisintegration\src\aspnetcoremodulev2\inprocessrequesthandler\dllmain.cpp:120 
[aspnetcorev2_inprocess.dll] Starting app_offline monitoring in application 'D:\inetpub\wwwroot\apistage.municode.com\site\'
[aspnetcorev2_inprocess.dll] Starting file watcher thread

[guardrex]

HRESULT returned: 0x800700b7

Cannot create a file that already exists?

https://github.com/aspnet/IISIntegration/blob/master/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp#L415

[guardrex]

@pakrym Just want to make sure you see :eye: this.

[pakrym]

@guardrex thank you for pointing me to this.

This is a bug. Related to https://github.com/aspnet/AspNetCore/issues/4566

[guardrex]

Ok

@pholly ... track on the bug issue ... I'm going to close the doc issue.

[muratg]

@pakrym good to close?

[softvisionmarcelorosende]

just go cmd, go to u side folder. run dotnet as u found on the web.config. then u will found what error. for me.. it the damm shit connection string the "", need to put "\"

This actually helped me A LOT

[yncardoso]

just go cmd, go to u side folder. run dotnet as u found on the web.config. then u will found what error. for me.. it the damm shit connection string the "", need to put "\"

Yes, ran my app on the console and could see the problem (Info log level wasn't configured). Thanks for the tip :)

[dewelloper]

it worked when i changed this code
var environment = whb.GetSetting("environment");
to this
var environment = "Development";// whb.GetSetting("environment");
cause it couldn't find the appsettings.json file on the prod environment