[WinHttpHandler] Long running test: ResponseHeadersRead_SynchronizationContextNotUsedByHandler on Win7/Win8

[ViktorHofer]

Test types:

• System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test
• System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Http2_Test

Looks like a regression introduced on 2021/6/10 (see last table)

Hangs 7/8-7/29 (incl. PRs):

Date	Run	OS	Type
7/8	PR #55350	Windows.7.Amd64.Open	Http2
7/8	PR #55037	Windows.7.Amd64.Open	Http2
7/8	PR #55292	Windows.7.Amd64.Open	Http2
7/8	PR #54611	Windows.7.Amd64.Open	Http2
7/9	PR #55434	Windows.7.Amd64.Open	Http2
7/9	PR #54845	Windows.7.Amd64.Open	Http2
7/9	PR #55384	Windows.7.Amd64.Open
7/9	PR #55256	Windows.7.Amd64.Open	Http2
7/10	PR #55419	Windows.7.Amd64.Open
7/10	PR #55395	Windows.7.Amd64.Open	Http2
7/10	PR #55385	Windows.7.Amd64.Open	Http2
7/11	Official run	Windows.81.Amd64.Open
7/11	PR #55474	Windows.7.Amd64.Open	Http2
7/12	PR #55046	Windows.7.Amd64.Open	Http2
7/12	Official run	Windows.7.Amd64.Open
7/12	PR #55501	Windows.81.Amd64.Open	Http2
7/12	PR #55490	Windows.81.Amd64.Open	Http2
7/13	PR #55108	Windows.7.Amd64.Open	Http2
7/13	PR #55430	Windows.7.Amd64.Open	Http2
7/13	PR #55373	Windows.7.Amd64.Open	Http2
7/13	PR #55565	Windows.7.Amd64.Open	Http2
7/13	PR #55550	Windows.7.Amd64.Open
7/13	PR #55537	Windows.7.Amd64.Open	Http2
7/15	PR #55636	Windows.7.Amd64.Open	Http2
7/17	Official run	Windows.7.Amd64.Open
7/19	PR #55954	Windows.7.Amd64.Open
7/19	PR #55813	Windows.7.Amd64.Open	Http2
7/21	PR #55664	Windows.81.Amd64.Open	Http2
7/21	PR #56068	Windows.81.Amd64.Open
7/22	PR #54640	Windows.81.Amd64.Open	Http2
7/23	PR #56211	Windows.7.Amd64.Open
7/23	PR #56175	Windows.7.Amd64.Open
7/26	PR #56307	Windows.81.Amd64.Open	Http2
7/26	PR #56288	Windows.7.Amd64.Open	Http2
7/27	PR #56353	Windows.81.Amd64.Open	Http2
7/27	PR #56330	Windows.81.Amd64.Open	Http2
7/27	PR #56324	Windows.7.Amd64.Open	Http2

Example of hang:

C:\h\w\BAE609E5\w\B003097B\e>"C:\h\w\BAE609E5\p\dotnet.exe" exec --runtimeconfig System.Net.Http.WinHttpHandler.Functional.Tests.runtimeconfig.json --depsfile System.Net.Http.WinHttpHandler.Functional.Tests.deps.json xunit.console.dll System.Net.Http.WinHttpHandler.Functional.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing  
  Discovering: System.Net.Http.WinHttpHandler.Functional.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Http.WinHttpHandler.Functional.Tests (found 295 of 535 test cases)
  Starting:    System.Net.Http.WinHttpHandler.Functional.Tests (parallel test collections = on, max threads = 2)
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:02:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:04:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:06:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:08:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:10:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:12:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:14:11
['System.Net.Http.WinHttpHandler.Functional.Tests' WORK ITEM LOG TRUNCATED: Command timed out, and was killed]

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1181785&view=ms.vss-test-web.build-test-results-tab&runId=35557044&paneView=debug

Here are likely also duplicates (esp. on Win7 and Win8.1) for period 3/29-7/8 -- the console logs are missing to confirm, but frequency on Win7 and Win8.1 is similar:

Day	Run	OS
5/11	Official run	Windows.Server.Core.1909.Amd64.Open
5/17	PR #51094	Windows.81.Amd64.Open
5/19	Official run	Windows.Server.Core.1909.Amd64.Open
5/19	Official run	Windows.Server.Core.1909.Amd64.Open
5/23	Official run	Windows.Server.Core.1909.Amd64.Open
5/29	Official run	Windows.Server.Core.1909.Amd64.Open
5/30	Official run	Windows.Server.Core.1909.Amd64.Open
5/30	Official run	Windows.Server.Core.1909.Amd64.Open
6/10	PR #53971	Windows.7.Amd64.Open
6/10	PR #53864	Windows.7.Amd64.Open
6/11	PR #53704	Windows.81.Amd64.Open
6/11	PR #54047	Windows.7.Amd64.Open
6/11	PR #50510	Windows.7.Amd64.Open
6/11	PR #53808	Windows.7.Amd64.Open
6/11	PR #54056	Windows.7.Amd64.Open
6/11	PR #53852	Windows.7.Amd64.Open
6/12	PR #54094	Windows.7.Amd64.Open
6/12	PR #53752	Windows.7.Amd64.Open
6/13	PR #53752	Windows.7.Amd64.Open
6/13	PR #53752	Windows.7.Amd64.Open
6/14	PR #54060	Windows.7.Amd64.Open
6/15	PR #51294	Windows.7.Amd64.Open
6/15	PR #53201	Windows.7.Amd64.Open
6/15	PR #54147	Windows.7.Amd64.Open
6/15	PR #54147	Windows.7.Amd64.Open
6/15	PR #54006	Windows.7.Amd64.Open
6/15	PR #54238	Windows.7.Amd64.Open
6/16	PR #54248	Windows.81.Amd64.Open
6/16	PR #54006	Windows.7.Amd64.Open
6/16	PR #54286	Windows.7.Amd64.Open
6/16	PR #54245	Windows.7.Amd64.Open
6/16	PR #54291	Windows.7.Amd64.Open
6/17	PR #54273	Windows.7.Amd64.Open
6/17	PR #54289	Windows.7.Amd64.Open
6/17	PR #54377	Windows.7.Amd64.Open
6/18	PR #54280	Windows.7.Amd64.Open
6/18	PR #54218	Windows.7.Amd64.Open
6/18	PR #54246	Windows.81.Amd64.Open
6/18	PR #47640	Windows.7.Amd64.Open
6/18	PR #54429	Windows.7.Amd64.Open
6/18	PR #53763	Windows.7.Amd64.Open
6/19	PR #54089	Windows.7.Amd64.Open
6/21	PR #54483	Windows.7.Amd64.Open
6/21	PR #54477	Windows.7.Amd64.Open
6/21	PR #54453	Windows.7.Amd64.Open
6/21	PR #54136	Windows.7.Amd64.Open
6/21	PR #54289	Windows.81.Amd64.Open
6/21	PR #49662	Windows.7.Amd64.Open
6/22	PR #54465	Windows.7.Amd64.Open
6/22	PR #53469	Windows.7.Amd64.Open
6/22	PR #51255	Windows.7.Amd64.Open
6/22	PR #51255	Windows.7.Amd64.Open
6/22	PR #52929	Windows.7.Amd64.Open
6/22	PR #54564	Windows.7.Amd64.Open
6/23	PR #54564	Windows.7.Amd64.Open
6/23	PR #51255	Windows.7.Amd64.Open
6/23	PR #54552	Windows.7.Amd64.Open
6/23	PR #54544	Windows.7.Amd64.Open
6/23	PR #54590	Windows.81.Amd64.Open
6/24	PR #54585	Windows.7.Amd64.Open
6/24	PR #54136	Windows.7.Amd64.Open
6/24	PR #50510	Windows.7.Amd64.Open
6/24	PR #54543	Windows.7.Amd64.Open
6/24	PR #54673	Windows.7.Amd64.Open
6/24	PR #54681	Windows.7.Amd64.Open
6/25	PR #54451	Windows.7.Amd64.Open
6/25	Official run	Windows.7.Amd64.Open
6/25	PR #54717	Windows.7.Amd64.Open
6/25	PR #54590	Windows.7.Amd64.Open
6/25	PR #54732	Windows.7.Amd64.Open
6/25	PR #54250	Windows.7.Amd64.Open
6/25	PR #54750	Windows.81.Amd64.Open
6/26	PR #54636	Windows.7.Amd64.Open
6/27	PR #54785	Windows.7.Amd64.Open
6/28	PR #54755	Windows.7.Amd64.Open
6/28	PR #54755	Windows.7.Amd64.Open
6/29	PR #54650	Windows.7.Amd64.Open
6/29	PR #54650	Windows.7.Amd64.Open
6/29	PR #54884	Windows.7.Amd64.Open
6/29	PR #54884	Windows.7.Amd64.Open
6/29	PR #54467	Windows.7.Amd64.Open
6/29	PR #54467	Windows.7.Amd64.Open
6/29	PR #54917	Windows.7.Amd64.Open
6/29	PR #54253	Windows.81.Amd64.Open
6/29	PR #54247	Windows.7.Amd64.Open
6/30	PR #54960	Windows.7.Amd64.Open
6/30	PR #54266	Windows.7.Amd64.Open
6/30	PR #54942	Windows.7.Amd64.Open
6/30	PR #54949	Windows.7.Amd64.Open
6/30	PR #51653	Windows.7.Amd64.Open
7/1	PR #54692	Windows.7.Amd64.Open
7/1	PR #54938	Windows.7.Amd64.Open
7/1	PR #54884	Windows.7.Amd64.Open
7/1	PR #55012	Windows.7.Amd64.Open
7/1	PR #55022	Windows.7.Amd64.Open
7/1	PR #54453	Windows.7.Amd64.Open
7/1	PR #54451	Windows.7.Amd64.Open
7/1	PR #55041	Windows.81.Amd64.Open
7/2	PR #54429	Windows.7.Amd64.Open
7/2	PR #55048	Windows.7.Amd64.Open
7/2	PR #54253	Windows.7.Amd64.Open
7/2	PR #55007	Windows.7.Amd64.Open
7/2	PR #54250	Windows.7.Amd64.Open
7/2	PR #54266	Windows.7.Amd64.Open
7/2	PR #54453	Windows.81.Amd64.Open
7/2	PR #55019	Windows.81.Amd64.Open
7/2	PR #54845	Windows.7.Amd64.Open
7/2	PR #55046	Windows.7.Amd64.Open
7/2	PR #53370	Windows.10.Amd64.Server19H1.Open
7/2	PR #54254	Windows.7.Amd64.Open
7/2	Official run	Windows.81.Amd64.Open
7/2	PR #55037	Windows.7.Amd64.Open
7/3	PR #55110	Windows.7.Amd64.Open
7/3	PR #55122	Windows.7.Amd64.Open
7/3	PR #54254	Windows.81.Amd64.Open
7/4	PR #55123	Windows.7.Amd64.Open
7/5	PR #54903	Windows.81.Amd64.Open
7/5	PR #55182	Windows.7.Amd64.Open
7/6	PR #54970	Windows.7.Amd64.Open
7/6	PR #54241	Windows.7.Amd64.Open
7/6	PR #54845	Windows.7.Amd64.Open
7/6	PR #55046	Windows.7.Amd64.Open
7/7	PR #54186	Windows.7.Amd64.Open
7/7	PR #54640	Windows.7.Amd64.Open
7/7	PR #55074	Windows.7.Amd64.Open
7/8	PR #55282	Windows.7.Amd64.Open
7/8	PR #55303	Windows.7.Amd64.Open

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

Issue Details

---

C:\h\w\BAE609E5\w\B003097B\e>"C:\h\w\BAE609E5\p\dotnet.exe" exec --runtimeconfig System.Net.Http.WinHttpHandler.Functional.Tests.runtimeconfig.json --depsfile System.Net.Http.WinHttpHandler.Functional.Tests.deps.json xunit.console.dll System.Net.Http.WinHttpHandler.Functional.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing  
  Discovering: System.Net.Http.WinHttpHandler.Functional.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Http.WinHttpHandler.Functional.Tests (found 295 of 535 test cases)
  Starting:    System.Net.Http.WinHttpHandler.Functional.Tests (parallel test collections = on, max threads = 2)
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:02:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:04:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:06:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:08:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:10:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:12:11
   System.Net.Http.WinHttpHandler.Functional.Tests: [Long Running Test] 'System.Net.Http.Functional.Tests.PlatformHandler_HttpClientHandler_Asynchrony_Test.ResponseHeadersRead_SynchronizationContextNotUsedByHandler', Elapsed: 00:14:11
['System.Net.Http.WinHttpHandler.Functional.Tests' WORK ITEM LOG TRUNCATED: Command timed out, and was killed]

Configuration: net6.0-windows-Debug-x86-CoreCLR_release-Windows.7.Amd64.Open

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1181785&view=ms.vss-test-web.build-test-results-tab&runId=35557044&paneView=debug

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

[danmoseley]

A hang, so there is no dump 😢

[ManickaP]

Didn't we used to get dumps from hanging tests? Or am I imagining it?

[danmoseley]

Not from hangs.. that requires vstest 😿

[ViktorHofer]

Happened again: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-54544-merge-cb74d6d59d8d4bfaaa/System.Net.Http.WinHttpHandler.Functional.Tests/console.c985adec.log?sv=2019-07-07&se=2021-07-13T15%3A11%3A32Z&sr=c&sp=rl&sig=irZnBJiqmayMmmj8MYGt6zrAp0RdziUjMWLKT1VjKeM%3D

Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1201849&view=ms.vss-test-web.build-test-results-tab&runId=35987784&paneView=dotnet-dnceng.dnceng-build-release-tasks.helix-test-information-tab&resultId=195324

[danmoseley]

Hit again
Console log: 'System.Net.Http.WinHttpHandler.Functional.Tests' from job 1328b510-44f9-490f-af27-3e4ddc879c2d workitem 5b996f63-2532-4473-94ed-c684bddabc53 (windows.81.amd64.open.svc) executed on machine a0001VZ

Perhaps code inspection might suggest the problem?

[danmoseley]

Hit again on Libraries Test Run release coreclr windows x86 Debug.

I wonder whether there is logging that we can add.