dotnet / aspnetcore

ASP.NET Core is a cross-platform .NET framework for building modern cloud-based web applications on Windows, Mac, or Linux.
https://asp.net
MIT License
35.4k stars 10k forks source link

HttpConnectionContext Disposes WindowsIdentity objects it does not own #37521

Closed Applesauce314 closed 3 years ago

Applesauce314 commented 3 years ago

Describe the bug

The changes introduced to fix issue #2985 (with issues corrected by #11051) update Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.EnsureConnectionStateAsync to Clone WindowsIdentity objects when long polling instead of assigning the User Property from the HttpContext.

HttpConnectionDispatcher https://github.com/dotnet/aspnetcore/blob/c83777e4e6ec8ded364cf45d398910e3575d5367/src/SignalR/common/Http.Connections/src/Internal/HttpConnectionDispatcher.cs#L538-L572

It also added disposal of these cloned objects to Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync . However it disposes any WindowsIdentity objects in HttpConnectionContext.User.Identities even if the User property was assigned from HttpContext.User.

HttpConnectionContext https://github.com/dotnet/aspnetcore/blob/c83777e4e6ec8ded364cf45d398910e3575d5367/src/SignalR/common/Http.Connections/src/Internal/HttpConnectionContext.cs#L258-L264

In some circumstances the HttpContext outlives the HttpConnectionContext and an ObjectDisposedException will be thrown if certain properties of the identity is accessed via HttpContext.User.Identities or HttpContext.User.Identity. My code is triggering this issue in logging code when logging where a Serilog Enricher is providing username using using an injected HttpContextAccessor. But I expect this could be triggered numerous ways.

EndpointMiddleware https://github.com/dotnet/aspnetcore/blob/c83777e4e6ec8ded364cf45d398910e3575d5367/src/Http/Routing/src/EndpointMiddleware.cs#L83
Code ``` private readonly IHttpContextAccessor _contextAccessor; public UserEnricher() : this(new HttpContextAccessor()) { } internal UserEnricher(IHttpContextAccessor contextAccessor) { _contextAccessor = contextAccessor; } public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { string? username; username = _contextAccessor.HttpContext?.User?.Identity)?.Name; var userProperty = new LogEventProperty(UserPropertyName, new ScalarValue(username)); logEvent.AddPropertyIfAbsent(userProperty); } } } ```

To Reproduce

more detailed steps can be provided, but the extra disposals are pretty apparent from the linked code.

Exceptions (if any)

ObjectDisposedException {"Safe handle has been closed. Object name: 'SafeHandle'."}

Proposed Solution

I think this would be solved one of two ways

  1. HttpConnectionContext should keep track of WindowsIdentity objects it is reponsible for and dispose only those.
  2. HttpConnectionContext should always create a new WindowPrincipal and Clone the Identities

Further technical details

dotnet --info Output ``` .NET SDK (reflecting any global.json): Version: 5.0.303 Commit: 6409b42649 Runtime Environment: OS Name: Windows OS Version: 10.0.16299 OS Platform: Windows RID: win10-x64 Base Path: C:\Program Files\dotnet\sdk\5.0.303\ Host (useful for support): Version: 5.0.10 Commit: e1825b4928 .NET SDKs installed: 3.1.118 [C:\Program Files\dotnet\sdk] 5.0.301 [C:\Program Files\dotnet\sdk] 5.0.302 [C:\Program Files\dotnet\sdk] 5.0.303 [C:\Program Files\dotnet\sdk] .NET runtimes installed: Microsoft.AspNetCore.All 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All] Microsoft.AspNetCore.All 2.1.30 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All] Microsoft.AspNetCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 2.1.30 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 3.1.18 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 5.0.9 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.AspNetCore.App 5.0.10 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App] Microsoft.NETCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 2.1.30 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 3.1.18 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.9 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.NETCore.App 5.0.10 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App] Microsoft.WindowsDesktop.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 3.1.18 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.9 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] Microsoft.WindowsDesktop.App 5.0.10 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App] To install additional .NET runtimes or SDKs: https://aka.ms/dotnet-download ```

Edited to include all the relevant lines from HttpConnectionDispatcher

Applesauce314 commented 3 years ago

I have a proposed fix in https://github.com/Applesauce314/aspnetcore/tree/Applesauce314-patch-1 but have not made a PR yet as I do not currently have a setup capable of building and running tests. It is a modified version of Proposed Solution 2. Except that it does not create a new WindowsPrincipal, and clones any members of User.Identites that are type WindowsIndentity . This Clone should increment the reference count of the underlying SafeHandle of the WindowsIndentity and allow both the HttpContext and the HttpConnectionContext to be disposed in either order. It removes a bunch of code from HttpConnectionDispatcher that was doing half the work of Cloning sometimes as the implentation makes HttpConnectionContext fully responsible.

shirhatti commented 3 years ago

@Applesauce314 Can you provide a stack trace for the ObjectDisposedException that you're seeing?

shirhatti commented 3 years ago

Triage: LongPolling was a red-herring. In the websocket (and SSE) case, we shouldn't disposing the WindowsIdentity

https://github.com/dotnet/aspnetcore/blob/c83777e4e6ec8ded364cf45d398910e3575d5367/src/SignalR/common/Http.Connections/src/Internal/HttpConnectionContext.cs#L258-L264

Applesauce314 commented 3 years ago
Call Stack at point ObjectDisposedException is thrown (company and usernames anonymized) ``` Contoso.Web.dll!Contoso.Common.Logging.UserEnricher.Enrich(Serilog.Events.LogEvent logEvent = {Serilog.Events.LogEvent}, Serilog.Core.ILogEventPropertyFactory propertyFactory = {Serilog.Capturing.MessageTemplateProcessor}) Line 44 Serilog.dll!Serilog.Core.Enrichers.SafeAggregateEnricher.Enrich(Serilog.Events.LogEvent logEvent = {Serilog.Events.LogEvent}, Serilog.Core.ILogEventPropertyFactory propertyFactory = {Serilog.Capturing.MessageTemplateProcessor}) Line 40 Serilog.dll!Serilog.Core.Logger.Dispatch(Serilog.Events.LogEvent logEvent = {Serilog.Events.LogEvent}) Line 403 Serilog.Extensions.Logging.dll!Serilog.Extensions.Logging.SerilogLogger.Log>(Microsoft.Extensions.Logging.LogLevel logLevel, Microsoft.Extensions.Logging.EventId eventId, Microsoft.Extensions.Logging.LoggerMessage.LogValues state, System.Exception exception, System.Func, System.Exception, string> formatter) Microsoft.Extensions.Logging.Abstractions.dll!Microsoft.Extensions.Logging.LoggerMessage.Define.__Log|0(Microsoft.Extensions.Logging.ILogger logger, string arg1, System.Exception exception) Line 158 Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.Log.FailedDispose(Microsoft.Extensions.Logging.ILogger logger, string connectionId, System.Exception exception) Line 54 Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.DisposeAndRemoveAsync(Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext connection = {Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext}, bool closeGracefully = true) Line 212 [Resuming Async Method] System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__16>.ExecutionContextCallback(object s = Id = 1280, Status = WaitingForActivation, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__16>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__16>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1278, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception, ref System.Threading.Tasks.Task taskField) Line 465 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception) Line 120 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync(bool closeGracefully = true) Line 264 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__111>.ExecutionContextCallback(object s = Id = 1278, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__111>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__111>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1267, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception, ref System.Threading.Tasks.Task taskField) Line 465 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception) Line 120 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.WaitOnTasks(System.Threading.Tasks.Task applicationTask = Id = 1155, Status = Faulted, Method = "{null}", Result = "{Not yet computed}", System.Threading.Tasks.Task transportTask = Id = 1169, Status = RanToCompletion, Method = "{null}", Result = "System.Threading.Tasks.VoidTaskResult", bool closeGracefully = true) Line 374 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__112>.ExecutionContextCallback(object s = Id = 1267, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__112>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__112>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1155, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3331 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception, ref System.Threading.Tasks.Task taskField) Line 465 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception) Line 120 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.ExecuteApplication(Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate = {Method = {System.Reflection.RuntimeMethodInfo}}) Line 555 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__118>.ExecutionContextCallback(object s = Id = 1155, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__118>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__118>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1158, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception, ref System.Threading.Tasks.Task taskField) Line 465 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception) Line 120 [Completed] Microsoft.AspNetCore.SignalR.Core.dll!Microsoft.AspNetCore.SignalR.HubConnectionHandler.OnConnectedAsync(Microsoft.AspNetCore.Connections.ConnectionContext connection = {Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext}) Line 148 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBox.d__16>.ExecutionContextCallback(object s = Id = 1158, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBox.d__16>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBox.d__16>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1275, Status = Faulted, Method = "{null}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Threading.Tasks.Task.WhenAllPromise.Invoke(System.Threading.Tasks.Task completedTask) Line 5667 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunOrQueueCompletionAction(System.Threading.Tasks.ITaskCompletionAction completionAction, bool allowInlining) Line 3358 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3241 System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2008 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetException(object exceptionObject) Line 3133 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception, ref System.Threading.Tasks.Task taskField) Line 465 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetException(System.Exception exception) Line 120 [Completed] Microsoft.AspNetCore.SignalR.StackExchangeRedis.dll!Microsoft.AspNetCore.SignalR.StackExchangeRedis.Internal.RedisSubscriptionManager.RemoveSubscriptionAsync(string id = "Contoso.MST.RedTag.RedTagHub:user:MYDomain\\alice", Microsoft.AspNetCore.SignalR.HubConnectionContext connection = {Microsoft.AspNetCore.SignalR.HubConnectionContext}, System.Func unsubscribeMethod = {Method = {System.Reflection.RuntimeMethodInfo}}) Line 59 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__3>.ExecutionContextCallback(object s = Id = 1273, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__3>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__3>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1274, Status = Faulted, Method = "{null}", Result = "{Not yet computed}") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.System.Threading.IThreadPoolWorkItem.Execute() Line 647 System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch() Line 655 [Async Call Stack] [Async] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.DoPersistentConnection(Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate, Microsoft.AspNetCore.Http.Connections.Internal.Transports.IHttpTransport transport, Microsoft.AspNetCore.Http.HttpContext context, Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext connection) Line 277 [Async] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.ExecuteAsync(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}, Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate = {Method = {System.Reflection.RuntimeMethodInfo}}, Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions options = {Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions}, Microsoft.AspNetCore.Http.Connections.Internal.ConnectionLogScope logScope = {Microsoft.AspNetCore.Http.Connections.Internal.ConnectionLogScope}) Line 176 [Async] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.ExecuteAsync(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}, Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions options = {Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions}, Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate = {Method = {System.Reflection.RuntimeMethodInfo}}) Line 86 [Async] Microsoft.AspNetCore.Routing.dll!Microsoft.AspNetCore.Routing.EndpointMiddleware.Invoke.__AwaitRequestTask|6_0(Microsoft.AspNetCore.Http.Endpoint endpoint = {Microsoft.AspNetCore.Routing.RouteEndpoint}, System.Threading.Tasks.Task requestTask = Id = 1175, Status = WaitingForActivation, Method = "{null}", Result = "{Not yet computed}", Microsoft.Extensions.Logging.ILogger logger = {Microsoft.Extensions.Logging.Logger}) Line 80 [Async] Microsoft.AspNetCore.Authorization.Policy.dll!Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context) Line 64 [Async] Microsoft.AspNetCore.Authentication.dll!Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context) Line 77 [Async] Microsoft.VisualStudio.Web.BrowserLink.dll!Microsoft.VisualStudio.Web.BrowserLink.BrowserLinkMiddleware.ExecuteWithFilter(Microsoft.VisualStudio.Web.BrowserLink.IHttpSocketAdapter injectScriptSocket, string requestId, Microsoft.AspNetCore.Http.HttpContext httpContext) Line 119 [Async] Microsoft.AspNetCore.Diagnostics.dll!Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context) Line 95 [Async] Microsoft.AspNetCore.Server.IIS.dll!Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT.ProcessRequestAsync() Line 39 [Async] Microsoft.AspNetCore.Server.IIS.dll!Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.HandleRequest() Line 674 ```

Contoso.Common.Logging.UserEnricher uses an Injected HttpContextAccessor to access the HttpContext the same way as some built in Serilog providers. Link

I verified that dispose on the HttpContext has not yet been called. I put a breakpoint in WindowsIdentity.Dispose and found the point at which the object in question was being disposed. The call stack is below.

Call Stack for point of disposal of WindowsIdentity that causes ObjectDisposedException ``` System.Security.Principal.Windows.dll!System.Security.Principal.WindowsIdentity.Dispose(bool disposing = true) Line 720 System.Security.Principal.Windows.dll!System.Security.Principal.WindowsIdentity.Dispose() Line 733 Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext.DisposeAsync(bool closeGracefully = true) Line 255 Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager.DisposeAndRemoveAsync(Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext connection = {Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext}, bool closeGracefully = true) Line 200 Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.DoPersistentConnection(Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate, Microsoft.AspNetCore.Http.Connections.Internal.Transports.IHttpTransport transport, Microsoft.AspNetCore.Http.HttpContext context, Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionContext connection) Line 275 [Resuming Async Method] System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__11>.ExecutionContextCallback(object s = Id = 1171, Status = WaitingForActivation, Method = "{null}", Result = "{Not yet computed}") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__11>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__11>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1170, Status = RanToCompletion, Method = "{null}", Result = "System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[System.Threading.Tasks.VoidTaskResult,Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsServerTransport+d__6]") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetResult(System.__Canon result) Line 398 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TwoTaskWhenAnyPromise.Invoke(System.Threading.Tasks.Task completingTask) Line 6060 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunOrQueueCompletionAction(System.Threading.Tasks.ITaskCompletionAction completionAction, bool allowInlining) Line 3358 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3241 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetResult(System.Threading.Tasks.VoidTaskResult result) Line 398 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetExistingTaskResult(System.Threading.Tasks.Task task, System.Threading.Tasks.VoidTaskResult result) Line 436 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetResult() Line 109 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsServerTransport.ProcessRequestAsync(Microsoft.AspNetCore.Http.HttpContext context, System.Threading.CancellationToken token) Line 67 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__6>.ExecutionContextCallback(object s = Id = 1169, Status = RanToCompletion, Method = "{null}", Result = "System.Threading.Tasks.VoidTaskResult") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__6>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__6>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1168, Status = RanToCompletion, Method = "{null}", Result = "System.Threading.Tasks.VoidTaskResult") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetResult(System.Threading.Tasks.VoidTaskResult result) Line 398 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetExistingTaskResult(System.Threading.Tasks.Task task, System.Threading.Tasks.VoidTaskResult result) Line 436 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetResult() Line 109 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsServerTransport.ProcessSocketAsync(System.Net.WebSockets.WebSocket socket) Line 137 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__7>.ExecutionContextCallback(object s = Id = 1168, Status = RanToCompletion, Method = "{null}", Result = "System.Threading.Tasks.VoidTaskResult") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 186 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__7>.MoveNext(System.Threading.Thread threadPoolThread = null) Line 327 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__7>.MoveNext() Line 305 System.Private.CoreLib.dll!System.Runtime.CompilerServices.TaskAwaiter.OutputWaitEtwEvents.AnonymousMethod__12_0(System.Action innerContinuation, System.Threading.Tasks.Task innerTask = Id = 1266, Status = RanToCompletion, Method = "{null}", Result = "System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[System.Threading.Tasks.VoidTaskResult,Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsServerTransport+d__9]") Line 302 System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Action action, bool allowInlining) Line 743 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3229 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetResult(System.__Canon result) Line 398 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TwoTaskWhenAnyPromise.Invoke(System.Threading.Tasks.Task completingTask) Line 6060 System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3340 System.Private.CoreLib.dll!System.Threading.Tasks.Task.TrySetResult(System.Threading.Tasks.VoidTaskResult result) Line 398 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetExistingTaskResult(System.Threading.Tasks.Task task, System.Threading.Tasks.VoidTaskResult result) Line 436 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.SetResult() Line 109 [Completed] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsServerTransport.StartSending(System.Net.WebSockets.WebSocket socket) Line 286 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__9>.ExecutionContextCallback(object s = Id = 1166, Status = RanToCompletion, Method = "{null}", Result = "System.Threading.Tasks.VoidTaskResult") Line 290 System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread threadPoolThread = {System.Threading.Thread}, System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 274 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__9>.MoveNext(System.Threading.Thread threadPoolThread = {System.Threading.Thread}) Line 335 System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder.AsyncStateMachineBoxd__9>.ExecuteFromThreadPool(System.Threading.Thread threadPoolThread = {System.Threading.Thread}) Line 302 System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch() Line 641 [Async Call Stack] [Async] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.ExecuteAsync(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}, Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate = {Method = {System.Reflection.RuntimeMethodInfo}}, Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions options = {Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions}, Microsoft.AspNetCore.Http.Connections.Internal.ConnectionLogScope logScope = {Microsoft.AspNetCore.Http.Connections.Internal.ConnectionLogScope}) Line 176 [Async] Microsoft.AspNetCore.Http.Connections.dll!Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher.ExecuteAsync(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}, Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions options = {Microsoft.AspNetCore.Http.Connections.HttpConnectionDispatcherOptions}, Microsoft.AspNetCore.Connections.ConnectionDelegate connectionDelegate = {Method = {System.Reflection.RuntimeMethodInfo}}) Line 86 [Async] Microsoft.AspNetCore.Routing.dll!Microsoft.AspNetCore.Routing.EndpointMiddleware.Invoke.__AwaitRequestTask|6_0(Microsoft.AspNetCore.Http.Endpoint endpoint = {Microsoft.AspNetCore.Routing.RouteEndpoint}, System.Threading.Tasks.Task requestTask = Id = 1175, Status = WaitingForActivation, Method = "{null}", Result = "{Not yet computed}", Microsoft.Extensions.Logging.ILogger logger = {Microsoft.Extensions.Logging.Logger}) Line 80 [Async] Microsoft.AspNetCore.Authorization.Policy.dll!Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}) Line 64 [Async] Microsoft.AspNetCore.Authentication.dll!Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}) Line 77 [Async] Microsoft.VisualStudio.Web.BrowserLink.dll!Microsoft.VisualStudio.Web.BrowserLink.BrowserLinkMiddleware.ExecuteWithFilter(Microsoft.VisualStudio.Web.BrowserLink.IHttpSocketAdapter injectScriptSocket = {Microsoft.VisualStudio.Web.BrowserLink.DelayConnectingHttpSocketAdapter}, string requestId = "21499105721b4295b915199c43b1345d", Microsoft.AspNetCore.Http.HttpContext httpContext = {Microsoft.AspNetCore.Http.DefaultHttpContext}) Line 119 [Async] Microsoft.AspNetCore.Diagnostics.dll!Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(Microsoft.AspNetCore.Http.HttpContext context = {Microsoft.AspNetCore.Http.DefaultHttpContext}) Line 95 [Async] Microsoft.AspNetCore.Server.IIS.dll!Microsoft.AspNetCore.Server.IIS.Core.IISHttpContextOfT.ProcessRequestAsync() Line 39 [Async] Microsoft.AspNetCore.Server.IIS.dll!Microsoft.AspNetCore.Server.IIS.Core.IISHttpContext.HandleRequest() Line 674 ```

I then followed the path by which `HTTPConnectionContext.User is assigned, and that brought me to HttpConnectionDispatcher.

HttpConnectionDispatcher https://github.com/dotnet/aspnetcore/blob/c83777e4e6ec8ded364cf45d398910e3575d5367/src/SignalR/common/Http.Connections/src/Internal/HttpConnectionDispatcher.cs#L572

From this we see in our case (websockets) Clone is not being called on the WindowsIdentity objects, but Dispose is. I then followed the source of the code that perform the dispose Blame HttpConnectionContext L257-264 and see that this was added to support LongPolling by https://github.com/dotnet/aspnetcore/commit/f0a34a4ca46129b8434020dedb8c360e751e2963 with bug fixes in https://github.com/dotnet/aspnetcore/pull/11051 . Prior to these 2 changes, HttpConnectionContext never disposed the WindowsIdentity objects, and always assigned the HttpContext.User without cloning, but after the changes it always disposes the WindowsIdentity objects, but only sometimes clones the objects.

Applesauce314 commented 3 years ago

bug repo project created at https://github.com/Applesauce314/HttpConnectionDisposalIssue

BrennanConroy commented 3 years ago

From this we see in our case (websockets) Clone is not being called on the WindowsIdentity objects, but Dispose is.

Right, the bug here is that we are disposing the user on non-longpolling transports https://github.com/dotnet/aspnetcore/issues/37521#issuecomment-944654017

Should be a simple fix of checking the transport type in the dispose logic.