System.ObjectDisposedException: IFeatureCollection has been disposed.

[viktors-telle]

Describe the bug

A few .NET Core applications running in the Azure Service Fabric cluster are crashing several times per day with the exception: System.ObjectDisposedException: IFeatureCollection has been disposed.

To Reproduce

Unfortunately, I was not able to reproduce the issue on my machine. I suspect that might be caused by IHttpContextAccessor use in a singleton class. I am not capturing the HttpContext in a private field, nor using async void anywhere. I have ruled out all the bad practices mentioned in the guide by @davidfowl:

https://github.com/davidfowl/AspNetCoreDiagnosticScenarios/blob/master/AspNetCoreGuidance.md#do-not-store-ihttpcontextaccessorhttpcontext-in-a-field

Exceptions (if any)

Application: service.exe
CoreCLR Version: 4.700.20.41105
.NET Core Version: 3.1.8
Description: The process was terminated due to an unhandled exception.
Exception Info: System.ObjectDisposedException: IFeatureCollection has been disposed.
Object name: 'Collection'.
   at Microsoft.AspNetCore.Http.Features.FeatureReferences`1.ThrowContextDisposed()
   at Microsoft.AspNetCore.Http.DefaultHttpRequest.get_Scheme()
   at Microsoft.AspNetCore.Http.Extensions.UriHelper.GetDisplayUrl(HttpRequest request)
   at IFBaltics.Hosting.WebHostRequestFiller.Fill(LogEventInfo logEventInfo)
   at Sysmsg.SysmsgLogCommand.Write()
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, String message, Object[] args)
   at Microsoft.AspNetCore.Server.HttpSys.DisconnectListener.<>c__DisplayClass7_0.<CreateDisconnectToken>b__0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* overlappedPtr)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
   at System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* pNativeOverlapped)

Further technical details

• ASP.NET Core version 3.1.8

• It was not possible to find any installed .NET Core SDKs
  Did you mean to run .NET Core SDK commands? Install a .NET Core SDK from:
  https://aka.ms/dotnet-download

  Host (useful for support):
  Version: 3.1.8
  Commit: 9c1330dedd

  .NET Core SDKs installed:
  No SDKs were found.

  .NET Core runtimes installed:
  Microsoft.AspNetCore.All 2.1.21 [c:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.21 [c:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.8 [c:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.21 [c:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.8 [c:\Program Files\dotnet\shared\Microsoft.NETCore.App]

  To install additional .NET Core runtimes or SDKs:
  https://aka.ms/dotnet-download

• Not dependant on the IDE.

[jkotalik]

To me, this looks like a bug in our HttpSys Server. Do you have the ability to host with Kestrel and see if it does or does not reproduce there?

[davidfowl]

It's a combination of things:

• I'm assuming you have a custom logger that is adding properties from the request to log entries
• We're creating a cancellation token which ends up capturing the execution context (including the HttpContextAccessor) and logging after the request is over.
• The custom logger tries to access the HttpContext fields and throws as a result.

We need to avoid capturing the ExecutionContext here

aspnetcore/src/Servers/HttpSys/src/NativeInterop/DisconnectListener.cs

Line 70 in d8caeb2

nativeOverlapped = new SafeNativeOverlapped(boundHandle, boundHandle.AllocateNativeOverlapped(

[viktors-telle]

@davidfowl Exactly, we have a custom logger that adds data to the log entry from the request object.
Do you have any ideas on why this exception is thrown only from time to time?

[davidfowl]

Do you have any ideas on why this exception is thrown only from time to time?

It would only happen if the client disconnects after the request is complete/disposed.

Thanks for contacting us.
We're moving this issue to the Next sprint planning milestone for future evaluation / consideration. We will evaluate the request when we are planning the work for the next milestone. To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.

[davidfowl]

This should be backported to 3.1 as well.

[dragoilic]

I had this issues when update record of table.
if (await TryUpdateModelAsync(editProfile, "",
d => d.Title, d => d.FirstName, d => d.MiddleName, d => d.SurName, d => d.Gender, d => d.Email, d => d.CountryCode, d => d.PhoneNumber, d => d.ClinicName, d => d.Profession, d => d.ProviderNumber))

[davidfowl]

Are you using httpsys server? That's what this specific issues was about.