[HttpStress] massive timeouts around HTTP/3 stress test startup

[antonfirsov]

This happened 3 times in the past 4 weeks, main and release/7.0 are both affected:

• 09/24
• 09/26
• 10/10

Looks like sometimes the stress server is unresponsive for a long time around startup in these cases.

[ghost]

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

Issue Details

---

This happened 3 times in the past 4 weeks, main and release/7.0 are both affected:

• 09/24
• 09/26
• 10/10

Looks like sometimes the stress server is unresponsive for a long time around startup in these cases.

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

[CarnaViire]

I've seen this happening on local runs as well; we suspected it might be related to #55979

[ManickaP]

Triage: we should investigate to confirm if it's #55979. Either way, we should at least put a mitigation in stress to not to fail the test in this case.

[antonfirsov]

Unfortunately, this is still happening. I see 4 occurrences out of 22 runs in the last 30 days. It wasn't this frequent before, is it possible that #84793 made it worse? Or could it be a server-side issue? /cc @ManickaP

• https://dev.azure.com/dnceng-public/public/_build/results?buildId=280888&view=logs&j=22fea640-1099-5f32-ec5d-316ad83f359a&t=a923b061-8445-5c16-cd6e-848990587cb0
• https://dev.azure.com/dnceng-public/public/_build/results?buildId=257086&view=logs&j=22fea640-1099-5f32-ec5d-316ad83f359a&t=a923b061-8445-5c16-cd6e-848990587cb0
• https://dev.azure.com/dnceng-public/public/_build/results?buildId=254739&view=logs&j=22fea640-1099-5f32-ec5d-316ad83f359a&t=a923b061-8445-5c16-cd6e-848990587cb0

System.Net.Http.HttpRequestException: Requesting HTTP version 3.0 with version policy RequestVersionExact while unable to establish HTTP/3 connection.
client_1  |  ---> System.Net.Http.HttpRequestException: The operation was canceled. (server:5001)
client_1  |  ---> System.OperationCanceledException: The operation was canceled.
client_1  |    at System.Net.Quic.ValueTaskSource.TryComplete(Exception exception) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ValueTaskSource.cs:line 119
client_1  |    at System.Net.Quic.ValueTaskSource.TrySetException(Exception exception) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ValueTaskSource.cs:line 166
client_1  |    at System.Net.Quic.ValueTaskSource.<>c.<TryInitialize>b__10_0(Object obj, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Quic/src/System/Net/Quic/Internal/ValueTaskSource.cs:line 70
client_1  |    at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 981
client_1  |    at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 806
client_1  |    at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 977
client_1  |    at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 806
client_1  |    at HttpStress.RequestContext.SendAsync(HttpRequestMessage request, HttpCompletionOption httpCompletion, Nullable`1 token) in /app/ClientOperations.cs:line 89
client_1  |    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncMethodBuilderCore.cs:line 38
client_1  |    at HttpStress.RequestContext.SendAsync(HttpRequestMessage request, HttpCompletionOption httpCompletion, Nullable`1 token)
client_1  |    at HttpStress.ClientOperations.<>c.<<get_Operations>b__1_0>d.MoveNext() in /app/ClientOperations.cs:line 193
client_1  |    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncMethodBuilderCore.cs:line 38
client_1  |    at HttpStress.ClientOperations.<>c.<get_Operations>b__1_0(RequestContext ctx)
client_1  |    at HttpStress.StressClient.<>c__DisplayClass17_0.<<StartCore>g__RunWorker|0>d.MoveNext() in /app/StressClient.cs:line 204
client_1  |    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncMethodBuilderCore.cs:line 38
client_1  |    at HttpStress.StressClient.<>c__DisplayClass17_0.<StartCore>g__RunWorker|0(Int32 taskNum)
client_1  |    at System.Linq.Enumerable.SelectRangeIterator`1.Fill(Span`1 results, Int32 start, Func`2 func) in /_/src/libraries/System.Linq/src/System/Linq/Select.SpeedOpt.cs:line 227
client_1  |    at System.Linq.Enumerable.SelectRangeIterator`1.ToArray() in /_/src/libraries/System.Linq/src/System/Linq/Select.SpeedOpt.cs:line 210
client_1  |    at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source) in /_/src/libraries/System.Linq/src/System/Linq/ToCollection.cs:line 17
client_1  |    at HttpStress.StressClient.StartCore() in /app/StressClient.cs:line 184
client_1  |    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) in /_/src/libraries/System.Private.CoreLib/src/System/Runtime/CompilerServices/AsyncMethodBuilderCore.cs:line 38
client_1  |    at HttpStress.StressClient.StartCore()
client_1  |    at HttpStress.StressClient.Start() in /app/StressClient.cs:line 92
client_1  |    at HttpStress.Program.Run(Configuration config) in /app/Program.cs:line 197

[ManickaP]

Revert of the hack is up in #87926. When it starts manifesting in the original way, we can mitigate that with targeted error handling.

[ManickaP]

Looking at the error in more detail, this is something else. It's not timeout. If you look bellow the exception you can see it's mostly not cancelled and very fast:

Duration: 00:00:00.0010132, Cancelled: False

All three errors are the same, just coming from a different operation and they are the same with or without the hack. This is completely new problem that might have started occurring at similar time as we merged #84793. But right know I'm not convinced this was caused by this.

Also, AFAIR, the original error was the server dropping connections due to overload, i.e. System.Net.Quic.QuicException : Connection has been shutdown by transport. Error Code: CONNECTION_REFUSED. I will re-close this issue and create a new one for the cancellation error we're now seeing.