Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Test failure: System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled #41078

Closed
v-haren opened this issue Aug 20, 2020 · 35 comments · Fixed by #55572 or #89788
Assignees
Labels
area-System.Net.Http disabled-test The test is disabled in source code against the issue test-bug Problem in test source code (most likely) test-run-core Test failures in .NET Core test runs
Milestone

Comments

@v-haren
Copy link

v-haren commented Aug 20, 2020

failed in job: runtime 20200819.105

net5.0-Linux-Release-x64-CoreCLR_release-Ubuntu.1604.Amd64.Open

Error message

System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
---- System.TimeoutException : The operation was canceled.
-------- System.Threading.Tasks.TaskCanceledException : The operation was canceled.


Stack trace
   at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime) in /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 605
   at System.Threading.Tasks.TaskTimeoutExtensions.TimeoutAfter(Task task, TimeSpan timeout) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 43
   at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.PrepareConnection(Http2LoopbackServer server, HttpClient client, UInt32 maxConcurrentStreams, Int32 readTimeout, Int32 expectedWarpUpTasks) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs:line 2280
   at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs:line 2075
--- End of stack trace from previous location ---
----- Inner Stack Trace -----

----- Inner Stack Trace -----
   at System.Net.Http.Http2Connection.Http2Stream.<>c.<WaitForDataAsync>b__67_0(Object s) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 1224
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 694
   at System.Threading.CancellationTokenSource.<>c.<.cctor>b__56_0(Object obj) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 35
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 627
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 589
   at System.Threading.TimerQueue.FireNextTimers() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 274
--- End of stack trace from previous location ---
   at System.Net.Http.Http2Connection.Http2Stream.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 1184
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 857
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1906
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs:line 898
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs:line 30
   at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime) in /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 605
@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added the untriaged New issue has not been triaged by the area owner label Aug 20, 2020
@ghost
Copy link

ghost commented Aug 20, 2020

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

@karelz karelz added this to the 6.0.0 milestone Aug 20, 2020
@karelz karelz added test-bug Problem in test source code (most likely) and removed untriaged New issue has not been triaged by the area owner labels Aug 20, 2020
@jkotas jkotas added the blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' label Aug 23, 2020
@jkotas
Copy link
Member

jkotas commented Aug 23, 2020

Another failure mode of the same test:

 System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled [FAIL]
      Assert.Equal() Failure
      Expected: 6
      Actual:   4
      Stack Trace:
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs(2080,0): at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled()
        --- End of stack trace from previous location ---

Hit in #41234

@safern
Copy link
Member

safern commented Aug 26, 2020

Another failure:

    System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled [FAIL]
      System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
      ---- System.TimeoutException : The operation was canceled.
      -------- System.Threading.Tasks.TaskCanceledException : The operation was canceled.
      Stack Trace:
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(595,0): at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime)
        /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs(37,0): at System.Threading.Tasks.TaskTimeoutExtensions.TimeoutAfter(Task task, TimeSpan timeout)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs(2280,0): at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.PrepareConnection(Http2LoopbackServer server, HttpClient client, UInt32 maxConcurrentStreams, Int32 readTimeout, Int32 expectedWarpUpTasks)
        /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs(2075,0): at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled()
        --- End of stack trace from previous location ---
        ----- Inner Stack Trace -----
        
        ----- Inner Stack Trace -----
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs(1224,0): at System.Net.Http.Http2Connection.Http2Stream.<>c.<WaitForDataAsync>b__67_0(Object s)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs(694,0): at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs(35,0): at System.Threading.CancellationTokenSource.<>c.<.cctor>b__56_0(Object obj)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs(627,0): at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs(589,0): at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
        /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs(274,0): at System.Threading.TimerQueue.FireNextTimers()
        --- End of stack trace from previous location ---
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs(1184,0): at System.Net.Http.Http2Connection.Http2Stream.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs(857,0): at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs(1890,0): at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs(898,0): at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs(30,0): at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
        /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs(565,0): at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime)

#41358
https://dev.azure.com/dnceng/public/_build/results?buildId=788022&view=ms.vss-test-web.build-test-results-tab&runId=24847778&resultId=179707&paneView=debug

@v-haren
Copy link
Author

v-haren commented Aug 28, 2020

failed again in job: runtime 20200827.91

Configurations:
net5.0-Linux-Release-x64-CoreCLR_release-Ubuntu.1604.Amd64.Open

Error message

System.Threading.Tasks.TaskCanceledException : The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
---- System.TimeoutException : The operation was canceled.
-------- System.Threading.Tasks.TaskCanceledException : The operation was canceled.


Stack trace
   at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime) in /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 605
   at System.Threading.Tasks.TaskTimeoutExtensions.TimeoutAfter(Task task, TimeSpan timeout) in /_/src/libraries/Common/tests/System/Threading/Tasks/TaskTimeoutExtensions.cs:line 43
   at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.PrepareConnection(Http2LoopbackServer server, HttpClient client, UInt32 maxConcurrentStreams, Int32 readTimeout, Int32 expectedWarpUpTasks) in /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs:line 2280
   at System.Net.Http.Functional.Tests.SocketsHttpHandlerTest_Http2.Http2_MultipleConnectionsEnabled_ConnectionLimitNotReached_ConcurrentRequestsSuccessfullyHandled() in /_/src/libraries/System.Net.Http/tests/FunctionalTests/SocketsHttpHandlerTest.cs:line 2075
--- End of stack trace from previous location ---
----- Inner Stack Trace -----

----- Inner Stack Trace -----
   at System.Net.Http.Http2Connection.Http2Stream.<>c.<WaitForDataAsync>b__67_0(Object s) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 1224
   at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 694
   at System.Threading.CancellationTokenSource.<>c.<.cctor>b__56_0(Object obj) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/CancellationTokenSource.cs:line 35
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 627
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 589
   at System.Threading.TimerQueue.FireNextTimers() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 274
--- End of stack trace from previous location ---
   at System.Net.Http.Http2Connection.Http2Stream.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 1185
   at System.Net.Http.Http2Connection.Http2Stream.ReadResponseHeadersAsync(CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Stream.cs:line 889
   at System.Net.Http.Http2Connection.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/Http2Connection.cs:line 1906
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/HttpConnectionPool.cs:line 898
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Http/src/System/Net/Http/SocketsHttpHandler/RedirectHandler.cs:line 30
   at System.Net.Http.HttpClient.FinishSendAsync(ValueTask`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts, Boolean buffered, Boolean async, CancellationToken callerToken, Int64 timeoutTime) in /_/src/libraries/System.Net.Http/src/System/Net/Http/HttpClient.cs:line 605

@danmoseley
Copy link
Member

Again in #41908

@dotnet/ncl this seems to be causing fairly regular failures.

@ManickaP
Copy link
Member

ManickaP commented Sep 7, 2020

cc: @alnikola

@danmoseley
Copy link
Member

I just hit this again in another PR. @ManickaP does that linked issue fix this? If not should we make this test outerloop today?

@danmoseley
Copy link
Member

And another PR hit.

@danmoseley
Copy link
Member

And another one #41908

@alnikola
Copy link
Contributor

alnikola commented Sep 8, 2020

I wouldn't make it outerloop because the root cause of the failure is not known yet, thus it can be an indicator of some production code issue. We need to investigate.
@karelz This is one of the failing tests I highlighted today as potentially production code-related.

@danmoseley
Copy link
Member

@alnikola in that case we should disable it: as it is we are already ignoring it, but it is breaking unrelated CI jobs.

@alnikola
Copy link
Contributor

alnikola commented Sep 8, 2020

I tried fixing it in #40844 by improving request handling code on the test server, but it seems there is some other issue.

@jkotas
Copy link
Member

jkotas commented Sep 8, 2020

It still means you should disable it until you figure it out. We do not want to have tests that are frequently failing in CI. It is killing productivity of the team as a whole.

@alnikola
Copy link
Contributor

alnikola commented Nov 25, 2020

Moved to: #45204

@ManickaP
Copy link
Member

Created 2 new issues from this one since there's been yet another different failure reported here. Moving discussion about the offending test to #45204

@safern
Copy link
Member

safern commented Nov 25, 2020

Thanks @ManickaP and @alnikola -- I completely missed that is was another test that was failing.

@karelz karelz added the test-run-core Test failures in .NET Core test runs label Apr 23, 2021
@alnikola alnikola assigned alnikola and unassigned alnikola Jun 24, 2021
@alnikola alnikola self-assigned this Jul 13, 2021
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Jul 13, 2021
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Jul 14, 2021
@alnikola
Copy link
Contributor

The test is still failing.

@karelz
Copy link
Member

karelz commented Jul 22, 2021

The test was disabled again by 8a6fa30 on 7/14 (the same day it was enabled by PR #55572)

Failures on 7/14 while it was enabled:

Summary of known facts from history:

  • Tests a new 5.0 feature - reported failure also on 5.0.x servicing, not a regression

@alnikola
Copy link
Contributor

The test is still failing even with the latest fixes/changes (see #55730).

@alnikola alnikola removed their assignment Jul 22, 2021
@alnikola alnikola modified the milestones: 6.0.0, 7.0.0 Jul 22, 2021
@karelz karelz modified the milestones: 7.0.0, 8.0.0 Jul 19, 2022
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Aug 1, 2023
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Aug 1, 2023
@ghost ghost locked as resolved and limited conversation to collaborators Sep 1, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
area-System.Net.Http disabled-test The test is disabled in source code against the issue test-bug Problem in test source code (most likely) test-run-core Test failures in .NET Core test runs
Projects
None yet