Test failure: System.Net.Http.Functional.Tests.SocketsHttpHandler_HttpClientHandler_Cancellation_Test / GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly

[Sunny-pu]

Test System.Net.Http.Functional.Tests.SocketsHttpHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly has failed.

MESSAGE:
Elapsed time 00:00:31.6655081 should be less than 30 seconds, was 31.6655081\r\nExpected: True\r\nActual: False

STACK TRACE:
at System.Net.Http.Functional.Tests.HttpClientHandler_Cancellation_Test.ValidateClientCancellationAsync(Func`1 clientBodyAsync) in D:\j\workspace\outerloop_net---92764178\src\System.Net.Http\tests\FunctionalTests\HttpClientHandlerTest.Cancellation.cs:line 372 at System.Net.Http.Functional.Tests.HttpClientHandler_Cancellation_Test.<>c__DisplayClass2_2.<<GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly>b__0>d.MoveNext() in D:\j\workspace\outerloop_net---92764178\src\System.Net.Http\tests\FunctionalTests\HttpClientHandlerTest.Cancellation.cs:line 128 --- End of stack trace from previous location where exception was thrown --- at System.Net.Test.Common.LoopbackServer.CreateServerAsync(Func`2 funcAsync, Options options) in D:\j\workspace\outerloop_net---92764178\src\Common\tests\System\Net\Http\LoopbackServer.cs:line 67 at System.Net.Http.Functional.Tests.HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly(Boolean chunkedTransfer, Boolean connectionClose, CancellationMode mode) in D:\j\workspace\outerloop_net---92764178\src\System.Net.Http\tests\FunctionalTests\HttpClientHandlerTest.Cancellation.cs:line 110 --- End of stack trace from previous location where exception was thrown ---

Details: https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_netcoreapp_win7_debug/456/testReport/System.Net.Http.Functional.Tests/SocketsHttpHandler_HttpClientHandler_Cancellation_Test/GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly_chunkedTransfer__True__connectionClose__False__mode__Token__CancelPendingRequests_/

[ViktorHofer]

Timing out again: https://dnceng.visualstudio.com/public/_build/results?buildId=394779&view=ms.vss-test-web.build-test-results-tab&runId=12301110&resultId=178961&paneView=attachments

   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:02:16
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:04:17
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:06:17
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:08:17
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:10:17
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:12:17
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:14:17

@stephentoub @davidsh

[ahsonkhan]

Time out again in dotnet/corefx#41845

netcoreapp-Windows_NT-Debug-x64-Windows.81.Amd64.Open

https://helix.dot.net/api/2019-06-17/jobs/f1180365-05b8-4a6e-af0e-6703f5088588/workitems/System.Net.Http.Functional.Tests/console

   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:02:27
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:04:27
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:06:27
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:08:28
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:10:28
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:12:28
   System.Net.Http.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Cancellation_Test.GetAsync_CancelDuringResponseBodyReceived_Buffered_TaskCanceledQuickly', Elapsed: 00:14:28

[alnikola]

I ran this test locally in a loop 100+ times and everything completed successfully. Can the issue be fixed already? Or, do we believe it happens only on the cloud?

[stephentoub]

I don't know if the issue has been fixed, but often these sporadic failures only manifest under load, and even then only sometimes.

[karelz]

@wfurt used to run entire test suite in a loop on his machine. Sometimes other tests may interact. If that does not hir the problem, it was usually good sign to try to re-enable the test and observe if it fails in CI.

[wfurt]

This also may be dependent on HW configuration e.g. CPU count and others. Maybe we can move them to OuterLoop for now so we get some CI runs while keeping this open.

Also, it seems like old failures were on Win 7/8 queue. What OS did you use @alnikola ?

While back, we had issues when running tests on single-core CPU.
Ather option I see is to wrap the test(s) with timer and Assert() on failures.
That should produce core file now, and we may be able to diagnose if this happens ever again.

[alnikola]

I ran it on Win 10. Today, I also artificially slowed down the test execution by binding it to one core with "Idle" priority and running another CPU-consuming process on the same core, but didn't get any failures either. So, I will follow the above suggestion to wrap the test with a time and enable it.