[HTTP/3] Cancellation of response download not reported correctly on server

[JamesNK]

Justification for 6.0: Causes data loss / data corruption on server side.

Reproduction: #56129 (comment)

---

1. Client calls server
2. Client sends data
3. Client pauses sending.
4. Server reads data
5. Server sends data
6. Server pauses sending.
7. Client reads data
8. Client cancels request (HttpResponseMessage.Dispose())
9. Server QuicStream.ReadAsync doesn't throw QuicStreamAbortedException. Instead QuicStream.ReadAsync returns a read count of 0.
10. Server never raises its HttpContext.RequestAbort cancellation token because it never saw the abort.

Logs

 Interop.FunctionalTests.Http3.Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation
   Source: Http3RequestTests.cs line 77
   Duration: 5.4 sec

  Message: 
System.TimeoutException : The operation has timed out.

  Stack Trace: 
TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber) line 125
Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation() line 145
--- End of stack trace from previous location ---

  Standard Output: 
| [0.009s] TestLifetime Information: Starting test Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation at 2021-07-22T03:15:33
<- Event Private.InternalDiagnostics.System.Net.Http - Info : SocketsHttpHandler#2889227,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpClient#21168530,.ctor,HttpClient#21168530,SocketsHttpHandler#2889227 ->
| [0.069s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting starting
| [0.105s] Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer Debug: Using development certificate: CN=localhost (Thumbprint: 2584996C10BB6B5D974C7FF0A7D513F6E9BD16B8)
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#49467480,.ctor,[list][0x22CD09646E0] Listener created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#49467480,.ctor,[list][0x22CD09646E0] Listener started ->
| [0.149s] Microsoft.Hosting.Lifetime Information: Now listening on: https://127.0.0.1:61512
| [0.155s] Microsoft.AspNetCore.Hosting.Diagnostics Debug: Loaded hosting startup assembly Interop.FunctionalTests
| [0.156s] Microsoft.Hosting.Lifetime Information: Application started. Press Ctrl+C to shut down.
| [0.156s] Microsoft.Hosting.Lifetime Information: Hosting environment: Production
| [0.156s] Microsoft.Hosting.Lifetime Information: Content root path: C:\Development\Source\AspNetCore\artifacts\bin\Interop.FunctionalTests\Debug\net6.0\
| [0.156s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting started
<- Event Private.InternalDiagnostics.System.Net.Http - Info : StreamingHttpContext#4530763,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpRequestMessage#38803894,Content,HttpRequestMessage#38803894,StreamingHttpContext#4530763 ->
<- Event System.Net.Http - RequestStart : https,127.0.0.1,61512,/,3,0,2 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,.ctor,AutoConfigUrl=(null), AutoDetect=True, Proxy=(null), ProxyBypass=(null) ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,.ctor,_useProxy=True ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,TryCreate,AutoSettingsUsed, calling WinHttpOpen ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionHandler#15343725,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : DiagnosticsHandler#7911073,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : RedirectHandler#16633715,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : WinInetProxyHelper#43340473,GetProxyForUrl,error=12180 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,GetProxyForUrl,useProxy=False ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,.ctor,HttpConnectionPool https://127.0.0.1:61512 ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,GetHttp3ConnectionAsync,Attempting new HTTP3 connection. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,.ctor,[conn][0x22CD0969FA0] Outbound connection created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,.ctor,[conn][0x22CD0E62F40] Inbound connection created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event IDEAL_PROCESSOR_CHANGED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event STREAMS_AVAILABLE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event DATAGRAM_STATE_CHANGED ->
| [0.209s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" accepted.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event PEER_CERTIFICATE_RECEIVED ->
| [0.216s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" accepted.
| [0.219s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" started.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,.ctor,[strm][0x22CD096DFA0] Outbound unidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,HandleEventPeerCertificateReceived,[conn][0x22CD0969FA0] Certificate validation for '$CN=localhost' finished with $None ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event CONNECTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event CONNECTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,.ctor,[strm][0x22CD096DB30] Outbound unidirectional stream created in connection [conn][0x22CD0969FA0]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,.ctor,[strm][0x22CD0EAE4D0] Inbound unidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEvent,[strm][0x22CD0EAE4D0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,GetHttp3ConnectionAsync,New HTTP3 connection established. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,.ctor,[strm][0x22CD0EAE790] Outbound bidirectional stream created in connection [conn][0x22CD0969FA0]. ->
| [0.244s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" type Unidirectional connected.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,ReadAsync,[strm][0x22CD0EAE790] Stream reading into Memory of '64' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,.ctor,[strm][0x22CD0EAEAF0] Inbound bidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,.ctor,[strm][0x22CD0E781B0] Inbound unidirectional stream created in connection [conn][0x22CD0969FA0]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event IDEAL_SEND_BUFFER_SIZE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,ReadAsync,[strm][0x22CD0EAE4D0] Stream reading into Memory of '4096' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,ReadAsync,[strm][0x22CD0EAE4D0] Stream reading into Memory of '4096' bytes. ->
| [0.267s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:2" type Unidirectional accepted.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,ReadAsync,[strm][0x22CD0EAEAF0] Stream reading into Memory of '4096' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,ReadAsync,[strm][0x22CD0EAEAF0] Stream reading into Memory of '4096' bytes. ->
| [0.268s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" type Bidirectional accepted.
| [0.276s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:2" received SETTINGS frame for stream ID 2 with length 5.
| [0.279s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" received HEADERS frame for stream ID 0 with length 48.
| [0.301s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" received DATA frame for stream ID 0 with length 11.
| [0.324s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request starting HTTP/3 POST https://127.0.0.1:61512/ - -
| [0.332s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Flush headers on server
| [0.341s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" sending HEADERS frame for stream ID 0 with length 53.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_COMPLETE ->
| [0.342s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server read body
| [0.346s] Microsoft.AspNetCore.Server.Kestrel Debug: Connection id "0HMACNRS3J8IG:0", Request id "0HMACNRS3J8IG:0": started reading request body.
| [0.351s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" sending DATA frame for stream ID 0 with length 11.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_COMPLETE ->
| [0.352s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server wait for abort
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event IDEAL_SEND_BUFFER_SIZE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,ReadFrameEnvelopeAsync,Received frame 1 of length 53. ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#61858317,RequestMessage,HttpResponseMessage#61858317,HttpRequestMessage#38803894 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionResponseContent#57265338,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#61858317,Content,HttpResponseMessage#61858317,HttpConnectionResponseContent#57265338 ->
<- Event System.Net.Http - RequestStop :  ->
| [0.370s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Client read body
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,ReadFrameEnvelopeAsync,Received frame 0 of length 11. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,ReadAsync,[strm][0x22CD0EAE790] Stream reading into Memory of '4' bytes. ->
| [0.371s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Client canceling
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Dispose,[strm][0x22CD0EAE790] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Dispose,[strm][0x22CD0EAE790] Stream disposed ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event PEER_RECEIVE_ABORTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event PEER_SEND_SHUTDOWN ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEventPeerSendShutdown,[strm][0x22CD0EAEAF0] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEventShutdownComplete,[strm][0x22CD0EAE790] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Cleanup,[strm][0x22CD0EAE790] releasing handles. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEventShutdownComplete,[strm][0x22CD0EAEAF0] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event STREAMS_AVAILABLE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,Dispose,Disposing pool. ->
| [5.399s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Listener has aborted with exception: Operation aborted.
| [5.401s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" aborted by application because: "The connection was aborted by the application via MultiplexedConnectionContext.Abort().".
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEvent,[strm][0x22CD0EAE4D0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEventConnectionClose,[strm][0x22CD0EAE4D0] Stream handling connection [conn][0x22CD0E62F40] close ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEventConnectionClose,[strm][0x22CD096DFA0] Stream handling connection [conn][0x22CD0E62F40] close ->
| [5.405s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Some connections failed to close gracefully during server shutdown.
| [5.410s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" aborted by application because: "The connection was aborted because the server is shutting down and request processing didn't complete within the time specified by HostOptions.ShutdownTimeout.".
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event SHUTDOWN_INITIATED_BY_PEER ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEventConnectionClose,[strm][0x22CD096DB30] Stream handling connection [conn][0x22CD0969FA0] close with code 256 ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEventConnectionClose,[strm][0x22CD0E781B0] Stream handling connection [conn][0x22CD0969FA0] close with code 256 ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,Dispose,[strm][0x22CD096DB30] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,Dispose,[strm][0x22CD096DB30] Stream disposed ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,Dispose,[conn][0x22CD0969FA0] Stream disposing True ->
| [5.423s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Connection id "0HMACNRS3J8IG" is closing.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,Dispose,[strm][0x22CD0E781B0] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,Dispose,[strm][0x22CD0E781B0] Stream disposed ->
| [5.425s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "(null)" sending GO_AWAY frame for stream ID 3 with length 8.
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,Abort,abortException==System.Net.Quic.QuicConnectionAbortedException: Connection aborted by peer (256).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventConnectionClose(State state) in System.Net.Quic.dll:token 0x6000159+0x109
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventShutdownComplete(State state, StreamEvent& evt) in System.Net.Quic.dll:token 0x600014e+0x14
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt) in System.Net.Quic.dll:token 0x6000149+0xbc
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent) in System.Net.Quic.dll:token 0x6000148+0x14
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token) in System.Net.Quic.dll:token 0x600019d+0xf
   at System.Net.Http.Http3Connection.<>c__DisplayClass45_0.<<ProcessServerControlStreamAsync>g__ReadFrameEnvelopeAsync|0>d.MoveNext() in System.Net.Http.dll:token 0x60006aa+0x9d
--- End of stack trace from previous location ---
   at System.Net.Http.Http3Connection.ProcessServerControlStreamAsync(QuicStream stream, ArrayBuffer buffer) in System.Net.Http.dll:token 0x6000699+0x21c
   at System.Net.Http.Http3Connection.ProcessServerStreamAsync(QuicStream stream) in System.Net.Http.dll:token 0x6000698+0x204
   at System.Net.Http.Http3Connection.ProcessServerStreamAsync(QuicStream stream) in System.Net.Http.dll:token 0x6000698+0x4fb ->
| [5.427s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" shutting down writes because: "The QUIC transport's send loop completed gracefully.".
| [5.430s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Connection id "0HMACNRS3J8IG" is closed. The last processed stream ID was 0.
| [5.434s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "(null)" sending GO_AWAY frame for stream ID 3 with length 1.
| [5.434s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Trace id "0HMACNRS3J8IG:0": HTTP/3 stream error "H3_NO_ERROR". An abort is being sent to the stream.
| Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/3 connection faulted.
| [5.435s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" aborted by application because: "The HTTP/3 connection faulted.".
| [5.435s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" shutting down writes because: "The QUIC transport's send loop completed gracefully.".
| [5.438s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Trace id "(null)": HTTP/3 stream error "H3_NO_ERROR". An abort is being sent to the stream.
| Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/3 connection faulted.
| [5.438s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server RequestAborted token raised.
| [5.438s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" aborted by application because: "The HTTP/3 connection faulted.".
| [5.439s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request finished HTTP/3 POST https://127.0.0.1:61512/ - - - 200 - - 5116.4570ms
| [5.443s] Microsoft.AspNetCore.Server.Kestrel Debug: Connection id "0HMACNRS3J8IG:0", Request id "0HMACNRS3J8IG:0": done reading request body.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Dispose,[strm][0x22CD0EAEAF0] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Cleanup,[strm][0x22CD0EAEAF0] releasing handles. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Dispose,[strm][0x22CD0EAEAF0] Stream disposed ->
| [5.446s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" stopped.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,Dispose,[conn][0x22CD0E62F40] Stream disposing True ->
| [5.455s] Interop.FunctionalTests.Http3.Http3RequestTests Error: Test threw an exception.
| System.TimeoutException: The operation has timed out.
|    at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber) in C:\Development\Source\AspNetCore\src\Shared\TaskExtensions.cs:line 125
|    at Interop.FunctionalTests.Http3.Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation() in C:\Development\Source\AspNetCore\src\Servers\Kestrel\test\Interop.FunctionalTests\Http3\Http3RequestTests.cs:line 145
|    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
| [5.465s] TestLifetime Information: Finished test Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation in 5.4616622s

.NET SDK (reflecting any global.json):
 Version:   6.0.100-rc.1.21370.2
 Commit:    64c36e46ff

Tagging subscribers to this area: @dotnet/ncl
See info in area-owners.md if you want to be subscribed.

Issue Details

---

1. Client calls server
2. Client sends data
3. Server reads data
4. Server sends data
5. Client reads data
6. Client cancels request (HttpResponseMessage.Dispose())
7. QuicStream.ReadAsync doesn't throw QuicStreamAbortedException. Instead QuicStream.ReadAsync returns a read count of 0.
8. Server never raises its HttpContext.RequestAbort cancellation token because it never saw the cancellation.

Logs

 Interop.FunctionalTests.Http3.Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation
   Source: Http3RequestTests.cs line 77
   Duration: 5.4 sec

  Message: 
System.TimeoutException : The operation has timed out.

  Stack Trace: 
TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber) line 125
Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation() line 145
--- End of stack trace from previous location ---

  Standard Output: 
| [0.009s] TestLifetime Information: Starting test Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation at 2021-07-22T03:15:33
<- Event Private.InternalDiagnostics.System.Net.Http - Info : SocketsHttpHandler#2889227,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpClient#21168530,.ctor,HttpClient#21168530,SocketsHttpHandler#2889227 ->
| [0.069s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting starting
| [0.105s] Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer Debug: Using development certificate: CN=localhost (Thumbprint: 2584996C10BB6B5D974C7FF0A7D513F6E9BD16B8)
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#49467480,.ctor,[list][0x22CD09646E0] Listener created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#49467480,.ctor,[list][0x22CD09646E0] Listener started ->
| [0.149s] Microsoft.Hosting.Lifetime Information: Now listening on: https://127.0.0.1:61512
| [0.155s] Microsoft.AspNetCore.Hosting.Diagnostics Debug: Loaded hosting startup assembly Interop.FunctionalTests
| [0.156s] Microsoft.Hosting.Lifetime Information: Application started. Press Ctrl+C to shut down.
| [0.156s] Microsoft.Hosting.Lifetime Information: Hosting environment: Production
| [0.156s] Microsoft.Hosting.Lifetime Information: Content root path: C:\Development\Source\AspNetCore\artifacts\bin\Interop.FunctionalTests\Debug\net6.0\
| [0.156s] Microsoft.Extensions.Hosting.Internal.Host Debug: Hosting started
<- Event Private.InternalDiagnostics.System.Net.Http - Info : StreamingHttpContext#4530763,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpRequestMessage#38803894,Content,HttpRequestMessage#38803894,StreamingHttpContext#4530763 ->
<- Event System.Net.Http - RequestStart : https,127.0.0.1,61512,/,3,0,2 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,.ctor,AutoConfigUrl=(null), AutoDetect=True, Proxy=(null), ProxyBypass=(null) ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,.ctor,_useProxy=True ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,TryCreate,AutoSettingsUsed, calling WinHttpOpen ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionHandler#15343725,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : DiagnosticsHandler#7911073,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : RedirectHandler#16633715,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : WinInetProxyHelper#43340473,GetProxyForUrl,error=12180 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#43340473,GetProxyForUrl,useProxy=False ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,.ctor,HttpConnectionPool https://127.0.0.1:61512 ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,GetHttp3ConnectionAsync,Attempting new HTTP3 connection. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,.ctor,[conn][0x22CD0969FA0] Outbound connection created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,.ctor,[conn][0x22CD0E62F40] Inbound connection created ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event IDEAL_PROCESSOR_CHANGED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event STREAMS_AVAILABLE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event DATAGRAM_STATE_CHANGED ->
| [0.209s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" accepted.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event PEER_CERTIFICATE_RECEIVED ->
| [0.216s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" accepted.
| [0.219s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" started.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,.ctor,[strm][0x22CD096DFA0] Outbound unidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,HandleEventPeerCertificateReceived,[conn][0x22CD0969FA0] Certificate validation for '$CN=localhost' finished with $None ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event CONNECTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event CONNECTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,.ctor,[strm][0x22CD096DB30] Outbound unidirectional stream created in connection [conn][0x22CD0969FA0]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,.ctor,[strm][0x22CD0EAE4D0] Inbound unidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEvent,[strm][0x22CD0EAE4D0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,GetHttp3ConnectionAsync,New HTTP3 connection established. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,(null) Stream received event START_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,.ctor,[strm][0x22CD0EAE790] Outbound bidirectional stream created in connection [conn][0x22CD0969FA0]. ->
| [0.244s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" type Unidirectional connected.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,ReadAsync,[strm][0x22CD0EAE790] Stream reading into Memory of '64' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,.ctor,[strm][0x22CD0EAEAF0] Inbound bidirectional stream created in connection [conn][0x22CD0E62F40]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event PEER_STREAM_STARTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,.ctor,[strm][0x22CD0E781B0] Inbound unidirectional stream created in connection [conn][0x22CD0969FA0]. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event IDEAL_SEND_BUFFER_SIZE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,ReadAsync,[strm][0x22CD0EAE4D0] Stream reading into Memory of '4096' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,ReadAsync,[strm][0x22CD0E781B0] Stream reading into Memory of '32' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,ReadAsync,[strm][0x22CD0EAE4D0] Stream reading into Memory of '4096' bytes. ->
| [0.267s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:2" type Unidirectional accepted.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,ReadAsync,[strm][0x22CD0EAEAF0] Stream reading into Memory of '4096' bytes. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,ReadAsync,[strm][0x22CD0EAEAF0] Stream reading into Memory of '4096' bytes. ->
| [0.268s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" type Bidirectional accepted.
| [0.276s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:2" received SETTINGS frame for stream ID 2 with length 5.
| [0.279s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" received HEADERS frame for stream ID 0 with length 48.
| [0.301s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" received DATA frame for stream ID 0 with length 11.
| [0.324s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request starting HTTP/3 POST https://127.0.0.1:61512/ - -
| [0.332s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Flush headers on server
| [0.341s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" sending HEADERS frame for stream ID 0 with length 53.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_COMPLETE ->
| [0.342s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server read body
| [0.346s] Microsoft.AspNetCore.Server.Kestrel Debug: Connection id "0HMACNRS3J8IG:0", Request id "0HMACNRS3J8IG:0": started reading request body.
| [0.351s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "0HMACNRS3J8IG:0" sending DATA frame for stream ID 0 with length 11.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_COMPLETE ->
| [0.352s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server wait for abort
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event IDEAL_SEND_BUFFER_SIZE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,ReadFrameEnvelopeAsync,Received frame 1 of length 53. ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#61858317,RequestMessage,HttpResponseMessage#61858317,HttpRequestMessage#38803894 ->
<- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionResponseContent#57265338,.ctor, ->
<- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpResponseMessage#61858317,Content,HttpResponseMessage#61858317,HttpConnectionResponseContent#57265338 ->
<- Event System.Net.Http - RequestStop :  ->
| [0.370s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Client read body
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,ReadFrameEnvelopeAsync,Received frame 0 of length 11. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,ReadAsync,[strm][0x22CD0EAE790] Stream reading into Memory of '4' bytes. ->
| [0.371s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Client canceling
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Dispose,[strm][0x22CD0EAE790] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Dispose,[strm][0x22CD0EAE790] Stream disposed ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event PEER_RECEIVE_ABORTED ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event RECEIVE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event PEER_SEND_SHUTDOWN ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEventPeerSendShutdown,[strm][0x22CD0EAEAF0] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEvent,[strm][0x22CD0EAE790] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,HandleEventShutdownComplete,[strm][0x22CD0EAE790] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#30135413,Cleanup,[strm][0x22CD0EAE790] releasing handles. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEvent,[strm][0x22CD0EAEAF0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,HandleEventShutdownComplete,[strm][0x22CD0EAEAF0] Stream completing resettable event source. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event STREAMS_AVAILABLE ->
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,0,0,Dispose,Disposing pool. ->
| [5.399s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Listener has aborted with exception: Operation aborted.
| [5.401s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" aborted by application because: "The connection was aborted by the application via MultiplexedConnectionContext.Abort().".
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEvent,[strm][0x22CD0EAE4D0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#60644701,HandleEventConnectionClose,[strm][0x22CD0EAE4D0] Stream handling connection [conn][0x22CD0E62F40] close ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEvent,[strm][0x22CD096DFA0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#34717384,HandleEventConnectionClose,[strm][0x22CD096DFA0] Stream handling connection [conn][0x22CD0E62F40] close ->
| [5.405s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Some connections failed to close gracefully during server shutdown.
| [5.410s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Connection id "0HMACNRS3J8IG" aborted by application because: "The connection was aborted because the server is shutting down and request processing didn't complete within the time specified by HostOptions.ShutdownTimeout.".
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event SHUTDOWN_INITIATED_BY_PEER ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SEND_SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEvent,[strm][0x22CD096DB30] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,HandleEventConnectionClose,[strm][0x22CD096DB30] Stream handling connection [conn][0x22CD0969FA0] close with code 256 ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEvent,[strm][0x22CD0E781B0] Stream received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,HandleEventConnectionClose,[strm][0x22CD0E781B0] Stream handling connection [conn][0x22CD0969FA0] close with code 256 ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,Dispose,[strm][0x22CD096DB30] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#22460983,Dispose,[strm][0x22CD096DB30] Stream disposed ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,NativeCallbackHandler,[conn][0x22CD0969FA0] Connection received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,NativeCallbackHandler,[conn][0x22CD0E62F40] Connection received event SHUTDOWN_COMPLETE ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#57906006,Dispose,[conn][0x22CD0969FA0] Stream disposing True ->
| [5.423s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Connection id "0HMACNRS3J8IG" is closing.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,Dispose,[strm][0x22CD0E781B0] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11373314,Dispose,[strm][0x22CD0E781B0] Stream disposed ->
| [5.425s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "(null)" sending GO_AWAY frame for stream ID 3 with length 8.
<- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 60604200,36620877,0,Abort,abortException==System.Net.Quic.QuicConnectionAbortedException: Connection aborted by peer (256).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventConnectionClose(State state) in System.Net.Quic.dll:token 0x6000159+0x109
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventShutdownComplete(State state, StreamEvent& evt) in System.Net.Quic.dll:token 0x600014e+0x14
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt) in System.Net.Quic.dll:token 0x6000149+0xbc
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent) in System.Net.Quic.dll:token 0x6000148+0x14
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token) in System.Net.Quic.dll:token 0x600019d+0xf
   at System.Net.Http.Http3Connection.<>c__DisplayClass45_0.<<ProcessServerControlStreamAsync>g__ReadFrameEnvelopeAsync|0>d.MoveNext() in System.Net.Http.dll:token 0x60006aa+0x9d
--- End of stack trace from previous location ---
   at System.Net.Http.Http3Connection.ProcessServerControlStreamAsync(QuicStream stream, ArrayBuffer buffer) in System.Net.Http.dll:token 0x6000699+0x21c
   at System.Net.Http.Http3Connection.ProcessServerStreamAsync(QuicStream stream) in System.Net.Http.dll:token 0x6000698+0x204
   at System.Net.Http.Http3Connection.ProcessServerStreamAsync(QuicStream stream) in System.Net.Http.dll:token 0x6000698+0x4fb ->
| [5.427s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" shutting down writes because: "The QUIC transport's send loop completed gracefully.".
| [5.430s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Connection id "0HMACNRS3J8IG" is closed. The last processed stream ID was 0.
| [5.434s] Microsoft.AspNetCore.Server.Kestrel.Http3 Trace: Connection id "(null)" sending GO_AWAY frame for stream ID 3 with length 1.
| [5.434s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Trace id "0HMACNRS3J8IG:0": HTTP/3 stream error "H3_NO_ERROR". An abort is being sent to the stream.
| Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/3 connection faulted.
| [5.435s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" aborted by application because: "The HTTP/3 connection faulted.".
| [5.435s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:0" shutting down writes because: "The QUIC transport's send loop completed gracefully.".
| [5.438s] Microsoft.AspNetCore.Server.Kestrel.Http3 Debug: Trace id "(null)": HTTP/3 stream error "H3_NO_ERROR". An abort is being sent to the stream.
| Microsoft.AspNetCore.Connections.ConnectionAbortedException: The HTTP/3 connection faulted.
| [5.438s] Interop.FunctionalTests.Http3.Http3RequestTests Information: Server RequestAborted token raised.
| [5.438s] Microsoft.AspNetCore.Server.Kestrel.Transport.Quic Debug: Stream id "0HMACNRS3J8IG:3" aborted by application because: "The HTTP/3 connection faulted.".
| [5.439s] Microsoft.AspNetCore.Hosting.Diagnostics Information: Request finished HTTP/3 POST https://127.0.0.1:61512/ - - - 200 - - 5116.4570ms
| [5.443s] Microsoft.AspNetCore.Server.Kestrel Debug: Connection id "0HMACNRS3J8IG:0", Request id "0HMACNRS3J8IG:0": done reading request body.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Dispose,[strm][0x22CD0EAEAF0] Stream disposing True ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Cleanup,[strm][0x22CD0EAEAF0] releasing handles. ->
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#13273752,Dispose,[strm][0x22CD0EAEAF0] Stream disposed ->
| [5.446s] Microsoft.AspNetCore.Server.Kestrel.Connections Debug: Connection id "0HMACNRS3J8IG" stopped.
<- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#6451435,Dispose,[conn][0x22CD0E62F40] Stream disposing True ->
| [5.455s] Interop.FunctionalTests.Http3.Http3RequestTests Error: Test threw an exception.
| System.TimeoutException: The operation has timed out.
|    at Microsoft.AspNetCore.Testing.TaskExtensions.TimeoutAfter(Task task, TimeSpan timeout, String filePath, Int32 lineNumber) in C:\Development\Source\AspNetCore\src\Shared\TaskExtensions.cs:line 125
|    at Interop.FunctionalTests.Http3.Http3RequestTests.Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation() in C:\Development\Source\AspNetCore\src\Servers\Kestrel\test\Interop.FunctionalTests\Http3\Http3RequestTests.cs:line 145
|    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
| [5.465s] TestLifetime Information: Finished test Bidirectional_ClientCancellationAfterResponseReceived_ServerGetsCancellation in 5.4616622s

.NET SDK (reflecting any global.json):
 Version:   6.0.100-rc.1.21370.2
 Commit:    64c36e46ff

Author:	JamesNK
Assignees:	-
Labels:	area-System.Net.Http
Milestone:	-

[CarnaViire]

@JamesNK when you saw this, did the code already contain changes from #55724 ? A lot of aborting issues were fixed in that PR

UPD:

Ok, I've re-read the description again. So, as I understand the description, client already has sent the request and now is reading a response. Why would server's ReadAsync throw? Server's reading side was finished already - I understand that from the fact that server is already sending the response. So server's ReadAsync will return 0 on the subsequent calls. Server's WriteAsync should properly throw though, because client has aborted reading in Dispose (fixed in #55724).

Please note that some first WriteAsync's after peer aborting might "succeed" because success would just mean buffering in transport and because of the timings of events arriving, I've mentioned it in that PR:

I've spent a lot of time digging why server didn't get StreamAbortedException on Write even after client clearly called AbortRead and it was synchronized by semaphores. I found out that it is possible that PEER_RECEIVE_ABORTED event will arrive with a significant delay after peer calls AbortRead. In that case even with synchronization via semaphores, first writes after peer aborting may "succeed" (get SEND_COMPLETE event). I ended up asserting that PEER_RECEIVE_ABORTED would arrive eventually.

[JamesNK]

Ok, I've re-read the description again. So, as I understand the description, client already has sent the request and now is reading a response. Why would server's ReadAsync throw? Server's reading side was finished already

In a duplex scenario, the client and server sends are still open. The client hasn't finished sending. I'll update the description in the first post to be more explicit. I'm not experienced with reading the logs from HTTP and QUIC event sources but you should be able to see that low-level behavior there.

[karelz]

Triage: If it is not specific to Duplex, we should try it in 6.0.

[CarnaViire]

From online discussion: This is not specific to duplex, it will most probably show on disposing not finished request (e.g. upload?) Dispose on Quic stream will send FIN flag on write side - that's why server's Read was returning 0. We need to add HTTP/3 level logic to be sure to differentiate between fully sent and canceled request, and in case of canceled, call AbortWrite on Quic stream before disposing it.

[JamesNK]

I've confirmed that it is not specific to duplex. Canceling an in-progress GET request shows the same problem.

https://github.com/dotnet/aspnetcore/tree/jamesnk/http3-httpclientbug-disposeresponse

Test: GET_ClientCancellationAfterResponseHeaders_RequestAbortRaised

[karelz]

Thanks @JamesNK!