AccessViolationException in IIS in-proc request cleanup

[Tratcher]

ASP.NET 5.0 Blazor Server app with ApplicationInsights frequently crashes while accessing request data from HostingApplication.DisposeContext. @DamianEdwards

Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
   at Microsoft.AspNetCore.HttpSys.Internal.NativeRequestContext.CopyOutAddress(IntPtr)
   at Microsoft.AspNetCore.HttpSys.Internal.NativeRequestContext.GetEndPointHelper(Boolean, HTTP_REQUEST*, Byte*)
   at Microsoft.AspNetCore.HttpSys.Internal.NativeRequestContext.GetEndPoint(Boolean)
   at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.InitializeRemoteEndpoint()
   at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.Microsoft.AspNetCore.Http.Features.IHttpConnectionFeature.get_RemoteIpAddress()
   at Microsoft.ApplicationInsights.AspNetCore.TelemetryInitializers.ClientIpHeaderTelemetryInitializer.OnInitializeTelemetry(Microsoft.AspNetCore.Http.HttpContext, Microsoft.ApplicationInsights.DataContracts.RequestTelemetry, Microsoft.ApplicationInsights.Channel.ITelemetry)
   at Microsoft.ApplicationInsights.AspNetCore.TelemetryInitializers.TelemetryInitializerBase.Initialize(Microsoft.ApplicationInsights.Channel.ITelemetry)
   at Microsoft.ApplicationInsights.TelemetryClient.Initialize(Microsoft.ApplicationInsights.Channel.ITelemetry)
   at Microsoft.ApplicationInsights.TelemetryClient.Track(Microsoft.ApplicationInsights.Channel.ITelemetry)
   at Microsoft.ApplicationInsights.TelemetryClient.TrackRequest(Microsoft.ApplicationInsights.DataContracts.RequestTelemetry)
   at Microsoft.ApplicationInsights.AspNetCore.DiagnosticListeners.HostingDiagnosticListener.EndRequest(Microsoft.AspNetCore.Http.HttpContext, Int64)
   at Microsoft.ApplicationInsights.AspNetCore.DiagnosticListeners.HostingDiagnosticListener.OnHttpRequestInStop(Microsoft.AspNetCore.Http.HttpContext)
   at Microsoft.ApplicationInsights.AspNetCore.DiagnosticListeners.HostingDiagnosticListener.OnNext(System.Collections.Generic.KeyValuePair`2<System.String,System.Object>)
   at System.Diagnostics.DiagnosticListener.Write(System.String, System.Object)
   at Microsoft.AspNetCore.Hosting.HostingApplicationDiagnostics.StopActivity(System.Diagnostics.Activity, Microsoft.AspNetCore.Http.HttpContext)
   at Microsoft.AspNetCore.Hosting.HostingApplicationDiagnostics.StopActivity(Microsoft.AspNetCore.Http.HttpContext, System.Diagnostics.Activity, Boolean)
   at Microsoft.AspNetCore.Hosting.HostingApplication.DisposeContext(Context, System.Exception)
   at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].ExecutionContextCallback(System.Object)
   at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].MoveNext(System.Threading.Thread)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT`1+<ProcessRequestAsync>d__2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].MoveNext()
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox, Boolean)
   at System.Threading.Tasks.Task.RunContinuations(System.Object)
   at System.Threading.Tasks.Task.FinishContinuations()
   at System.Threading.Tasks.Task`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].TrySetResult(System.Threading.Tasks.VoidTaskResult)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetResult()
   at Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<WriteBody>d__338.MoveNext()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<WriteBody>d__338, Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].ExecutionContextCallback(System.Object)
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<WriteBody>d__338, Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].MoveNext(System.Threading.Thread)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext+<WriteBody>d__338, Microsoft.AspNetCore.Server.IIS, Version=5.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]].ExecuteFromThreadPool(System.Threading.Thread)
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

The IIS call is here:

aspnetcore/src/Servers/IIS/IIS/src/Core/IISHttpContextOfT.cs

Lines 100 to 109 in b463e04

	PostCompletion(ConvertRequestCompletionResults(success));
	if (_onCompleted != null)
	{
	await FireOnCompleted();
	}
	try
	{
	_application.DisposeContext(context, _applicationException);

It looks like it needs to re-order PostCompletion and DisposeContext.

Also it looks like this was a 5.0 regression in https://github.com/dotnet/aspnetcore/pull/17756/files. Fixing it is going to re-introduce the latency issue we were trying to fix.

We don't think HttpSys is affected despite some shared code, it doesn’t clean up the buffer until after DisposeContext:

aspnetcore/src/Servers/HttpSys/src/MessagePump.cs

Lines 222 to 223 in 8109690

	_application.DisposeContext(context, null);
	requestContext.Dispose();

[analogrelay]

Triage: We think that accessing the request in DisposeContext is invalid behavior here, we should review where we are signalling the EndRequest Diagnostic Source event and consider firing it before the context is disposed. We'll look at doing some hardening to prevent an AV, but may still throw an exception.

[analogrelay]

@Tratcher given the timeline it's probably going to be best if you take this on. You've got familiarity with the code.