MultipleOperationsOverSingleHandle_CompletedWorkItemCountTest frequent failures

[directhex]

Description

Assert.InRange() Failure\r\nRange:  (0 - 60000)\r\nActual: 60016

https://dev.azure.com/dnceng/public/_build/results?buildId=1039498
https://dev.azure.com/dnceng/public/_build/results?buildId=1039390
https://dev.azure.com/dnceng/public/_build/results?buildId=1035778

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[adamsitnik]

@kouvel I've hit that in #57717

From logs:

Console log: 'System.Threading.Overlapped.Tests' from job 4fc058d6-4acd-4f87-b026-b0d30f1af6ea workitem ac9b57b8-827c-4562-909c-aa8cdcf343f6 (windows.7.amd64.open.rt) executed on machine a0014RZ

C:\h\w\B48909FB\w\B0FD09B4\e>taskkill.exe /f /im corerun.exe 
ERROR: The process "corerun.exe" not found.

C:\h\w\B48909FB\w\B0FD09B4\e>call RunTests.cmd --runtime-path C:\h\w\B48909FB\p 
----- start Thu 08/19/2021  9:57:11.09 ===============  To repro directly: ===================================================== 
pushd C:\h\w\B48909FB\w\B0FD09B4\e\
"C:\h\w\B48909FB\p\dotnet.exe" exec --runtimeconfig System.Threading.Overlapped.Tests.runtimeconfig.json --depsfile System.Threading.Overlapped.Tests.deps.json xunit.console.dll System.Threading.Overlapped.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing 
popd
===========================================================================================================

C:\h\w\B48909FB\w\B0FD09B4\e>"C:\h\w\B48909FB\p\dotnet.exe" exec --runtimeconfig System.Threading.Overlapped.Tests.runtimeconfig.json --depsfile System.Threading.Overlapped.Tests.deps.json xunit.console.dll System.Threading.Overlapped.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing  
  Discovering: System.Threading.Overlapped.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Threading.Overlapped.Tests (found 62 of 63 test cases)
  Starting:    System.Threading.Overlapped.Tests (parallel test collections = on, max threads = 2)
    ThreadPoolBoundHandleTests.MultipleOperationsOverSingleHandle_CompletedWorkItemCountTest [FAIL]
      System.AggregateException : changeInCompletedWorkItemCount: 1 (Assert.InRange() Failure
      Range:  (0 - 60000)
      Actual: 60016)
      ---- Assert.InRange() Failure
      Range:  (0 - 60000)
      Actual: 60016
      Stack Trace:
        /_/src/libraries/System.Threading.Overlapped/tests/ThreadPoolBoundHandle_IntegrationTests.netcoreapp.cs(29,0): at ThreadPoolBoundHandleTests.MultipleOperationsOverSingleHandle_CompletedWorkItemCountTest()
        ----- Inner Stack Trace -----
        /_/src/libraries/Common/tests/System/Threading/ThreadTestHelpers.cs(147,0): at System.Threading.Tests.ThreadTestHelpers.WaitForConditionWithCustomDelay(Func`1 condition, Action delay)
        /_/src/libraries/Common/tests/System/Threading/ThreadTestHelpers.cs(117,0): at System.Threading.Tests.ThreadTestHelpers.WaitForCondition(Func`1 condition)
        /_/src/libraries/System.Threading.Overlapped/tests/ThreadPoolBoundHandle_IntegrationTests.netcoreapp.cs(20,0): at ThreadPoolBoundHandleTests.MultipleOperationsOverSingleHandle_CompletedWorkItemCountTest()
  Finished:    System.Threading.Overlapped.Tests
=== TEST EXECUTION SUMMARY ===
   System.Threading.Overlapped.Tests  Total: 71, Errors: 0, Failed: 1, Skipped: 0, Time: 60.398s

FWIW It's Windows 7, x86

[kouvel]

Thanks @adamsitnik. This seems to have the new info I added but I still don't know why it would be failing. Disabling the test for now.

[AustinWise]

I don't know if it's related, but I committed a changed that touched one of the places that that increments CompletedWorkItemCount. See this commit. It should not be possible for this change to cause more counting than before, since I deleted both CallbackForInitiateDrainageOfCompletionPortQueue and CallbackForContinueDrainageOfCompletionPortQueue. But I wanted to point it out anyway since the test started to fail shortly after my change.

[kouvel]

@AustinWise I agree it doesn't look like that change would cause a completion to be missed in counting. The drainage work items were fake housekeeping work items so they were not counted, in this test there should be two real completions.

[mangod9]

Closing since this doesnt appear to repro anymore.

[MichalStrehovsky]

That test doesn't run because it's blocked on this issue.

runtime/src/libraries/System.Threading.Overlapped/tests/ThreadPoolBoundHandle_IntegrationTests.netcoreapp.cs

Line 13 in fdce644

[ActiveIssue("https://github.com/dotnet/runtime/issues/49700")]

[mangod9]

Ok assigning to @eduardo-vp for now since Kount is out. Please check if the failure still repros after removing the [ActiveIssue] tag. Thanks

[kouvel]

The ActiveIssue was removed in #72973