[HTTP/3] ReservedFrameType_Throws test fails #53090

ManickaP · 2021-05-21T15:50:45Z

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws

Intermittently fails with:

Assert.Throws() Failure\nExpected: typeof(System.Net.Quic.QuicConnectionAbortedException)\nActual:   typeof(System.Exception): unable to read request headers; unexpected end of stream.\n---- System.Exception : unable to read request headers; unexpected end of stream.
   at System.Net.Test.Common.Http3LoopbackStream.ReadRequestDataAsync(Boolean readBody) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 179
   at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 48
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass5_1.<<ReservedFrameType_Throws>b__2>d.MoveNext() in /home/manicka/Repositories/runtime.2/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 136
--- End of stack trace from previous location ---
----- Inner Stack Trace -----
   at System.Net.Test.Common.Http3LoopbackStream.ReadRequestDataAsync(Boolean readBody) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 179
   at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 48
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass5_1.<<ReservedFrameType_Throws>b__2>d.MoveNext() in /home/manicka/Repositories/runtime.2/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 136
--- End of stack trace from previous location ---

The text was updated successfully, but these errors were encountered:

ghost · 2021-05-21T15:50:48Z

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

Issue Details

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws

Intermittently fails with:

Assert.Throws() Failure\nExpected: typeof(System.Net.Quic.QuicConnectionAbortedException)\nActual:   typeof(System.Exception): unable to read request headers; unexpected end of stream.\n---- System.Exception : unable to read request headers; unexpected end of stream.
   at System.Net.Test.Common.Http3LoopbackStream.ReadRequestDataAsync(Boolean readBody) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 179
   at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 48
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass5_1.<<ReservedFrameType_Throws>b__2>d.MoveNext() in /home/manicka/Repositories/runtime.2/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 136
--- End of stack trace from previous location ---
----- Inner Stack Trace -----
   at System.Net.Test.Common.Http3LoopbackStream.ReadRequestDataAsync(Boolean readBody) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 179
   at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content) in /home/manicka/Repositories/runtime.2/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 48
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass5_1.<<ReservedFrameType_Throws>b__2>d.MoveNext() in /home/manicka/Repositories/runtime.2/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 136
--- End of stack trace from previous location ---

Author:	ManickaP
Assignees:	-
Labels:	`area-System.Net.Http`, `disabled-test`
Milestone:	6.0.0

CarnaViire · 2021-08-27T17:19:01Z

The error is now different (either OperationCanceledException or INVALID_STATE) -- described in #58078
Need to revisit after #58078 is fixed.

wfurt · 2021-08-27T19:42:28Z

BTW I was under impression that the INVALID_STATE should not happen any more with current msquic and we should get different error code when the connection is closed remotely. Do you still see it?

CarnaViire · 2021-08-30T17:47:04Z

I've seen that on 8/24 on that day's runtime main. I will re-check later

     System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws [FAIL]
      Assert.Throws() Failure
      Expected: typeof(System.Net.Quic.QuicConnectionAbortedException)
      Actual:   typeof(System.Net.Quic.QuicException): Could not send data to peer. Error Code: INVALID_STATE
      ---- System.Net.Quic.QuicException : Could not send data to peer. Error Code: INVALID_STATE
      Stack Trace:
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\Internal\QuicExceptionHelpers.cs(14,0): at System.Net.Quic.Implementations.MsQuic.Internal.QuicExceptionHelpers.ThrowIfFailed(UInt32 status, String message, Exception innerException)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\MsQuicStream.cs(1209,0): at System.Net.Quic.Implementations.MsQuic.MsQuicStream.SendReadOnlyMemoryAsync(ReadOnlyMemory`1 buffer, QUIC_SEND_FLAGS flags)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\MsQuicStream.cs(296,0): at System.Net.Quic.Implementations.MsQuic.MsQuicStream.WriteAsync(ReadOnlyMemory`1 buffer, Boolean endStream, CancellationToken cancellationToken)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(162,0): at System.Net.Test.Common.Http3LoopbackStream.SendFrameHeaderAsync(Int64 frameType, Int32 payloadLength)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(167,0): at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(123,0): at System.Net.Test.Common.Http3LoopbackStream.SendHeadersFrameAsync(HttpStatusCode statusCode, IEnumerable`1 headers, Boolean qpackEncodeStatus)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(264,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseHeadersAsync(HttpStatusCode statusCode, IEnumerable`1 headers)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(247,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseAsync(HttpStatusCode statusCode, IList`1 headers, String content, Boolean isFinal)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(53,0): at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Http\tests\FunctionalTests\HttpClientHandlerTest.Http3.cs(299,0): at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass7_1.<<ReservedFrameType_Throws>b__2>d.MoveNext()
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace -----
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\Internal\QuicExceptionHelpers.cs(14,0): at System.Net.Quic.Implementations.MsQuic.Internal.QuicExceptionHelpers.ThrowIfFailed(UInt32 status, String message, Exception innerException)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\MsQuicStream.cs(1209,0): at System.Net.Quic.Implementations.MsQuic.MsQuicStream.SendReadOnlyMemoryAsync(ReadOnlyMemory`1 buffer, QUIC_SEND_FLAGS flags)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Quic\src\System\Net\Quic\Implementations\MsQuic\MsQuicStream.cs(296,0): at System.Net.Quic.Implementations.MsQuic.MsQuicStream.WriteAsync(ReadOnlyMemory`1 buffer, Boolean endStream, CancellationToken cancellationToken)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(162,0): at System.Net.Test.Common.Http3LoopbackStream.SendFrameHeaderAsync(Int64 frameType, Int32 payloadLength)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(167,0): at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(123,0): at System.Net.Test.Common.Http3LoopbackStream.SendHeadersFrameAsync(HttpStatusCode statusCode, IEnumerable`1 headers, Boolean qpackEncodeStatus)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(264,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseHeadersAsync(HttpStatusCode statusCode, IEnumerable`1 headers)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(247,0): at System.Net.Test.Common.Http3LoopbackStream.SendResponseAsync(HttpStatusCode statusCode, IList`1 headers, String content, Boolean isFinal)
        C:\Users\knatalia\dev\git\runtime\src\libraries\Common\tests\System\Net\Http\Http3LoopbackStream.cs(53,0): at System.Net.Test.Common.Http3LoopbackStream.HandleRequestAsync(HttpStatusCode statusCode, IList`1 headers, String content)
        C:\Users\knatalia\dev\git\runtime\src\libraries\System.Net.Http\tests\FunctionalTests\HttpClientHandlerTest.Http3.cs(299,0): at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass7_1.<<ReservedFrameType_Throws>b__2>d.MoveNext()
        --- End of stack trace from previous location ---

wfurt · 2021-08-30T18:10:12Z

OK. I was expecting we would no longer see this after #57541 as that should bring microsoft/msquic#1875
cc: @ThadHouse @nibanks

ThadHouse · 2021-08-30T18:15:41Z

You can still get invalid state if you have closed the connection locally. Are you sure that hasn't happened?

wfurt · 2021-08-30T18:33:35Z

I would expect not but @CarnaViire to confirm. WriteAsync should not try to call msquic if locally closed.

CarnaViire · 2022-02-08T15:25:45Z

I was looking at microsoft/msquic#1875 and it seems to fix that only for StreamStart and StreamOpen, but not for StreamSend. Is it possible INVALID_STATE is still used for StreamSend? @nibanks @thhous-msft

CarnaViire · 2022-02-16T17:46:19Z

I confirm that I can still get INVALID_STATE because of the race between calling StreamSend and receiving SHUTDOWN_INITIATED_BY_PEER.

The test is to call StreamSend indefinitely while peer is calling ConnectionClose after a couple of reads.

Most of the time I would get SEND_COMPLETE with Canceled=true. We have another issue to correctly handle it QUIC: Peer closing connection can result in OperationCanceledException on pending write #58078
Sometimes I would luck out and receive stream's SHUTDOWN_COMPLETE with ConnectionShutdown=true.
And sometimes StreamSend itself will fail with INVALID_STATE.
Extract from msquic logs below (I have full logs if needed)

115964 [1]42FC.3134::2022/02/16-17:34:34.879798900 [Microsoft-Quic][ api] Enter 14(CONNECTION_SHUTDOWN) (0x23C2D306D20).
115966 [1]42FC.3134::2022/02/16-17:34:34.879800500 [Microsoft-Quic][ api] Exit
116007 [7]42FC.2B50::2022/02/16-17:34:34.879836900 [Microsoft-Quic][conn][0x23C2D306D20] App Shutdown: 123 (Remote=0)

116010 [7]42FC.2B50::2022/02/16-17:34:34.879839400 [Microsoft-Quic][strm][0x23C2CF088F0] Indicating QUIC_STREAM_EVENT_SEND_SHUTDOWN_COMPLETE
116014 [7]42FC.2B50::2022/02/16-17:34:34.879844400 [Microsoft-Quic][strm][0x23C2CF088F0] Send State: 3(RESET_ACKED)
116015 [7]42FC.2B50::2022/02/16-17:34:34.879845500 [Microsoft-Quic][strm][0x23C2CF088F0] Recv State: 3(STOPPED)
116018 [7]42FC.2B50::2022/02/16-17:34:34.879848000 [Microsoft-Quic][strm][0x23C2CF088F0] Indicating QUIC_STREAM_EVENT_SHUTDOWN_COMPLETE [ConnectionShutdown=1]

116021 [1]42FC.3134::2022/02/16-17:34:34.879850800 [Microsoft-Quic][ api] Enter 22(STREAM_SEND) (0x23C2CF07AE0).
116023 [1]42FC.3134::2022/02/16-17:34:34.879852300 [Microsoft-Quic][ api] Exit 459749
116084 [4]42FC.C1C0::2022/02/16-17:34:34.879964300 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SEND_COMPLETE [0000023C2B64C330]

116237 [4]42FC.3134::2022/02/16-17:34:34.880321100 [Microsoft-Quic][ api] Enter 22(STREAM_SEND) (0x23C2CF07AE0).
116239 [4]42FC.3134::2022/02/16-17:34:34.880325800 [Microsoft-Quic][ api] Exit 459749

116251 [7]42FC.2B50::2022/02/16-17:34:34.880385600 [Microsoft-Quic][strm][0x23C2CF088F0] Ignoring recv flush (recv disabled)

116256 [1]42FC.C1C0::2022/02/16-17:34:34.880389400 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SEND_COMPLETE [0000023C2B64C8D0]

116310 [4]42FC.25A8::2022/02/16-17:34:34.880446300 [Microsoft-Quic][ api] Enter 22(STREAM_SEND) (0x23C2CF07AE0).
116314 [4]42FC.25A8::2022/02/16-17:34:34.880451300 [Microsoft-Quic][ api] Exit 459749
116335 [1]42FC.C1C0::2022/02/16-17:34:34.880479400 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SEND_COMPLETE [0000023C2B64C510]

116340 [4]42FC.25A8::2022/02/16-17:34:34.880484600 [Microsoft-Quic][ api] Enter 22(STREAM_SEND) (0x23C2CF07AE0).
116342 [4]42FC.25A8::2022/02/16-17:34:34.880485800 [Microsoft-Quic][ api] Exit 459749
116392 [1]42FC.C1C0::2022/02/16-17:34:34.880541200 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SEND_COMPLETE [0000023C2B64CC90]

116430 [1]42FC.C1C0::2022/02/16-17:34:34.880588500 [Microsoft-Quic][conn][0x23C2B64CEE0] Indicating QUIC_CONNECTION_EVENT_SHUTDOWN_INITIATED_BY_PEER [0x7b]

116434 [4]42FC.3134::2022/02/16-17:34:34.880596700 [Microsoft-Quic][ api] Enter 22(STREAM_SEND) (0x23C2CF07AE0).
116435 [4]42FC.3134::2022/02/16-17:34:34.880598300 [Microsoft-Quic][ api] Exit 2147947423        <--- INVALID_STATE

116436 [1]42FC.C1C0::2022/02/16-17:34:34.880598900 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SEND_SHUTDOWN_COMPLETE
116441 [1]42FC.C1C0::2022/02/16-17:34:34.880606400 [Microsoft-Quic][strm][0x23C2CF07AE0] Indicating QUIC_STREAM_EVENT_SHUTDOWN_COMPLETE [ConnectionShutdown=1]

cc @nibanks @thhous-msft

It would be great if we could distinguish INVALID_STATE from connection shutdown vs all other possible invalid states.

Same with Canceled. If the send is canceled because of connection shutdown, we can ignore the event and wait for SHUTDOWN_COMPLETE, but if it's a user cancelation of Send operation, we should throw OperationCanceledException.

thhous-msft · 2022-02-16T17:49:32Z

StreamSend wasn't part of the changes done before, as the bug we got seemed to only apply to Start. I'll look into StreamSend.

nibanks · 2022-02-16T17:55:14Z

@CarnaViire would you mind opening a new MsQuic Issue to track StreamSend and we'll prioritize accordingly. We've still got a number of v2 things that need to get fixed ASAP. This can be fixed in a new minor version later.

CarnaViire · 2022-02-16T18:12:28Z

opening a new MsQuic Issue

Sure! We are currently in the middle of collecting all the potential problems and asks to discuss with you and then convert some or all of them into issues.

CarnaViire · 2022-02-16T21:32:02Z

Judging from the discussion here #55485 (comment) is it correct that if SEND_COMPLETE contains Canceled=true, that could only mean that the stream is being closed (because of connection shutdown or other reasons)? Meaning, can we skip that event and wait for the following STREAM_SHUTDOWN* event? @nibanks @thhous-msft

nibanks · 2022-02-16T23:30:35Z

A canceled send can happen for one of the following reasons:

The peer aborted their receive.
The local app aborted their send.
The connection was shutdown (by either side).

ManickaP added area-System.Net.Http disabled-test The test is disabled in source code against the issue labels May 21, 2021

ManickaP added this to the 6.0.0 milestone May 21, 2021

dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label May 21, 2021

ManickaP removed the untriaged New issue has not been triaged by the area owner label May 21, 2021

ManickaP mentioned this issue May 21, 2021

Disabled failing HTTP/3 tests. #53092

Merged

ManickaP modified the milestones: 6.0.0, Future Aug 10, 2021

CarnaViire self-assigned this Aug 24, 2021

CarnaViire mentioned this issue Aug 25, 2021

QUIC: Peer closing connection can result in OperationCanceledException on pending write #58078

Closed

CarnaViire removed their assignment Aug 27, 2021

nibanks mentioned this issue Feb 16, 2022

Report ABORTED for StreamSend if remotely closed microsoft/msquic#2401

Merged

ManickaP mentioned this issue Mar 31, 2022

[QUIC] Update to msquic 2 #67383

Merged

rzikm self-assigned this Apr 6, 2022

rzikm mentioned this issue Apr 6, 2022

Fix exception thrown from MsQuicStream writes when connection is aborted by peer. #67651

Merged

ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 6, 2022

rzikm closed this as completed in #67651 Apr 8, 2022

ghost removed the in-pr There is an active PR which will close this issue when it is merged label Apr 8, 2022

ghost locked as resolved and limited conversation to collaborators May 8, 2022

karelz modified the milestones: Future, 7.0.0 Jul 19, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[HTTP/3] ReservedFrameType_Throws test fails #53090

[HTTP/3] ReservedFrameType_Throws test fails #53090

ManickaP commented May 21, 2021

ghost commented May 21, 2021

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws

CarnaViire commented Aug 27, 2021

wfurt commented Aug 27, 2021

CarnaViire commented Aug 30, 2021

wfurt commented Aug 30, 2021

ThadHouse commented Aug 30, 2021

wfurt commented Aug 30, 2021

CarnaViire commented Feb 8, 2022

CarnaViire commented Feb 16, 2022

thhous-msft commented Feb 16, 2022

nibanks commented Feb 16, 2022

CarnaViire commented Feb 16, 2022

CarnaViire commented Feb 16, 2022

nibanks commented Feb 16, 2022

[HTTP/3] ReservedFrameType_Throws test fails #53090

[HTTP/3] ReservedFrameType_Throws test fails #53090

Comments

ManickaP commented May 21, 2021

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws

ghost commented May 21, 2021

System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.ReservedFrameType_Throws

CarnaViire commented Aug 27, 2021

wfurt commented Aug 27, 2021

CarnaViire commented Aug 30, 2021

wfurt commented Aug 30, 2021

ThadHouse commented Aug 30, 2021

wfurt commented Aug 30, 2021

CarnaViire commented Feb 8, 2022

CarnaViire commented Feb 16, 2022

thhous-msft commented Feb 16, 2022

nibanks commented Feb 16, 2022

CarnaViire commented Feb 16, 2022

CarnaViire commented Feb 16, 2022

nibanks commented Feb 16, 2022