Warning causing OPTIONS request to return as 502

[severisv]

After upgrading from RC1 to RC2 our OPTIONS-requests (used for CORS) return 502 instead of 204, causing them not to work.

As it turns out, this is caused by a NullReferenceException at AspNetCore.Hosting.Internal.HostingApplication.DisposeContext().

The warning occours at every request, but requests returned by the MVC-pipeline return with the correct status code, while the requests that do not hit any route in the MVC-pipeline or are returned by the CORS-middleware return as 502. The IIS-logs tell us it is a 502.3 occuring in the AspNetCore-module.

Adding app.UseDatabaseErrorPage() causes the warning to disappear and everything to work correctly, but this is obvously not a viable solution for a production environment.

Here is a gist of our project.json

stdout log:

WARN   2210ms [12               ] Token=adb9793829ddae60 Log                - Connection processing ended abnormally Message: Object reference not set to an instance of an object.
System.NullReferenceException: Object reference not set to an instance of an object.
   at Microsoft.AspNetCore.Hosting.Internal.HostingApplication.DisposeContext(Context context, Exception exception)
   at Microsoft.AspNetCore.Server.Kestrel.Http.Frame`1.<RequestProcessingAsync>d__2.MoveNext()

IIS-trace: https://drive.google.com/folderview?id=0B7YqWm3lf4vZMmNvdFpKZ2lxNGc&usp=sharing

[Tratcher]

I've asked @CesarBS to investigate.

[cesarblum]

@severisv Could you share more information on what else is in your request path? I've tried reproing with the template MVC app and an empty app with no success. I'm always getting a 204 response.

[severisv]

I have stripped our project down to a minimal setup that reproduces the issue and pushed it here: https://github.com/severisv/aspnetcore-rc2-cors-issue.

Note that the requests to non-existing endpoints also return 502.3 rather than 404.

[muratg]

@CesarBS Did you get a chance to look into this?

[cesarblum]

@severisv The problem is here:

https://github.com/severisv/aspnetcore-rc2-cors-issue/blob/master/src/SB.API/Configuration/Log4Net/Log4NetAdapter.cs#L94

This causes HostingApplication.DisposeContext to throw at:

Hosting/src/Microsoft.AspNetCore.Hosting/Internal/HostingApplication.cs

Line 83 in e62ceb8

context.Scope.Dispose();

To mitigate this you should do what we do in loggers that don't support scopes e.g.:

https://github.com/aspnet/Logging/blob/8387adbee91e86e35b6a3d2d0e75e5d59127879a/src/Microsoft.Extensions.Logging.Debug/DebugLogger.cs#L41

@Tratcher I think this warrants a defensive fix in HostingApplication i.e. only attempt to dispose Context.Scope is it's not null.

[Tratcher]

context.Scope?.Dispose(); would suffice.

[cesarblum]

I've pointed out a solution to @severisv and also changed HostingApplication so this doesn't happen again in the future. Closing.

@muratg @Eilon I've added appropriate tags and milestone.