Skip to content

[HTTP/3] Http3RequestStream.BufferFrameEnvelope null reference error #57619

New issue
New issue
Closed
#59204
Closed
[HTTP/3] Http3RequestStream.BufferFrameEnvelope null reference error#57619
#59204
Assignees
CarnaViire
Labels
area-System.Net.Httpbug
Milestone
7.0.0
@JamesNK

Description

@JamesNK
JamesNK
opened on Aug 18, 2021

The scenario is HttpClient is sending data to the server. The client writes some data to the request stream, then pauses enough so that HttpClient.Timeout is exceeded and the request is canceled.

The client then writes some more data to the canceled request stream. At this point, a NullReferenceException is sometimes thrown. Flakey behavior.

Expected exception: TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 0.3 seconds elapsing.

Logs:

 ClientStream_HttpClientWithTimeout_Success
   Source: StreamingTests.cs line 327
   Duration: 428 ms

  Message: 
System.Exception : Exception of type RpcException expected; got exception of type NullReferenceException.
  ----> System.NullReferenceException : Object reference not set to an instance of an object.
TearDown : System.Exception : 1 error(s) logged.
Grpc.Net.Client.Internal.GrpcCall - ErrorSendingMessage - Error sending message.
===================
System.NullReferenceException: Object reference not set to an instance of an object.
   at System.Net.Http.Http3RequestStream.BufferFrameEnvelope(Http3FrameType frameType, Int64 payloadLength)
   at System.Net.Http.Http3RequestStream.WriteRequestContentAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
   at Grpc.Net.Client.StreamExtensions.WriteMessageAsync[TMessage](Stream stream, GrpcCall call, TMessage message, Action`2 serializer, CallOptions callOptions) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\StreamExtensions.cs:line 303
   at Grpc.Net.Client.Internal.HttpContentClientStreamWriter`2.WriteAsyncCore[TState](Func`5 writeFunc, TState state) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\HttpContentClientStreamWriter.cs:line 159
   at Grpc.Tests.Shared.ExceptionAssert.ThrowsAsync[TException](Func`1 action, String[] possibleMessages) in C:\Development\Source\grpc-dotnet\test\Shared\ExceptionAssert.cs:line 37
===================

  Stack Trace: 
ExceptionAssert.ThrowsAsync[TException](Func`1 action, String[] possibleMessages) line 57
TaskExtensions.TimeoutAfter[T](Task`1 task, TimeSpan timeout, String filePath, Int32 lineNumber) line 65
StreamingTests.ClientStream_HttpClientWithTimeout_Success() line 405
GenericAdapter`1.BlockUntilCompleted()
NoMessagePumpStrategy.WaitForCompletion(AwaitAdapter awaiter)
AsyncToSyncAdapter.Await(Func`1 invoke)
TestMethodCommand.RunTestMethod(TestExecutionContext context)
TestMethodCommand.Execute(TestExecutionContext context)
<>c__DisplayClass1_0.<Execute>b__0()
BeforeAndAfterTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action)
--NullReferenceException
Http3RequestStream.BufferFrameEnvelope(Http3FrameType frameType, Int64 payloadLength)
Http3RequestStream.WriteRequestContentAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
StreamExtensions.WriteMessageAsync[TMessage](Stream stream, GrpcCall call, TMessage message, Action`2 serializer, CallOptions callOptions) line 303
HttpContentClientStreamWriter`2.WriteAsyncCore[TState](Func`5 writeFunc, TState state) line 159
ExceptionAssert.ThrowsAsync[TException](Func`1 action, String[] possibleMessages) line 37
--TearDown
VerifyNoErrorsScope.Dispose() line 82
GrpcTestContext.Dispose() line 106
FunctionalTestBase.TearDown() line 103

  Standard Output: 
0.003s GrpcTestContext - Information: Starting StreamingTests.ClientStream_HttpClientWithTimeout_Success
0.016s SERVER Grpc.AspNetCore.Server.Model.Internal.ServiceRouteBuilder - Trace: Discovering gRPC methods for FunctionalTestsWebsite.Infrastructure.DynamicService.
0.017s SERVER Grpc.AspNetCore.Server.Model.Internal.BinderServiceMethodProvider - Debug: Could not find bind method for FunctionalTestsWebsite.Infrastructure.DynamicService.
0.018s SERVER Grpc.AspNetCore.Server.Model.Internal.ServiceRouteBuilder - Trace: Added gRPC method 'ClientStreamedDataTimeout' to service 'DynamicService'. Method type: 'ClientStreaming', route pattern: '/DynamicService/ClientStreamedDataTimeout'.
0.020s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : SocketsHttpHandler#61916781,.ctor, ->
0.021s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : Http3DelegatingHandler#65167824,.ctor, ->
0.021s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : Http3DelegatingHandler#65167824,InnerHandler,Http3DelegatingHandler#65167824,SocketsHttpHandler#61916781 ->
0.021s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpClient#8050164,.ctor,HttpClient#8050164,Http3DelegatingHandler#65167824 ->
0.021s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - UriBaseAddress : https://127.0.0.1:50019/,HttpClient#8050164,8050164 ->
0.036s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : PushStreamContent`2#31364791,.ctor, ->
0.043s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Associate : HttpRequestMessage#55334867,Content,HttpRequestMessage#55334867,PushStreamContent`2#31364791 ->
0.053s Grpc.Net.Client.Internal.GrpcCall - Debug: Starting gRPC call. Method type: 'ClientStreaming', URI: 'https://127.0.0.1:50019/DynamicService/ClientStreamedDataTimeout'.
0.057s SystemNetEventSourceListener - Debug: <- Event System.Net.Http - RequestStart : https,127.0.0.1,50019,/DynamicService/ClientStreamedDataTimeout,2,0,1 ->
0.085s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#39996610,.ctor,AutoConfigUrl=(null), AutoDetect=True, Proxy=(null), ProxyBypass=(null) ->
0.085s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#39996610,.ctor,_useProxy=True ->
0.085s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#39996610,TryCreate,AutoSettingsUsed, calling WinHttpOpen ->
0.089s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : HttpConnectionHandler#49642866,.ctor, ->
0.089s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : DiagnosticsHandler#5560867,.ctor, ->
0.089s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : RedirectHandler#25912085,.ctor, ->
0.094s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : WinInetProxyHelper#39996610,GetProxyForUrl,error=12180 ->
0.094s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - Info : WinInetProxyHelper#39996610,GetProxyForUrl,useProxy=False ->
0.096s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 20936295,0,0,.ctor,HttpConnectionPool https://127.0.0.1:50019 ->
0.099s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 20936295,0,0,GetHttp3ConnectionAsync,Attempting new HTTP3 connection. ->
0.101s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,.ctor,[conn][0x24FD5062A40] Outbound connection created ->
0.104s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#25960677,.ctor,[conn][0x24FD50C9020] Inbound connection created ->
0.106s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#25960677,NativeCallbackHandler,[conn][0x24FD50C9020] Connection received event IDEAL_PROCESSOR_CHANGED ->
0.112s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,NativeCallbackHandler,[conn][0x24FD5062A40] Connection received event STREAMS_AVAILABLE ->
0.112s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,NativeCallbackHandler,[conn][0x24FD5062A40] Connection received event DATAGRAM_STATE_CHANGED ->
0.113s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,NativeCallbackHandler,[conn][0x24FD5062A40] Connection received event PEER_CERTIFICATE_RECEIVED ->
0.116s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : SafeX509ChainHandle#57600139,Verify,CertVerifyCertificateChainPolicy returned: True. Status: 2148204815 ->
0.116s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,NativeCallbackHandler,[conn][0x24FD5062A40] Connection received event CONNECTED ->
0.116s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#25960677,NativeCallbackHandler,[conn][0x24FD50C9020] Connection received event CONNECTED ->
0.119s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#46251828,HandleEvent,(null) Stream received event START_COMPLETE ->
0.119s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#46251828,.ctor,[strm][0x24FD5069A70] Outbound unidirectional stream created in connection [conn][0x24FD5062A40]. ->
0.119s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#46251828,HandleEvent,[strm][0x24FD5069A70] Stream received event SEND_COMPLETE ->
0.120s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#25960677,NativeCallbackHandler,[conn][0x24FD50C9020] Connection received event PEER_STREAM_STARTED ->
0.120s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#63449985,.ctor,[strm][0x24FD5066A60] Inbound unidirectional stream created in connection [conn][0x24FD50C9020]. ->
0.120s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#63449985,HandleEvent,[strm][0x24FD5066A60] Stream received event RECEIVE ->
0.123s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Connection id "0HMB1RT37U4HF" accepted.
0.125s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - HandlerMessage : 20936295,0,0,GetHttp3ConnectionAsync,New HTTP3 connection established. ->
0.125s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEvent,(null) Stream received event START_COMPLETE ->
0.125s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,.ctor,[strm][0x24FD5068AC0] Outbound bidirectional stream created in connection [conn][0x24FD5062A40]. ->
0.127s SERVER Microsoft.AspNetCore.Server.Kestrel.Connections - Debug: Connection id "0HMB1RT37U4HF" accepted.
0.127s SERVER Microsoft.AspNetCore.Server.Kestrel.Connections - Debug: Connection id "0HMB1RT37U4HF" started.
0.130s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEvent,[strm][0x24FD5068AC0] Stream received event SEND_COMPLETE ->
0.130s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#25960677,NativeCallbackHandler,[conn][0x24FD50C9020] Connection received event PEER_STREAM_STARTED ->
0.131s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,.ctor,[strm][0x24FD5068EA0] Inbound bidirectional stream created in connection [conn][0x24FD50C9020]. ->
0.131s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,HandleEvent,[strm][0x24FD5068EA0] Stream received event RECEIVE ->
0.133s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,ReadAsync,[strm][0x24FD5068AC0] Stream reading into Memory of '64' bytes. ->
0.133s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#456780,HandleEvent,(null) Stream received event START_COMPLETE ->
0.133s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#456780,.ctor,[strm][0x24FD50692B0] Outbound unidirectional stream created in connection [conn][0x24FD50C9020]. ->
0.135s Grpc.Net.Client.Internal.GrpcCall - Debug: Sending message.
0.141s Grpc.Net.Client.Internal.GrpcCall - Trace: Serialized 'Streaming.DataMessage' to 1027 byte message.
0.143s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000003" type Unidirectional connected.
0.145s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEvent,[strm][0x24FD5068AC0] Stream received event SEND_COMPLETE ->
0.146s Grpc.Net.Client.Internal.GrpcCall - Trace: Message sent.
0.149s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#456780,HandleEvent,[strm][0x24FD50692B0] Stream received event SEND_COMPLETE ->
0.150s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#11218383,NativeCallbackHandler,[conn][0x24FD5062A40] Connection received event PEER_STREAM_STARTED ->
0.150s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,.ctor,[strm][0x24FD51758E0] Inbound unidirectional stream created in connection [conn][0x24FD5062A40]. ->
0.150s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,HandleEvent,[strm][0x24FD51758E0] Stream received event RECEIVE ->
0.151s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,ReadAsync,[strm][0x24FD51758E0] Stream reading into Memory of '32' bytes. ->
0.152s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,ReadAsync,[strm][0x24FD51758E0] Stream reading into Memory of '32' bytes. ->
0.152s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#456780,HandleEvent,[strm][0x24FD50692B0] Stream received event SEND_COMPLETE ->
0.153s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,HandleEvent,[strm][0x24FD51758E0] Stream received event RECEIVE ->
0.154s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#39584784,ReadAsync,[strm][0x24FD51758E0] Stream reading into Memory of '32' bytes. ->
0.155s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync start
0.155s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#63449985,ReadAsync,[strm][0x24FD5066A60] Stream reading into Memory of '4096' bytes. ->
0.155s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync end. Bytes received: 8
0.156s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync start
0.156s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#63449985,ReadAsync,[strm][0x24FD5066A60] Stream reading into Memory of '4096' bytes. ->
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000002" type Unidirectional accepted.
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync start
0.157s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,ReadAsync,[strm][0x24FD5068EA0] Stream reading into Memory of '4096' bytes. ->
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync end. Bytes received: 252
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync start
0.157s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,ReadAsync,[strm][0x24FD5068EA0] Stream reading into Memory of '4096' bytes. ->
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000000" type Bidirectional accepted.
0.157s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,HandleEvent,[strm][0x24FD5068EA0] Stream received event RECEIVE ->
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync end. Bytes received: 1035
0.157s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: QuicStreamContext.ReadAsync start
0.157s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,ReadAsync,[strm][0x24FD5068EA0] Stream reading into Memory of '4096' bytes. ->
0.161s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMB1RT37U4HF" received SETTINGS frame for stream ID 2 with length 5.
0.163s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMB1RT37U4HF" received HEADERS frame for stream ID 0 with length 249.
0.176s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Trace: Connection id "0HMB1RT37U4HF" received DATA frame for stream ID 0 with length 1032.
0.180s SERVER Microsoft.AspNetCore.Hosting.Diagnostics - Information: Request starting HTTP/3 POST https://127.0.0.1:50019/DynamicService/ClientStreamedDataTimeout application/grpc -
0.207s SERVER Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware - Debug: Request matched endpoint 'gRPC - /DynamicService/ClientStreamedDataTimeout'
0.210s SERVER Microsoft.AspNetCore.Routing.EndpointMiddleware - Information: Executing endpoint 'gRPC - /DynamicService/ClientStreamedDataTimeout'
0.226s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Reading message.
0.227s SERVER Microsoft.AspNetCore.Server.Kestrel - Debug: Connection id "0HMB1RT37U4HF", Request id "0HMB1RT37U4HF:00000000": started reading request body.
0.229s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Deserializing 1027 byte message to 'Streaming.DataMessage'.
0.233s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Trace: Received message.
0.234s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Debug: Reading message.
0.394s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,HandleEvent,[strm][0x24FD5068EA0] Stream received event PEER_SEND_ABORTED ->
0.394s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,Dispose,[strm][0x24FD5068AC0] Stream disposing True ->
0.394s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,Dispose,[strm][0x24FD5068AC0] Stream disposed ->
0.394s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#47741942,HandleEvent,[strm][0x24FD5068EA0] Stream received event PEER_RECEIVE_ABORTED ->
0.395s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEvent,[strm][0x24FD5068AC0] Stream received event SEND_SHUTDOWN_COMPLETE ->
0.395s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEvent,[strm][0x24FD5068AC0] Stream received event SHUTDOWN_COMPLETE ->
0.395s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,HandleEventShutdownComplete,[strm][0x24FD5068AC0] Stream completing resettable event source. ->
0.395s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Quic - Info : State#40923024,Cleanup,[strm][0x24FD5068AC0] releasing handles. ->
0.396s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000000" aborted by peer with error code 268.
System.Net.Quic.QuicStreamAbortedException: Stream aborted by peer (268).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventPeerSendAborted(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent)
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Quic.Internal.QuicStreamContext.DoReceive()
0.397s SystemNetEventSourceListener - Debug: <- Event System.Net.Http - RequestFailed :  ->
0.398s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Information: Input complete. Reason: Microsoft.AspNetCore.Connections.ConnectionResetException: Stream aborted by peer (268).
 ---> System.Net.Quic.QuicStreamAbortedException: Stream aborted by peer (268).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventPeerSendAborted(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent)
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Quic.Internal.QuicStreamContext.DoReceive()
   --- End of inner exception stack trace ---
0.399s SERVER Microsoft.AspNetCore.Server.Kestrel.Http3 - Debug: Trace id "0HMB1RT37U4HF:00000000": HTTP/3 stream error "H3_REQUEST_CANCELLED". An abort is being sent to the stream.
Microsoft.AspNetCore.Connections.ConnectionAbortedException: Stream aborted by peer (268).
 ---> Microsoft.AspNetCore.Connections.ConnectionResetException: Stream aborted by peer (268).
 ---> System.Net.Quic.QuicStreamAbortedException: Stream aborted by peer (268).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventPeerSendAborted(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent)
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Quic.Internal.QuicStreamContext.DoReceive()
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3Stream.ProcessRequestAsync[TContext](IHttpApplication`1 application)
   --- End of inner exception stack trace ---
0.402s SystemNetEventSourceListener - Debug: <- Event Private.InternalDiagnostics.System.Net.Http - ErrorMessage : HttpClient#8050164,HandleFailure,System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 0.3 seconds elapsing.
 ---> System.TimeoutException: The operation was canceled.
 ---> System.OperationCanceledException: The operation was canceled.
 ---> System.OperationCanceledException: The operation was canceled.
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.<>c.<ReadAsync>b__35_0(Object obj, CancellationToken token)
   at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source)
   at System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback()
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.NotifyCancellation(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.LinkedNCancellationTokenSource.<>c.<.cctor>b__4_0(Object s)
   at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source)
   at System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback()
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.NotifyCancellation(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.TimerCallback(Object state)
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
   at System.Threading.TimerQueue.FireNextTimers()
   at System.Threading.TimerQueue.AppDomainTimerCallback(Int32 id)
   at System.Threading.UnmanagedThreadPoolWorkItem.System.Threading.IThreadPoolWorkItem.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
   at System.Threading.Thread.StartCallback()
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at System.Net.Http.Http3RequestStream.ReadFrameEnvelopeAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.ReadResponseAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.TrySendUsingHttp3Async(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.DetermineVersionAndSendAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendAndProcessAltSvcAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   --- End of inner exception stack trace ---
   --- End of inner exception stack trace --- ->
0.402s SystemNetEventSourceListener - Debug: <- Event System.Net.Http - RequestStop :  ->
0.402s Grpc.Net.Client.Internal.GrpcCall - Error: Error starting gRPC call.
System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 0.3 seconds elapsing.
 ---> System.TimeoutException: The operation was canceled.
 ---> System.OperationCanceledException: The operation was canceled.
 ---> System.OperationCanceledException: The operation was canceled.
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.<>c.<ReadAsync>b__35_0(Object obj, CancellationToken token)
   at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source)
   at System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback()
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.NotifyCancellation(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.LinkedNCancellationTokenSource.<>c.<.cctor>b__4_0(Object s)
   at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source)
   at System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback()
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.NotifyCancellation(Boolean throwOnFirstException)
   at System.Threading.CancellationTokenSource.TimerCallback(Object state)
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
   at System.Threading.TimerQueue.FireNextTimers()
   at System.Threading.TimerQueue.AppDomainTimerCallback(Int32 id)
   at System.Threading.UnmanagedThreadPoolWorkItem.System.Threading.IThreadPoolWorkItem.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
   at System.Threading.Thread.StartCallback()
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at System.Net.Http.Http3RequestStream.ReadFrameEnvelopeAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.ReadResponseAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3RequestStream.SendAsync(CancellationToken cancellationToken)
   at System.Net.Http.Http3Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.TrySendUsingHttp3Async(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.DetermineVersionAndSendAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendAndProcessAltSvcAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   --- End of inner exception stack trace ---
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancellationToken, CancellationTokenSource pendingRequestsCts)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\GrpcCall.cs:line 441
0.403s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000000" aborted by application with error code 268 because: "Stream aborted by peer (268).".
0.410s SERVER Microsoft.AspNetCore.Server.Kestrel.Transport.Quic - Debug: Stream id "0HMB1RT37U4HF:00000000" shutting down writes because: "Stream aborted by peer (268).".
0.412s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Information: Error reading message.
System.Threading.Tasks.TaskCanceledException: The request was aborted
 ---> Microsoft.AspNetCore.Connections.ConnectionAbortedException: Stream aborted by peer (268).
 ---> Microsoft.AspNetCore.Connections.ConnectionResetException: Stream aborted by peer (268).
 ---> System.Net.Quic.QuicStreamAbortedException: Stream aborted by peer (268).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventPeerSendAborted(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent)
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Quic.Internal.QuicStreamContext.DoReceive()
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3Stream.ProcessRequestAsync[TContext](IHttpApplication`1 application)
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3MessageBody.ReadAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3MessageBody.ReadAsync(CancellationToken cancellationToken)
   at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadStreamMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer, CancellationToken cancellationToken) in C:\Development\Source\grpc-dotnet\src\Grpc.AspNetCore.Server\Internal\PipeExtensions.cs:line 268
0.413s Grpc.Net.Client.Internal.GrpcCall - Debug: Sending message.
0.414s Grpc.Net.Client.Internal.GrpcCall - Trace: Serialized 'Streaming.DataMessage' to 1027 byte message.
0.414s Grpc.Net.Client.Internal.GrpcCall - Information: Call failed with gRPC error status. Status code: 'Cancelled', Message: ''.
0.414s Grpc.Net.Client.Internal.GrpcCall - Error: Error sending message.
System.NullReferenceException: Object reference not set to an instance of an object.
   at System.Net.Http.Http3RequestStream.BufferFrameEnvelope(Http3FrameType frameType, Int64 payloadLength)
   at System.Net.Http.Http3RequestStream.WriteRequestContentAsync(ReadOnlyMemory`1 buffer, CancellationToken cancellationToken)
   at Grpc.Net.Client.StreamExtensions.WriteMessageAsync[TMessage](Stream stream, GrpcCall call, TMessage message, Action`2 serializer, CallOptions callOptions) in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Client\Internal\StreamExtensions.cs:line 303
0.414s Grpc.Net.Client.Internal.GrpcCall - Debug: Finished gRPC call.
0.416s Grpc.Net.Client.Internal.GrpcCall - Debug: gRPC call canceled.
0.416s SERVER Grpc.AspNetCore.Server.ServerCallHandler - Error: Error when executing service method 'ClientStreamedDataTimeout'.
System.Threading.Tasks.TaskCanceledException: The request was aborted
 ---> Microsoft.AspNetCore.Connections.ConnectionAbortedException: Stream aborted by peer (268).
 ---> Microsoft.AspNetCore.Connections.ConnectionResetException: Stream aborted by peer (268).
 ---> System.Net.Quic.QuicStreamAbortedException: Stream aborted by peer (268).
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEventPeerSendAborted(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.HandleEvent(State state, StreamEvent& evt)
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.NativeCallbackHandler(IntPtr stream, IntPtr context, StreamEvent& streamEvent)
--- End of stack trace from previous location ---
   at System.Net.Quic.Implementations.MsQuic.Internal.ResettableCompletionSource`1.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Transport.Quic.Internal.QuicStreamContext.DoReceive()
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3Stream.ProcessRequestAsync[TContext](IHttpApplication`1 application)
   --- End of inner exception stack trace ---
   at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
   at System.IO.Pipelines.Pipe.GetReadAsyncResult()
   at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3MessageBody.ReadAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http3.Http3MessageBody.ReadAsync(CancellationToken cancellationToken)
   at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadStreamMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer, CancellationToken cancellationToken) in C:\Development\Source\grpc-dotnet\src\Grpc.AspNetCore.Server\Internal\PipeExtensions.cs:line 268
   at Grpc.AspNetCore.Server.Internal.HttpContextStreamReader`1.<MoveNext>g__MoveNextAsync|9_0(ValueTask`1 readStreamTask) in C:\Development\Source\grpc-dotnet\src\Grpc.AspNetCore.Server\Internal\HttpContextStreamReader.cs:line 51
   at Grpc.Core.AsyncStreamReaderExtensions.ReadAllAsyncCore[T](IAsyncStreamReader`1 streamReader, CancellationToken cancellationToken)+MoveNext() in C:\Development\Source\grpc-dotnet\src\Grpc.Net.Common\AsyncStreamReaderExtensions.cs:line 51
   at Grpc.Core.AsyncStreamReaderExtensions.ReadAllAsyncCore[T](IAsyncStreamReader`1 streamReader, CancellationToken cancellationToken)+System.Threading.Tasks.Sources.IValueTaskSource<System.Boolean>.GetResult()
   at Grpc.AspNetCore.FunctionalTests.Client.StreamingTests.<>c__DisplayClass11_0.<<ClientStream_HttpClientWithTimeout_Success>g__ClientStreamedData|1>d.MoveNext() in C:\Development\Source\grpc-dotnet\test\FunctionalTests\Client\StreamingTests.cs:line 361
--- End of stack trace from previous location ---
   at Grpc.AspNetCore.FunctionalTests.Client.StreamingTests.<>c__DisplayClass11_0.<<ClientStream_HttpClientWithTimeout_Success>g__ClientStreamedData|1>d.MoveNext() in C:\Development\Source\grpc-dotnet\test\FunctionalTests\Client\StreamingTests.cs:line 361
--- End of stack trace from previous location ---
   at Grpc.Shared.Server.ClientStreamingServerMethodInvoker`3.Invoke(HttpContext httpContext, ServerCallContext serverCallContext, IAsyncStreamReader`1 requestStream) in C:\Development\Source\grpc-dotnet\src\Shared\Server\ClientStreamingServerMethodInvoker.cs:line 100
   at Grpc.Shared.Server.ClientStreamingServerMethodInvoker`3.Invoke(HttpContext httpContext, ServerCallContext serverCallContext, IAsyncStreamReader`1 requestStream) in C:\Development\Source\grpc-dotnet\src\Shared\Server\ClientStreamingServerMethodInvoker.cs:line 111
   at Grpc.AspNetCore.Server.Internal.CallHandlers.ClientStreamingServerCallHandler`3.HandleCallAsyncCore(HttpContext httpContext, HttpContextServerCallContext serverCallContext) in C:\Development\Source\grpc-dotnet\src\Grpc.AspNetCore.Server\Internal\CallHandlers\ClientStreamingServerCallHandler.cs:line 52
   at Grpc.AspNetCore.Server.Internal.CallHandlers.ServerCallHandlerBase`3.<HandleCallAsync>g__AwaitHandleCall|8_0(HttpContextServerCallContext serverCallContext, Method`2 method, Task handleCall) in C:\Development\Source\grpc-dotnet\src\Grpc.AspNetCore.Server\Internal\CallHandlers\ServerCallHandlerBase.cs:line 95
0.421s GrpcTestContext - Information: Finishing StreamingTests.ClientStream_HttpClientWithTimeout_Success

SDK:

.NET SDK (reflecting any global.json):
 Version:   6.0.100-rc.1.21417.11
 Commit:    ca60baef37

Metadata

Metadata

Assignees

Labels

area-System.Net.Httpbug

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions