test_concurrent_futures.test_process_pool: test_map_timeout failed

[vstinner]

PPC64LE RHEL7 3.x:

FAIL: test_map_timeout (test.test_concurrent_futures.test_process_pool.ProcessPoolSpawnProcessPoolExecutorTest.test_map_timeout)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/buildbot/buildarea/3.x.cstratak-RHEL7-ppc64le/build/Lib/test/test_concurrent_futures/executor.py", line 69, in test_map_timeout
    self.assertEqual([None, None], results)
AssertionError: Lists differ: [None, None] != []

First list contains 2 additional elements.
First extra element 0:
None

- [None, None]
+ []

----------------------------------------------------------------------
Ran 57 tests in 120.147s

FAILED (failures=1, skipped=6)

The test passed when re-run in verbose mode in a fresh process:

0:22:41 load avg: 0.82 [1/1] test.test_concurrent_futures.test_process_pool passed
Re-running test.test_concurrent_futures.test_process_pool in verbose mode (matching: test_map_timeout)
test_map_timeout (test.test_concurrent_futures.test_process_pool.ProcessPoolForkProcessPoolExecutorTest.test_map_timeout) ... ok
test_map_timeout (test.test_concurrent_futures.test_process_pool.ProcessPoolForkserverProcessPoolExecutorTest.test_map_timeout) ... ok
test_map_timeout (test.test_concurrent_futures.test_process_pool.ProcessPoolSpawnProcessPoolExecutorTest.test_map_timeout) ... ok

----------------------------------------------------------------------
Ran 3 tests in 20.608s

OK

== Tests result: FAILURE then SUCCESS ==

build: https://buildbot.python.org/all/#/builders/446/builds/3961

Linked PRs

• gh-110097: Make test_map_timeout faster and increase timeout. #116427
• gh-110097: Fix flaky test_timeout in test_concurrent_futures.test_process_pool #131108

[sunmy2019]

Is it possible that the OS is scheduling many processes, so it did not wake up in 5 seconds?

    def test_map_timeout(self):
        results = []
        try:
            for i in self.executor.map(time.sleep,
                                       [0, 0, 6],
                                       timeout=5):
                results.append(i)
        except futures.TimeoutError:
            pass
        else:
            self.fail('expected TimeoutError')

        self.assertEqual([None, None], results)

0:12:20 load avg: 14.49 [409/467] test_sched passed -- running (6): test_capi (1 min 51 sec), test_math (5 min 17 sec), test.test_multiprocessing_forkserver.test_manager (47.5 sec), test_unparse (5 min 45 sec), test.test_concurrent_futures.test_process_pool (31.8 sec), test.test_multiprocessing_spawn.test_processes (5 min 7 sec)
...
0:13:51 load avg: 14.81 [436/467/1] test.test_concurrent_futures.test_process_pool failed (1 failure) (2 min 2 sec) -- running (5): test_capi (3 min 22 sec), test_math (6 min 48 sec), test.test_multiprocessing_forkserver.test_manager (2 min 18 sec), test_multiprocessing_main_handling (1 min 46 sec), test_source_encoding (1 min 23 sec)

This would explain why this fails randomly.

[vstinner]

Yes, on a very slow buildbot like this one, 5 seconds can be "too short" and make the test fail.

A test should not depend on the performance of the CI platform.

[vstinner]

I didn't see the failure recently, I close the issue.

[colesbury]

I'm seeing this again on Ubuntu (x86_64, free-threaded):

======================================================================
FAIL: test_map_timeout (test.test_concurrent_futures.test_process_pool.ProcessPoolSpawnProcessPoolExecutorTest.test_map_timeout)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ubuntu/buildarea/3.x.itamaro-ubuntu-aws.nogil/build/Lib/test/test_concurrent_futures/executor.py", line 71, in test_map_timeout
    self.assertEqual([None, None], results)
    ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: Lists differ: [None, None] != []

https://buildbot.python.org/all/#/builders/1225/builds/1670/steps/5/logs/stdio

I think it's not specific to PPC64LE, but rather happens when the machine is under load and spawning processes times out too soon.

[vstinner]

Sadly, this failure decided to hide again since March. I close the issue. Reopen it if it comes back.

[colesbury]

I'm seeing this again, especially with thread sanitizer, which causes a lot of things to execute more slowly. I'll send a PR.