Skip to content

Flaky test: test_nested_loop_error_in_grandchild_resource_tracker_silent #1273

@ogrisel

Description

@ogrisel

Observed several times:

https://dev.azure.com/joblib/joblib/_build/results?buildId=1849&view=logs&j=e366bf14-feff-5258-9913-c0ec433aa72d&t=db9d9cf0-46c0-52ca-1b5f-c25993207165&l=1312

https://dev.azure.com/joblib/joblib/_build/results?buildId=1874&view=logs&j=e366bf14-feff-5258-9913-c0ec433aa72d

2022-02-23T13:12:02.7548426Z =================================== FAILURES ===================================
2022-02-23T13:12:02.7549232Z _________ test_nested_loop_error_in_grandchild_resource_tracker_silent _________
2022-02-23T13:12:02.7549590Z 
2022-02-23T13:12:02.7549891Z     @with_numpy
2022-02-23T13:12:02.7550280Z     @with_multiprocessing
2022-02-23T13:12:02.7550753Z     def test_nested_loop_error_in_grandchild_resource_tracker_silent():
2022-02-23T13:12:02.7551346Z         # Safety smoke test: test that nested parallel calls using the loky backend
2022-02-23T13:12:02.7552776Z         # don't yield noisy resource_tracker outputs when the grandchild errors
2022-02-23T13:12:02.7553258Z         # out.
2022-02-23T13:12:02.7553799Z         cmd = '''if 1:
2022-02-23T13:12:02.7554216Z             from joblib import Parallel, delayed
2022-02-23T13:12:02.7554608Z     
2022-02-23T13:12:02.7555968Z     
2022-02-23T13:12:02.7556348Z             def raise_error(i):
2022-02-23T13:12:02.7556756Z                 raise ValueError
2022-02-23T13:12:02.7557096Z     
2022-02-23T13:12:02.7557431Z     
2022-02-23T13:12:02.7557795Z             def nested_loop(f):
2022-02-23T13:12:02.7558206Z                 Parallel(backend="loky", n_jobs=2)(
2022-02-23T13:12:02.7558663Z                     delayed(f)(i) for i in range(10)
2022-02-23T13:12:02.7559039Z                 )
2022-02-23T13:12:02.7559383Z     
2022-02-23T13:12:02.7559722Z     
2022-02-23T13:12:02.7560074Z             if __name__ == "__main__":
2022-02-23T13:12:02.7560524Z                 Parallel(backend="loky", n_jobs=2)(
2022-02-23T13:12:02.7560998Z                     delayed(nested_loop)(func) for func in [raise_error]
2022-02-23T13:12:02.7561450Z                 )
2022-02-23T13:12:02.7561991Z         '''
2022-02-23T13:12:02.7562587Z         p = subprocess.Popen([sys.executable, '-c', cmd],
2022-02-23T13:12:02.7563126Z                              stderr=subprocess.PIPE, stdout=subprocess.PIPE)
2022-02-23T13:12:02.7563847Z         p.wait()
2022-02-23T13:12:02.7564221Z         out, err = p.communicate()
2022-02-23T13:12:02.7564738Z         assert p.returncode == 1, out.decode()
2022-02-23T13:12:02.7565203Z >       assert b"resource_tracker" not in err, err.decode()
2022-02-23T13:12:02.7565763Z E       AssertionError: joblib.externals.loky.process_executor._RemoteTraceback: 
2022-02-23T13:12:02.7566236Z E         """
2022-02-23T13:12:02.7569213Z E         joblib.externals.loky.process_executor._RemoteTraceback: 
2022-02-23T13:12:02.7569920Z E         """
2022-02-23T13:12:02.7575120Z E         Traceback (most recent call last):
2022-02-23T13:12:02.7576344Z E           File "/home/vsts/work/1/s/joblib/externals/loky/process_executor.py", line 418, in _process_worker
2022-02-23T13:12:02.7579612Z E             r = call_item()
2022-02-23T13:12:02.7580180Z E           File "/home/vsts/work/1/s/joblib/externals/loky/process_executor.py", line 274, in __call__
2022-02-23T13:12:02.7580730Z E             return self.fn(*self.args, **self.kwargs)
2022-02-23T13:12:02.7581200Z E           File "/home/vsts/work/1/s/joblib/_parallel_backends.py", line 620, in __call__
2022-02-23T13:12:02.7581763Z E             return self.func(*args, **kwargs)
2022-02-23T13:12:02.7582513Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 287, in __call__
2022-02-23T13:12:02.7582958Z E             return [func(*args, **kwargs)
2022-02-23T13:12:02.7583504Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 287, in <listcomp>
2022-02-23T13:12:02.7584036Z E             return [func(*args, **kwargs)
2022-02-23T13:12:02.7584489Z E           File "<string>", line 6, in raise_error
2022-02-23T13:12:02.7584935Z E         ValueError
2022-02-23T13:12:02.7585327Z E         """
2022-02-23T13:12:02.7585673Z E         
2022-02-23T13:12:02.7586159Z E         The above exception was the direct cause of the following exception:
2022-02-23T13:12:02.7586614Z E         
2022-02-23T13:12:02.7587037Z E         Traceback (most recent call last):
2022-02-23T13:12:02.7587618Z E           File "/home/vsts/work/1/s/joblib/externals/loky/process_executor.py", line 418, in _process_worker
2022-02-23T13:12:02.7588148Z E             r = call_item()
2022-02-23T13:12:02.7588721Z E           File "/home/vsts/work/1/s/joblib/externals/loky/process_executor.py", line 274, in __call__
2022-02-23T13:12:02.7589305Z E             return self.fn(*self.args, **self.kwargs)
2022-02-23T13:12:02.7589856Z E           File "/home/vsts/work/1/s/joblib/_parallel_backends.py", line 620, in __call__
2022-02-23T13:12:02.7590443Z E             return self.func(*args, **kwargs)
2022-02-23T13:12:02.7590955Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 287, in __call__
2022-02-23T13:12:02.7591485Z E             return [func(*args, **kwargs)
2022-02-23T13:12:02.7592011Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 287, in <listcomp>
2022-02-23T13:12:02.7592569Z E             return [func(*args, **kwargs)
2022-02-23T13:12:02.7593053Z E           File "<string>", line 10, in nested_loop
2022-02-23T13:12:02.7593584Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 1093, in __call__
2022-02-23T13:12:02.7594061Z E             self.retrieve()
2022-02-23T13:12:02.7594567Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 972, in retrieve
2022-02-23T13:12:02.7595140Z E             self._output.extend(job.get(timeout=self.timeout))
2022-02-23T13:12:02.7595721Z E           File "/home/vsts/work/1/s/joblib/_parallel_backends.py", line 567, in wrap_future_result
2022-02-23T13:12:02.7596340Z E             return future.result(timeout=timeout)
2022-02-23T13:12:02.7596938Z E           File "/usr/share/miniconda/envs/testenv/lib/python3.10/concurrent/futures/_base.py", line 446, in result
2022-02-23T13:12:02.7597509Z E             return self.__get_result()
2022-02-23T13:12:02.7598103Z E           File "/usr/share/miniconda/envs/testenv/lib/python3.10/concurrent/futures/_base.py", line 391, in __get_result
2022-02-23T13:12:02.7598899Z E             raise self._exception
2022-02-23T13:12:02.7599298Z E         ValueError
2022-02-23T13:12:02.7599684Z E         """
2022-02-23T13:12:02.7600020Z E         
2022-02-23T13:12:02.7600501Z E         The above exception was the direct cause of the following exception:
2022-02-23T13:12:02.7601083Z E         
2022-02-23T13:12:02.7601475Z E         Traceback (most recent call last):
2022-02-23T13:12:02.7601887Z E           File "<string>", line 16, in <module>
2022-02-23T13:12:02.7602393Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 1093, in __call__
2022-02-23T13:12:02.7602896Z E             self.retrieve()
2022-02-23T13:12:02.7603398Z E           File "/home/vsts/work/1/s/joblib/parallel.py", line 972, in retrieve
2022-02-23T13:12:02.7604059Z E             self._output.extend(job.get(timeout=self.timeout))
2022-02-23T13:12:02.7604665Z E           File "/home/vsts/work/1/s/joblib/_parallel_backends.py", line 567, in wrap_future_result
2022-02-23T13:12:02.7605249Z E             return future.result(timeout=timeout)
2022-02-23T13:12:02.7605823Z E           File "/usr/share/miniconda/envs/testenv/lib/python3.10/concurrent/futures/_base.py", line 446, in result
2022-02-23T13:12:02.7606405Z E             return self.__get_result()
2022-02-23T13:12:02.7607000Z E           File "/usr/share/miniconda/envs/testenv/lib/python3.10/concurrent/futures/_base.py", line 391, in __get_result
2022-02-23T13:12:02.7607565Z E             raise self._exception
2022-02-23T13:12:02.7607989Z E         ValueError
2022-02-23T13:12:02.7608829Z E         /home/vsts/work/1/s/joblib/externals/loky/backend/resource_tracker.py:310: UserWarning: resource_tracker: There appear to be 3 leaked semlock objects to clean up at shutdown
2022-02-23T13:12:02.7609561Z E           warnings.warn(
2022-02-23T13:12:02.7611304Z E         
2022-02-23T13:12:02.7613091Z E       assert b'resource_tracker' not in b'joblib.externals.loky.process_executor._RemoteTraceback: \n"""\njoblib.externals.loky.process_executor._RemoteTraceb...UserWarning: resource_tracker: There appear to be 3 leaked semlock objects to clean up at shutdown\n  warnings.warn(\n'
2022-02-23T13:12:02.7614912Z 
2022-02-23T13:12:02.7623487Z cmd        = 'if 1:\n        from joblib import Parallel, delayed\n\n\n        def raise_error(i):\n            raise ValueError\n\...(backend="loky", n_jobs=2)(\n                delayed(nested_loop)(func) for func in [raise_error]\n            )\n    '
2022-02-23T13:12:02.7625198Z err        = b'joblib.externals.loky.process_executor._RemoteTraceback: \n"""\njoblib.externals.loky.process_executor._RemoteTraceb...UserWarning: resource_tracker: There appear to be 3 leaked semlock objects to clean up at shutdown\n  warnings.warn(\n'
2022-02-23T13:12:02.7626194Z out        = b''
2022-02-23T13:12:02.7626895Z p          = <Popen: returncode: 1 args: ['/usr/share/miniconda/envs/testenv/bin/python',...>
2022-02-23T13:12:02.7627310Z 
2022-02-23T13:12:02.7627698Z joblib/test/test_memmapping.py:619: AssertionError

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions