test_concurrent_futures: test_as_completed.test_future_times_out() fails on GHA Windows x86 CI

[vstinner]

Windows x86:

FAIL: test_future_times_out (test.test_concurrent_futures.test_as_completed.ThreadPoolAsCompletedTest.test_future_times_out) [0.01]
Test ``futures.as_completed`` timing out before
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\a\cpython\cpython\Lib\test\test_concurrent_futures\test_as_completed.py", line 60, in test_future_times_out
    self.assertEqual(completed_futures, already_completed)
AssertionError: Items in the first set but not the second:
<Future at 0x5684560 state=finished returned NoneType>

build: https://github.com/python/cpython/actions/runs/6225761937/job/16896880945?pr=108965

The test fails randomly. It passed when re-run in verbose mode in a fresh process:

0:16:02 load avg: 5.55 [2/2/1] test.test_concurrent_futures.test_as_completed passed
Re-running test.test_concurrent_futures.test_as_completed in verbose mode (matching: test_future_times_out)
test_future_times_out (test.test_concurrent_futures.test_as_completed.ProcessPoolForkAsCompletedTest.test_future_times_out)
Test ``futures.as_completed`` timing out before ... skipped 'require unix system'
test_future_times_out (test.test_concurrent_futures.test_as_completed.ProcessPoolForkserverAsCompletedTest.test_future_times_out)
Test ``futures.as_completed`` timing out before ... skipped 'require unix system'
test_future_times_out (test.test_concurrent_futures.test_as_completed.ProcessPoolSpawnAsCompletedTest.test_future_times_out)
Test ``futures.as_completed`` timing out before ... 0.75s ok
test_future_times_out (test.test_concurrent_futures.test_as_completed.ThreadPoolAsCompletedTest.test_future_times_out)
Test ``futures.as_completed`` timing out before ... 0.11s ok

----------------------------------------------------------------------
Ran 4 tests in 0.881s

OK (skipped=2)

Linked PRs

• gh-109565: Fix concurrent.futures test_future_times_out() #109949
• [3.12] gh-109565: Fix concurrent.futures test_future_times_out() (GH-109949) #109952

[vstinner]

Test also failed on s390x Fedora 3.x: https://buildbot.python.org/all/#/builders/223/builds/4511

  test_future_times_out (test.test_concurrent_futures.test_as_completed.ThreadPoolAsCompletedTest.test_future_times_out) [0]
Test ``futures.as_completed`` timing out before ... FAIL

Stdout:
0.35s 
test_no_timeout (test.test_concurrent_futures.test_as_completed.ThreadPoolAsCompletedTest.test_no_timeout) ... ok

======================================================================
FAIL: test_future_times_out (test.test_concurrent_futures.test_as_completed.ThreadPoolAsCompletedTest.test_future_times_out) [0]
Test ``futures.as_completed`` timing out before
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/dje/cpython-buildarea/3.x.edelsohn-fedora-z/build/Lib/test/test_concurrent_futures/test_as_completed.py", line 60, in test_future_times_out
    self.assertEqual(completed_futures, already_completed)
AssertionError: Items in the first set but not the second:
<Future at 0x3ff9280f1c0 state=finished returned NoneType>

[elfstrom]

I guess this would fix it:

            with self.subTest(timeout):

-               future = self.executor.submit(time.sleep, 0.1)
+               future = self.executor.submit(time.sleep, 10.0)
                completed_futures = set()
                try:

I don't think the short sleep serves any testing purpose here, it just makes the test more likely to fail if there is any unexpected CPU contention.

[vstinner]

The problem is that the test waits cleanly until the future completes, and so the test takes 10 seconds with your change, instead of 100 ms (100x slower).

[vstinner]

I proposed PR #109949 to fix this test.