DBG CI-trigger

[tomMoral]

No description provided.

[ogrisel]

On the first trigger we get 5 failures:

FAILED tests/test_loky_backend.py::test_kill_process_tree[True] - RuntimeErro...
FAILED tests/test_loky_backend.py::test_kill_process_tree[False] - RuntimeErr...
FAILED tests/test_process_executor_loky.py::TestsProcessPoolLokyExecutor::test_max_depth[True]
FAILED tests/test_process_executor_loky.py::TestsProcessPoolLokyExecutor::test_max_depth[False]
FAILED tests/test_process_executor_spawn.py::TestsProcessPoolSpawnExecutor::test_max_depth[True]

• https://dev.azure.com/joblib/loky/_build/results?buildId=2955&view=logs&j=f615b7fc-96c0-5239-4596-93297f15094c&t=34dacd20-5623-5562-27dd-37361663ad89&l=2094

and on the second we get a deadlock in test_max_depth after a failure in test_kill_process_tree:

tests/test_process_executor_loky.py::TestsProcessPoolLokyExecutor::test_max_depth[True]

• https://dev.azure.com/joblib/loky/_build/results?buildId=2956&view=logs&j=f615b7fc-96c0-5239-4596-93297f15094c&t=34dacd20-5623-5562-27dd-37361663ad89

[ogrisel]

I pushed a commit to display more debug into.

[ogrisel]

I pushed some logs to make sure which error comes from where.

[ogrisel]

So supposedly the OSError: [WinError 50] The request is not supported raised in LokyProcess-1:1:MainThread has errno 22 and should be ignorable.

Then the following traceback is the root cause of the failure:

[DEBUG:LokyProcess-1:1:1:MainThread] error in main:
Traceback (most recent call last):
  File "D:\a\1\s\loky\backend\popen_loky_win32.py", line 167, in main
    self = load(from_parent)
           ^^^^^^^^^^^^^^^^^
EOFError: Ran out of input

Note however that it is always logged after the errno 22 in its parent.

[ogrisel]

Also note that I cannot reproduce this in a py311 env on a local windows VM... hence the need to debug with the CI...

[ogrisel]

It's weird that this problem only happens in the third nested subprocess:

• MainProcess:MainThread is the pytest process
• LokyProcess-1 is the first level worker and can successfully spawn LokyProcess-1:1,
• LokyProcess-1:1 is the second level worker and fails to spawn LokyProcess-1:1:1 in turn.

The event is therefore never set. And this all happens before attempting to kill the process tree.

[ogrisel]

I have the impression that the failure reduction.dump(process_obj, to_child) at line 106 of loky/backend/popen_loky_win32.py is actually the cause of the problem, rather than an ignorable consequence in this case: the subprocess cannot read from its parent because of the OSError raised by _winapi.DuplicateHandle when calling reduction.dump(process_obj, to_child) in the parent.

[ogrisel]

For the record, is the full traceback of the ignored exception in the parent:

[DEBUG:LokyProcess-1:1:MainThread] error in Popen.__init__:
Traceback (most recent call last):
  File "D:\a\1\s\loky\backend\popen_loky_win32.py", line 106, in __init__
    reduction.dump(process_obj, to_child)
  File "D:\a\1\s\loky\backend\reduction.py", line 208, in dump
    _LokyPickler(file, reducers=reducers, protocol=protocol).dump(obj)
  File "D:\a\1\s\.tox\py311\Lib\site-packages\cloudpickle\cloudpickle_fast.py", line 632, in dump
    return Pickler.dump(self, obj)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\hostedtoolcache\windows\Python\3.11.3\x64\Lib\multiprocessing\synchronize.py", line 104, in __getstate__
    h = context.get_spawning_popen().duplicate_for_child(sl.handle)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "D:\a\1\s\loky\backend\popen_loky_win32.py", line 126, in duplicate_for_child
    return duplicate(handle, self.sentinel)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\hostedtoolcache\windows\Python\3.11.3\x64\Lib\multiprocessing\reduction.py", line 79, in duplicate
    return _winapi.DuplicateHandle(
           ^^^^^^^^^^^^^^^^^^^^^^^^
OSError: [WinError 50] The request is not supported

[ogrisel]

Note that in cpython main, this special casing of errno 22 does not exist: the exception is always raised.

[ogrisel]

Ok so this is a loky-specific problem: running the same test with the default "spawn" context works. So we will have to diff the 2 backends w.r.t. semlock usage.

[ogrisel]

I will re-push a trigger commit just to be sure.

[ogrisel]

Ok so based on the last CI runs, this is really a problem that only happens with the loky context, not the spawn context.

[ogrisel]

Fixed by #394.