Fix data race on incoming MsQuicStream abort #69483

rzikm · 2022-05-18T10:52:38Z

This PR fixes a data race which we occasionally hit when running Http.Funcional.Tests in a tight loop.

The data race this PR fixes occurs like this:

MsQuicThread indicates that our write side was aborted by the peer (in HandleEventPeerRecvAborted). And sets _state.SendState = SendState.Aborted
Application thread attempts to send data on the stream and in SetupWriteStartState, we check the _state.SendState == SendState.Aborted. This is done outside the lock to avoid locking when stream is in a terminal state.
Application thread continues and reads _state.SendErrorCode which hasn't been set yet by the MsQuic thread -> we throw QuicOperationAbortedException instead of QuicStreamAbortedException with appropriate error code.

Example test failure due to the race

Failed System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http3_MsQuic.RequestSentResponseDisposed_ThrowsOnServer [43 ms]
  Error Message:
   System.AggregateException : One or more errors occurred. (Sending has already been aborted on the stream) (Sending has already been aborted on the stream)
---- System.Net.Quic.QuicOperationAbortedException : Sending has already been aborted on the stream
---- System.Net.Quic.QuicOperationAbortedException : Sending has already been aborted on the stream
  Stack Trace:
     at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 88
   at System.Threading.Tasks.TaskTimeoutExtensions.WhenAllOrAnyFailed(Task[] tasks, Int32 millisecondsTimeout) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 55
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.RequestSentResponseDisposed_ThrowsOnServer() in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 367
--- End of stack trace from previous location ---
----- Inner Stack Trace #1 (System.Net.Quic.QuicOperationAbortedException) -----
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.SetupWriteStartState(Boolean emptyBuffer, CancellationToken cancellationToken) in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs:line 342
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.WriteAsync(ReadOnlyMemory`1 buffer, Boolean endStream, CancellationToken cancellationToken) in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs:line 307
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameHeaderAsync(Int64 frameType, Int32 payloadLength) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 162
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 167
   at System.Net.Test.Common.Http3LoopbackStream.SendDataFrameAsync(ReadOnlyMemory`1 data) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 140
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseBodyAsync(Byte[] content, Boolean isFinal) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 283
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass8_0.<<RequestSentResponseDisposed_ThrowsOnServer>b__0>d.MoveNext() in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 332
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 120
----- Inner Stack Trace #2 (System.Net.Quic.QuicOperationAbortedException) -----
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.SetupWriteStartState(Boolean emptyBuffer, CancellationToken cancellationToken) in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs:line 342
   at System.Net.Quic.Implementations.MsQuic.MsQuicStream.WriteAsync(ReadOnlyMemory`1 buffer, Boolean endStream, CancellationToken cancellationToken) in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs:line 307
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameHeaderAsync(Int64 frameType, Int32 payloadLength) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 162
   at System.Net.Test.Common.Http3LoopbackStream.SendFrameAsync(Int64 frameType, ReadOnlyMemory`1 framePayload) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 167
   at System.Net.Test.Common.Http3LoopbackStream.SendDataFrameAsync(ReadOnlyMemory`1 data) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 140
   at System.Net.Test.Common.Http3LoopbackStream.SendResponseBodyAsync(Byte[] content, Boolean isFinal) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Net/Http/Http3LoopbackStream.cs:line 283
   at System.Net.Http.Functional.Tests.HttpClientHandlerTest_Http3.<>c__DisplayClass8_0.<<RequestSentResponseDisposed_ThrowsOnServer>b__0>d.MoveNext() in /home/rzikm/dotnet-runtime/src/libraries/System.Net.Http/tests/FunctionalTests/HttpClientHandlerTest.Http3.cs:line 332
--- End of stack trace from previous location ---
   at System.Threading.Tasks.TaskTimeoutExtensions.GetRealException(Task task) in /home/rzikm/dotnet-runtime/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 120

ghost · 2022-05-18T10:52:44Z

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

Issue Details

This PR fixes a data race which we occasionally hit when running Http.Funcional.Tests in a tight loop.

The data race this PR fixes occurs like this:

MsQuicThread indicates that our write side was aborted by the peer (in HandleEventPeerRecvAborted). And sets _state.SendState = SendState.Aborted
Application thread attempts to send data on the stream and in SetupWriteStartState, we check the _state.SendState == SendState.Aborted. This is done outside the lock to avoid locking when stream is in a terminal state.
Application thread continues and reads _state.SendErrorCode which hasn't been set yet by the MsQuic thread -> we throw QuicOperationAbortedException instead of QuicStreamAbortedException with appropriate error code.

Author:	rzikm
Assignees:	-
Labels:	`area-System.Net.Quic`
Milestone:	-

rzikm · 2022-05-18T10:56:24Z

To consider:

is there any perf penalty for using Volatile.Read? cc: @stephentoub
alternatively, we can consider removing the outside-of-the-lock check. That in turn will require us to make sure that the CancellationTokenRegistration is properly disposed if we throw later.

stephentoub · 2022-05-18T11:00:19Z

is there any perf penalty for using Volatile.Read?

On x86/64, the memory model of the hardware is strong enough that no fences are emitted. The only impact is potentially prohibiting certain optimizations the JIT might otherwise do. Generally it's negligible.

On ARM, the hardware has a weaker memory model and the JIT does need to emit a fence in most situations.

ManickaP · 2022-05-18T11:33:52Z

src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs

                state.SendErrorCode = (long)streamEvent.PEER_RECEIVE_ABORTED.ErrorCode;
+                // make sure the SendErrorCode above is commited to memory before we assign the state. This
+                // ensures that the code is read correctly in SetupWriteStartState when checking without lock
+                Volatile.Write(ref Unsafe.As<SendState, int>(ref state.SendState), (int)SendState.Aborted);


I don't think you need the Volatile.Write here since you're inside a lock. AFAIK that should emit memory barriers if necessary. @stephentoub please correct me if I'm wrong.

The comment suggests the concern is the reordering of the write to SendErrorCode and the write to SendState. The volatile is necessary to prevent that reordering. There is a fence as part of releasing the lock, but that only guarantees that neither write will move past the lock exit, not that they won't move past each other.

🤦 yep, I should have read that comment 🤣

src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs

ManickaP

Thanks.

rzikm · 2022-05-18T16:15:00Z

Test failure is #69387

Fix data race on MsQuicStream abort

06757d1

ghost added the area-System.Net.Quic label May 18, 2022

ghost assigned rzikm May 18, 2022

fixup! Fix data race on MsQuicStream abort

246bf7a

rzikm requested review from CarnaViire and ManickaP and removed request for ManickaP May 18, 2022 10:53

rzikm changed the title ~~Fix data race on MsQuicStream abort~~ Fix data race on incoming MsQuicStream abort May 18, 2022

ManickaP reviewed May 18, 2022

View reviewed changes

MihaZupan reviewed May 18, 2022

View reviewed changes

src/libraries/System.Net.Quic/src/System/Net/Quic/Implementations/MsQuic/MsQuicStream.cs Show resolved Hide resolved

ManickaP approved these changes May 18, 2022

View reviewed changes

MihaZupan mentioned this pull request May 18, 2022

MsQuicStream can leak CancellationTokenRegistrations #69491

Closed

rzikm merged commit 43cc4c1 into dotnet:main May 18, 2022

ghost locked as resolved and limited conversation to collaborators Jun 17, 2022

karelz added this to the 7.0.0 milestone Jul 19, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Fix data race on incoming MsQuicStream abort #69483

Fix data race on incoming MsQuicStream abort #69483

Uh oh!

rzikm commented May 18, 2022 •

edited

Loading

Uh oh!

ghost commented May 18, 2022

Uh oh!

rzikm commented May 18, 2022

Uh oh!

stephentoub commented May 18, 2022

Uh oh!

ManickaP May 18, 2022

Uh oh!

stephentoub May 18, 2022

Uh oh!

ManickaP May 18, 2022

Uh oh!

Uh oh!

ManickaP left a comment

Uh oh!

rzikm commented May 18, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Fix data race on incoming MsQuicStream abort #69483

Fix data race on incoming MsQuicStream abort #69483

Uh oh!

Conversation

rzikm commented May 18, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ghost commented May 18, 2022

Uh oh!

rzikm commented May 18, 2022

Uh oh!

stephentoub commented May 18, 2022

Uh oh!

ManickaP May 18, 2022

Choose a reason for hiding this comment

Uh oh!

stephentoub May 18, 2022

Choose a reason for hiding this comment

Uh oh!

ManickaP May 18, 2022

Choose a reason for hiding this comment

Uh oh!

Uh oh!

ManickaP left a comment

Choose a reason for hiding this comment

Uh oh!

rzikm commented May 18, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

rzikm commented May 18, 2022 •

edited

Loading