Fix graceful close on HTTP/2 connection

[JamesNK]

Failing Test(s)

• Http2RequestTests.GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes

Error Message

System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host.

Logs

[0.001s] [TestLifetime] [Information] Starting test GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes-False at 2022-04-06T01:12:55
[0.006s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting starting
[0.006s] [Microsoft.Hosting.Lifetime] [Information] Now listening on: http://127.0.0.1:55248
[0.006s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Debug] Loaded hosting startup assembly Interop.FunctionalTests
[0.007s] [Microsoft.Hosting.Lifetime] [Information] Application started. Press Ctrl+C to shut down.
[0.007s] [Microsoft.Hosting.Lifetime] [Information] Hosting environment: Production
[0.007s] [Microsoft.Hosting.Lifetime] [Information] Content root path: C:\h\w\A0B908F0\w\C31709CB\e\
[0.007s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting started
[0.007s] [Test] [Information] Waiting for request on server
[0.564s] [Microsoft.AspNetCore.Server.Kestrel.Connections] [Debug] Connection id "0HMGNDA9QFTM1" accepted.
[0.564s] [Microsoft.AspNetCore.Server.Kestrel.Connections] [Debug] Connection id "0HMGNDA9QFTM1" started.
[0.567s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending SETTINGS frame for stream ID 0 with length 18 and flags NONE.
[0.567s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.568s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received SETTINGS frame for stream ID 0 with length 12 and flags NONE.
[0.568s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.568s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
[0.568s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received HEADERS frame for stream ID 1 with length 20 and flags END_STREAM, END_HEADERS.
[0.568s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Information] Request starting HTTP/2 GET http://127.0.0.1:55248/ - -
[0.569s] [Test] [Information] Stopping server
[0.569s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting stopping
[0.569s] [Microsoft.Hosting.Lifetime] [Information] Application is shutting down...
[0.569s] [Test] [Information] Server writing 500000 bytes response
[0.570s] [Test] [Information] Server advancing 500000 bytes response
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending HEADERS frame for stream ID 1 with length 41 and flags END_HEADERS.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Debug] Connection id "0HMGNDA9QFTM1" is closing.
[0.570s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0.
[0.571s] [Test] [Information] Received 49152 bytes. Total 49152 bytes.
[0.571s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received SETTINGS frame for stream ID 0 with length 0 and flags ACK.
[0.572s] [Test] [Information] Received 16383 bytes. Total 65535 bytes.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received PING frame for stream ID 0 with length 8 and flags NONE.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending PING frame for stream ID 0 with length 8 and flags ACK.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.572s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.573s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.573s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
[0.593s] [Test] [Information] Received 49152 bytes. Total 114687 bytes.
[0.640s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
[0.640s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
[0.642s] [Test] [Information] Received 65535 bytes. Total 180222 bytes.
[0.642s] [Test] [Information] Received 16383 bytes. Total 196605 bytes.
[0.642s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
[0.642s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16382 and flags NONE.
[0.643s] [Test] [Information] Received 49152 bytes. Total 245757 bytes.
[0.643s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
[0.644s] [Test] [Information] Received 65536 bytes. Total 311293 bytes.
[0.644s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.644s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.644s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.644s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
[0.645s] [Test] [Information] Received 65534 bytes. Total 376827 bytes.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending DATA frame for stream ID 1 with length 8486 and flags END_STREAM.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Debug] Connection id "0HMGNDA9QFTM1" is closed. The last processed stream ID was 1.
[0.645s] [Microsoft.AspNetCore.Server.Kestrel.Http2] [Verbose] Connection id "0HMGNDA9QFTM1" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0.
[0.648s] [Test] [Information] Received 49152 bytes. Total 425979 bytes.
[0.648s] [Microsoft.AspNetCore.Hosting.Diagnostics] [Information] Request finished HTTP/2 GET http://127.0.0.1:55248/ - - - 200 - - 79.4842ms
[0.648s] [Microsoft.AspNetCore.Server.Kestrel.Connections] [Debug] Connection id "0HMGNDA9QFTM1" stopped.
[0.648s] [Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets] [Debug] Connection id "0HMGNDA9QFTM1" sending FIN because: "The Socket transport's send loop completed gracefully."
[1.558s] [Microsoft.Extensions.Hosting.Internal.Host] [Debug] Hosting stopped
[1.576s] [Interop.FunctionalTests.Http2.Http2RequestTests] [Error] Test threw an exception.
System.IO.IOException: The request was aborted.
 ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
 ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
   at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
   at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
   at System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(IAsyncStateMachineBox box, Boolean allowInlining)
   at System.Threading.Tasks.Task.RunContinuations(Object continuationObject)
   at System.Net.Http.Http2Connection.ReadFrameAsync(Boolean initialFrame)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
   at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
   at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
--- End of stack trace from previous location ---

   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
   --- End of inner exception stack trace ---
   at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
   at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
   at System.Net.Http.Http2Connection.Http2Stream.TryReadFromBuffer(Span`1 buffer, Boolean partOfSyncRead)
   at System.Net.Http.Http2Connection.Http2Stream.ReadDataAsync(Memory`1 buffer, HttpResponseMessage responseMessage, CancellationToken cancellationToken)
   at Interop.FunctionalTests.Http2.Http2RequestTests.StartLongRunningRequestAsync(ILogger logger, IHost host, HttpMessageInvoker client) in /_/src/Servers/Kestrel/test/Interop.FunctionalTests/Http2/Http2RequestTests.cs:line 123
   at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) in /_/src/Shared/TaskExtensions.cs:line 88
   at Interop.FunctionalTests.Http2.Http2RequestTests.GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes(Boolean hasTrailers) in /_/src/Servers/Kestrel/test/Interop.FunctionalTests/Http2/Http2RequestTests.cs:line 98
   at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_1.<<InvokeTestMethodAsync>b__1>d.MoveNext() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestInvoker.cs:line 264
--- End of stack trace from previous location ---
   at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\ExecutionTimer.cs:line 48
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 90
[1.607s] [TestLifetime] [Information] Finished test GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes-False in 1.6057321s

Build

https://dev.azure.com/dnceng/public/_build/results?buildId=1701748&view=results

[JamesNK]

It's quite possible this is an issue in SocketsHttpHandler. I've updated the test to capture client logging. Should pass those logs onto the networking team when available.

[JamesNK]

Failure logs with client logging enabled:

 Interop.FunctionalTests.Http2.Http2RequestTests.GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes(hasTrailers: False)
   Source: Http2RequestTests.cs line 49
   Duration: 39 ms

  Message: 
System.IO.IOException : The request was aborted.
---- System.IO.IOException : Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
-------- System.Net.Sockets.SocketException : An existing connection was forcibly closed by the remote host.

  Stack Trace: 
Http2Connection.ThrowRequestAborted(Exception innerException)
Http2Stream.CheckResponseBodyState()
Http2Stream.TryReadFromBuffer(Span`1 buffer, Boolean partOfSyncRead)
Http2Stream.ReadDataAsync(Memory`1 buffer, HttpResponseMessage responseMessage, CancellationToken cancellationToken)
Http2RequestTests.StartLongRunningRequestAsync(ILogger logger, IHost host, HttpMessageInvoker client) line 132
TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) line 88
Http2RequestTests.GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes(Boolean hasTrailers) line 103
--- End of stack trace from previous location ---
----- Inner Stack Trace -----
Http2Connection.ProcessIncomingFramesAsync()
----- Inner Stack Trace -----
AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
Socket.ReceiveAsync(Memory`1 buffer, SocketFlags socketFlags, Boolean fromNetworkStream, CancellationToken cancellationToken)
NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
Http2Connection.ProcessIncomingFramesAsync()
AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
AsyncStateMachineBox`1.MoveNext()
AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
Callback.Invoke(Event e)
IThreadPoolWorkItem.Execute()
ThreadPoolWorkQueue.Dispatch()
WorkerThread.WorkerThreadStart()
--- End of stack trace from previous location ---

  Standard Output: 
| [0.002s] TestLifetime Information: Starting test GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes-False at 2022-04-07T00:51:20
| [0.002s] HttpEventSourceListener Debug: Starting HttpEventSourceListener.
| [0.007s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : SocketsHttpHandler#48165764,.ctor, ->
| [0.007s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpMessageInvoker#32904028,.ctor,HttpMessageInvoker#32904028,SocketsHttpHandler#48165764 ->
| [0.007s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting starting
| [0.009s] Microsoft.Hosting.Lifetime Information: Now listening on: http://127.0.0.1:57207
| [0.009s] Microsoft.AspNetCore.Hosting.Diagnostics Debug: Loaded hosting startup assembly Interop.FunctionalTests
| [0.009s] Microsoft.Hosting.Lifetime Information: Application started. Press Ctrl+C to shut down.
| [0.009s] Microsoft.Hosting.Lifetime Information: Hosting environment: Production
| [0.009s] Microsoft.Hosting.Lifetime Information: Content root path: C:\Development\Source\aspnetcore\artifacts\bin\Interop.FunctionalTests\Debug\net7.0\
| [0.009s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting started
| [0.009s] Test Information: Sending request to 'http://127.0.0.1:57207/'.
| [0.009s] HttpEventSourceListener Debug: <- Event System.Net.Http - RequestStart : http,127.0.0.1,57207,/,2,0,2 ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionHandler#31431550,.ctor, ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : DiagnosticsHandler#20469972,.ctor, ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : RedirectHandler#54201252,.ctor, ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,0,0,.ctor,HttpConnectionPool http://127.0.0.1:57207 ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,0,0,GetHttp2ConnectionAsync,No available HTTP/2 connections; request queued. ->
| [0.010s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,0,0,AddHttp2ConnectionAsync,Creating new HTTP/2 connection for pool. ->
| [0.010s] Test Information: Waiting for request on server
| [0.011s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMGO62TGK3M3" accepted.
| [0.011s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMGO62TGK3M3" started.
| [0.011s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,.ctor,_connectionWindow. initialCredit=65535 ->
| [0.012s] HttpEventSourceListener Debug: <- Event System.Net.Http - ConnectionEstablished : 2,0 ->
| [0.012s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,TraceConnection,Http2Connection(HttpConnectionPool http://127.0.0.1:57207) ->
| [0.012s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SetupAsync,Initial connection-level WINDOW_UPDATE, windowUpdateAmount=67043329 ->
| [0.012s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=True ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReturnHttp2Connection,isNewConnection=True ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReturnHttp2Connection,Dequeued waiting HTTP2 request. ->
| [0.013s] HttpEventSourceListener Debug: <- Event System.Net.Http - RequestLeftQueue : 2.5824,2,0 ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReleaseStream,_streamsInUse=2 ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SendAsync,Sending request: Method: GET, RequestUri: 'http://127.0.0.1:57207/', Version: 2.0, Content: <null>, Headers:
|                                         {
|                                         } ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
| [0.013s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReturnHttp2Connection,Put HTTP2 connection in pool. ->
| [0.013s] HttpEventSourceListener Debug: <- Event System.Net.Http - RequestHeadersStart :  ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,WriteHeaders, ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,WriteIndexedHeader,index=2 ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,WriteIndexedHeader,index=6 ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,WriteBytes,Length=17 ->
| [0.014s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending SETTINGS frame for stream ID 0 with length 18 and flags NONE.
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,WriteIndexedHeader,index=4 ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,.ctor,[FlowControl] InitialClientStreamWindowSize: 65535, StreamWindowThreshold: 8191, WindowScaleThresholdMultiplier: 1 ->
| [0.014s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#63037041,RequestMessage,HttpResponseMessage#63037041,HttpRequestMessage#18094558 ->
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionResponseContent#8948761,.ctor, ->
| [0.014s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received SETTINGS frame for stream ID 0 with length 12 and flags NONE.
| [0.014s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#63037041,Content,HttpResponseMessage#63037041,HttpConnectionResponseContent#8948761 ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 0: StreamId=0; Type=Settings; Flags=None; PayloadLength=18. ->
| [0.015s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending SETTINGS frame for stream ID 0 with length 0 and flags ACK.
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=29 ->
| [0.015s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 0 with length 4 and flags 0x0.
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ChangeMaxConcurrentStreams,newValue=100, _streamsInUse=1, _availableStreamsWaiter?=False ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SendHeadersAsync,Started writing. Total header bytes=20 ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ChangeInitialWindowSize,newSize=98304 ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,Initialize,initialWindowSize=65535 ->
| [0.015s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendHeadersAsync,Wrote HEADERS frame. Length=20, flags=Ack, EndHeaders ->
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=9 ->
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SendSettingsAckAsync,Started writing. ->
| [0.016s] HttpEventSourceListener Debug: <- Event System.Net.Http - RequestHeadersStop :  ->
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=38 ->
| [0.016s] HttpEventSourceListener Debug: <- Event System.Net.Http - ResponseHeadersStart :  ->
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 1: StreamId=0; Type=WindowUpdate; Flags=None; PayloadLength=4. ->
| [0.016s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received HEADERS frame for stream ID 1 with length 20 and flags END_STREAM, END_HEADERS.
| [0.016s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessWindowUpdateFrame,StreamId=0; Type=WindowUpdate; Flags=None; PayloadLength=4. amount=65537 ->
| [0.017s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,AdjustCredit,_connectionWindow. amount=65537, current=65535 ->
| [0.017s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received SETTINGS frame for stream ID 0 with length 0 and flags ACK.
| [0.017s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.017s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request starting HTTP/2 GET http://127.0.0.1:57207/ - -
| [0.017s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 2: StreamId=0; Type=Settings; Flags=Ack; PayloadLength=0. ->
| [0.017s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,RefreshRtt,[FlowControl] Updated MinRtt: 4.672 ms ->
| [0.017s] Test Information: Stopping server
| [0.018s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting stopping
| [0.018s] Microsoft.Hosting.Lifetime Information: Application is shutting down...
| [0.018s] Test Information: Server writing 500000 bytes response
| [0.018s] Microsoft.AspNetCore.Server.Kestrel.Http2 Debug: Connection id "0HMGO62TGK3M3" is closing.
| [0.018s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0.
| [0.018s] Test Information: Server advancing 500000 bytes response
| [0.019s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending HEADERS frame for stream ID 1 with length 41 and flags END_HEADERS.
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 3: StreamId=0; Type=GoAway; Flags=None; PayloadLength=8. ->
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessGoAwayFrame,lastStreamId=2147483647, errorCode=NoError ->
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,Shutdown,_shutdown=False, _abortException= ->
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=False, _availableStreamsWaiter?=False ->
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalShutdownWaiter,_shutdownWaiter?=True ->
| [0.019s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,InvalidateHttp2Connection, ->
| [0.019s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.019s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,Dispose,_disposed=False, _streamsInUse=1 ->
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=False, _availableStreamsWaiter?=False ->
| [0.020s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalShutdownWaiter,_shutdownWaiter?=False ->
| [0.020s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 4: StreamId=1; Type=Headers; Flags=EndHeaders; PayloadLength=41. ->
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessHeadersFrame,StreamId=1; Type=Headers; Flags=EndHeaders; PayloadLength=41 ->
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,OnStatus,Status code is 200 ->
| [0.020s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,OnHeader,Date: Thu, 07 Apr 2022 00:51:20 GMT ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,OnHeader,Server: Kestrel ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.021s] HttpEventSourceListener Debug: <- Event System.Net.Http - ResponseHeadersStop :  ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 5: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 16384 < 8388608. ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,ReadResponseHeadersAsync,Received response: StatusCode: 200, ReasonPhrase: 'OK', Version: 2.0, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
|                                         {
|                                           Date: Thu, 07 Apr 2022 00:51:20 GMT
|                                           Server: Kestrel
|                                         } ->
| [0.021s] HttpEventSourceListener Debug: <- Event System.Net.Http - RequestStop :  ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 6: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.021s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 32768 < 8388608. ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.022s] Test Information: Started reading response content
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 7: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 49152 < 8388608. ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 8: StreamId=1; Type=Data; Flags=None; PayloadLength=16383. ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,AdjustWindowDynamic,[FlowControl] Updated Stream Window. StreamWindowSize: 131070, StreamWindowThreshold: 16383 ->
| [0.022s] Test Information: Received 49152 bytes. Total 49152 bytes.
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16383 ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 65535 < 8388608. ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.022s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=114687 ->
| [0.023s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.023s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,AdjustWindowDynamic,[FlowControl] Updated Stream Window. StreamWindowSize: 262140, StreamWindowThreshold: 32767 ->
| [0.023s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.023s] Test Information: Received 16383 bytes. Total 65535 bytes.
| [0.023s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=147453 ->
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.023s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.024s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.024s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 9: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.024s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.024s] Test Information: Received 16384 bytes. Total 81919 bytes.
| [0.024s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 81919 < 8388608. ->
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.024s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.024s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 10: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.025s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.025s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.025s] Test Information: Received 16384 bytes. Total 98303 bytes.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 98303 < 8388608. ->
| [0.025s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16381 and flags NONE.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 11: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.025s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.025s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.025s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 114687 < 8388608. ->
| [0.025s] Test Information: Received 16384 bytes. Total 114687 bytes.
| [0.026s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 12: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.026s] Test Information: Received 16384 bytes. Total 131071 bytes.
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 131071 < 8388608. ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 13: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.026s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 147455 < 8388608. ->
| [0.026s] Test Information: Received 16384 bytes. Total 147455 bytes.
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.027s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 14: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.027s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.027s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.027s] Test Information: Received 16384 bytes. Total 163839 bytes.
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.027s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 163839 < 8388608. ->
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 15: StreamId=1; Type=Data; Flags=None; PayloadLength=16383. ->
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16383 ->
| [0.028s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.028s] Test Information: Received 16383 bytes. Total 180222 bytes.
| [0.028s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 180222 < 8388608. ->
| [0.029s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.029s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 16: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.029s] Test Information: Received 16384 bytes. Total 196606 bytes.
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32767 ->
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 196606 < 8388608. ->
| [0.029s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.029s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.030s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 17: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.030s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16383 and flags NONE.
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 212990 < 8388608. ->
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.030s] Test Information: Received 16384 bytes. Total 212990 bytes.
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 18: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.030s] Test Information: Received 16384 bytes. Total 229374 bytes.
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.030s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 229374 < 8388608. ->
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 19: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.031s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.031s] Test Information: Received 16384 bytes. Total 245758 bytes.
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 245758 < 8388608. ->
| [0.031s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 20: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.031s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 16384 and flags NONE.
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.031s] Test Information: Received 16384 bytes. Total 262142 bytes.
| [0.031s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 262142 < 8388608. ->
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.032s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" received WINDOW_UPDATE frame for stream ID 1 with length 4 and flags 0x0.
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 21: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.032s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending DATA frame for stream ID 1 with length 8486 and flags END_STREAM.
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.032s] Test Information: Received 16384 bytes. Total 278526 bytes.
| [0.032s] Microsoft.AspNetCore.Server.Kestrel.Http2 Debug: Connection id "0HMGO62TGK3M3" is closed. The last processed stream ID was 1.
| [0.032s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 278526 < 8388608. ->
| [0.032s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request finished HTTP/2 GET http://127.0.0.1:57207/ - - - 200 - - 15.5903ms
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.033s] Microsoft.AspNetCore.Server.Kestrel.Http2 Trace: Connection id "0HMGO62TGK3M3" sending GOAWAY frame for stream ID 0 with length 8 and flags 0x0.
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 22: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.033s] Test Information: Received 16384 bytes. Total 294910 bytes.
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 294910 < 8388608. ->
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=32768 ->
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.033s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 23: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.034s] Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets Debug: Connection id "0HMGO62TGK3M3" sending FIN because: "The Socket transport's send loop completed gracefully."
| [0.034s] Test Information: Received 16384 bytes. Total 311294 bytes.
| [0.034s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMGO62TGK3M3" stopped.
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 311294 < 8388608. ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 24: StreamId=1; Type=Data; Flags=None; PayloadLength=16381. ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16381 ->
| [0.034s] Test Information: Received 16381 bytes. Total 327675 bytes.
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 327675 < 8388608. ->
| [0.034s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 25: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.035s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting stopped
| [0.035s] Test Information: Received 16384 bytes. Total 344059 bytes.
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 344059 < 8388608. ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessOutgoingFramesAsync,writeBytes=13 ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendWindowUpdateAsync,Started writing. amount=49149 ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReadFrameAsync,initialFrame=False ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FlushOutgoingBytesAsync,ActiveLength=13 ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,Frame 26: StreamId=1; Type=Data; Flags=None; PayloadLength=16384. ->
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,amount=16384 ->
| [0.035s] Test Information: Received 16384 bytes. Total 360443 bytes.
| [0.035s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ExtendWindow,_pendingWindowUpdate 360443 < 8388608. ->
| [0.037s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ProcessIncomingFramesAsync,ProcessIncomingFramesAsync: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host.. ->
| [0.037s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,Abort,abortException==System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
|                                          ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.Socket.ReceiveAsync(Memory`1 buffer, SocketFlags socketFlags, Boolean fromNetworkStream, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
|                                            at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
|                                            at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
|                                            at System.Threading.PortableThreadPool.IOCompletionPoller.Callback.Invoke(Event e)
|                                            at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
|                                            at System.Threading.ThreadPoolWorkQueue.Dispatch()
|                                            at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
|                                         --- End of stack trace from previous location ---
|                                            --- End of inner exception stack trace ---
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync() ->
| [0.037s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,Shutdown,_shutdown=True, _abortException=System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
|                                          ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.Socket.ReceiveAsync(Memory`1 buffer, SocketFlags socketFlags, Boolean fromNetworkStream, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
|                                            at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
|                                            at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
|                                            at System.Threading.PortableThreadPool.IOCompletionPoller.Callback.Invoke(Event e)
|                                            at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
|                                            at System.Threading.ThreadPoolWorkQueue.Dispatch()
|                                            at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
|                                         --- End of stack trace from previous location ---
|                                            --- End of inner exception stack trace ---
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync() ->
| [0.037s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=False, _availableStreamsWaiter?=False ->
| [0.037s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalShutdownWaiter,_shutdownWaiter?=False ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,OnReset,resetException=System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
|                                          ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.Socket.ReceiveAsync(Memory`1 buffer, SocketFlags socketFlags, Boolean fromNetworkStream, CancellationToken cancellationToken)
|                                            at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
|                                            at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
|                                            at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
|                                            at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
|                                            at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
|                                            at System.Threading.PortableThreadPool.IOCompletionPoller.Callback.Invoke(Event e)
|                                            at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
|                                            at System.Threading.ThreadPoolWorkQueue.Dispatch()
|                                            at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
|                                         --- End of stack trace from previous location ---
|                                            --- End of inner exception stack trace ---
|                                            at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync(), resetStreamErrorCode= ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,Cancel, ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,SendReset,Stream reset. Request=Completed, Response=Failed. ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,Complete,Stream complete. Request=Completed, Response=Failed. ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,1,RemoveStream, ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,ReleaseStream,_streamsInUse=1 ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,SignalAvailableStreamsWaiter,result=True, _availableStreamsWaiter?=False ->
| [0.038s] HttpEventSourceListener Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 38508469,32686703,0,FinalTeardown, ->
| [0.038s] HttpEventSourceListener Debug: <- Event System.Net.Http - ConnectionClosed : 2,0 ->
| [0.038s] Test Information: Error reading response. Total 360443 bytes.
| [0.040s] HttpEventSourceListener Debug: Stopping HttpEventSourceListener.
| [0.042s] Interop.FunctionalTests.Http2.Http2RequestTests Error: Test threw an exception.
| System.IO.IOException: The request was aborted.
|  ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host..
|  ---> System.Net.Sockets.SocketException (10054): An existing connection was forcibly closed by the remote host.
|    at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
|    at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ReceiveAsync(Socket socket, CancellationToken cancellationToken)
|    at System.Net.Sockets.Socket.ReceiveAsync(Memory`1 buffer, SocketFlags socketFlags, Boolean fromNetworkStream, CancellationToken cancellationToken)
|    at System.Net.Sockets.NetworkStream.ReadAsync(Memory`1 buffer, CancellationToken cancellationToken)
|    at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
|    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.ExecutionContextCallback(Object s)
|    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
|    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
|    at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext()
|    at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.InvokeContinuation(Action`1 continuation, Object state, Boolean forceAsync, Boolean requiresExecutionContextFlow)
|    at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.OnCompleted(SocketAsyncEventArgs _)
|    at System.Net.Sockets.SocketAsyncEventArgs.<>c.<.cctor>b__176_0(UInt32 errorCode, UInt32 numBytes, NativeOverlapped* nativeOverlapped)
|    at System.Threading.PortableThreadPool.IOCompletionPoller.Callback.Invoke(Event e)
|    at System.Threading.ThreadPoolTypedWorkItemQueue`2.System.Threading.IThreadPoolWorkItem.Execute()
|    at System.Threading.ThreadPoolWorkQueue.Dispatch()
|    at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
| --- End of stack trace from previous location ---
|    --- End of inner exception stack trace ---
|    at System.Net.Http.Http2Connection.ProcessIncomingFramesAsync()
|    --- End of inner exception stack trace ---
|    at System.Net.Http.Http2Connection.ThrowRequestAborted(Exception innerException)
|    at System.Net.Http.Http2Connection.Http2Stream.CheckResponseBodyState()
|    at System.Net.Http.Http2Connection.Http2Stream.TryReadFromBuffer(Span`1 buffer, Boolean partOfSyncRead)
|    at System.Net.Http.Http2Connection.Http2Stream.ReadDataAsync(Memory`1 buffer, HttpResponseMessage responseMessage, CancellationToken cancellationToken)
|    at Interop.FunctionalTests.Http2.Http2RequestTests.StartLongRunningRequestAsync(ILogger logger, IHost host, HttpMessageInvoker client) in C:\Development\Source\aspnetcore\src\Servers\Kestrel\test\Interop.FunctionalTests\Http2\Http2RequestTests.cs:line 132
|    at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) in C:\Development\Source\aspnetcore\src\Shared\TaskExtensions.cs:line 88
|    at Interop.FunctionalTests.Http2.Http2RequestTests.GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes(Boolean hasTrailers) in C:\Development\Source\aspnetcore\src\Servers\Kestrel\test\Interop.FunctionalTests\Http2\Http2RequestTests.cs:line 103
|    at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_1.<<InvokeTestMethodAsync>b__1>d.MoveNext() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestInvoker.cs:line 264
| --- End of stack trace from previous location ---
|    at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\ExecutionTimer.cs:line 48
|    at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 90
| [0.062s] TestLifetime Information: Finished test GET_RequestReturnsLargeData_GracefulShutdownDuringRequest_RequestGracefullyCompletes-False in 0.0599109s

[ManickaP]

In server logs I see 31 outgoing DATA frames and then GO_AWAY, on client I see only 22 of them before it blows up. It's like client cannot keep up with processing the incoming data.
Have you already done any perf improvements for H/2? Is it possible that you're now so fast that before we even have a chance to consume all the data you've already closed connection?

[halter73]

Have you already done any perf improvements for H/2? Is it possible that you're now so fast that before we even have a chance to consume all the data you've already closed connection?

Maybe. Kestrel fully closing the socket immediately after sending final GOAWAY is the root problem. If the client tries to send a WINDOW_UPDATE around the same time as is the case in this test, the client can observe a socket error before it has a chance to consume all of the data flushed by the server.

We basically need to undo 54caf30#diff-f56927c9784e5825770f944af79a3ec57875ca9179c1f47b1fafc57d479bd112 at least for HTTP/2 connections. As the commit message notes, I did this because browsers would take forever to send back a FIN for HTTP/1.1 connections (I'm talking minutes here), so you'd always end up waiting on the Kestrel default 5 second shutdown timeout because browsers wouldn't promptly close their connection. This didn't really cause a huge problem for HTTP/1.1 connections because it's uncommon for a client to still be sending data when the server ends a response with HTTP/1.1, but obviously this is quite different with HTTP/2.

We should continue reading and ignoring frames after the second GOAWAY, but we shouldn't close the socket until either receiving a FIN from the client or hitting a relatively short timeout. I don't want to end up in the situation where Kestrel always waits for the (now 30 second default!) timeout to shutdown, but I'm hoping modern clients and browsers that support HTTP/2 are much quicker to close the connection.

Kestrel's socket transport doesn't support just closing the send side of the connection right now, so we'd be relying on the GOAWAY being enough for the client to send us a FIN. I think that would work in most or maybe even all cases with real HTTP/2 clients, but we could look into updating the transport to half close the connection when we just close the output pipe if we really need to.

[halter73]

Related suggested change to System.Net.Sockets which might address the same issue without complicating Kestrel: dotnet/runtime#43385

@geoffkizer @scalablecory no need to look at this of course, but I would appreciate any insights you might have.

[JamesNK]

This test could be changed to in-memory. Or removed altogether.

The test was added to check this issue - #40933. It's a valid scenario but HTTP/2 output writing has been completely refactored since then and the code it's testing is completely different.

Edit: I think even failing like it is at the moment might be a valid pass for the scenario (although not ideal). The request being ungracefully killed is better than the H2 connection getting into a bad state and stopping the server from shutting down until timeout.

Thanks for contacting us.

We're moving this issue to the .NET 7 Planning milestone for future evaluation / consideration. We would like to keep this around to collect more feedback, which can help us with prioritizing this work. We will re-evaluate this issue, during our next planning meeting(s).
If we later determine, that the issue has no community involvement, or it's very rare and low-impact issue, we will close it - so that the team can focus on more important and high impact issues.
To learn more about what to expect next and how this issue will be handled you can read more about our triage process here.