Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[3.5] test_first_completed_some_already_completed() of test_concurrent_futures.ProcessPoolWaitTests: time.sleep() fails with "sleep length must be non-negative" in setUp() on x86 Tiger 3.5 #75028

Closed
vstinner opened this issue Jul 4, 2017 · 5 comments
Labels
OS-mac tests Tests in the Lib/test dir

Comments

@vstinner
Copy link
Member

vstinner commented Jul 4, 2017

BPO 30845
Nosy @brianquinlan, @ronaldoussoren, @vstinner, @ned-deily
PRs
  • bpo-30845: Enhance test_concurrent_futures cleanup #2564
  • [3.6] bpo-30845: Enhance test_concurrent_futures cleanup (#2564) #2880
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2017-08-11.00:00:24.028>
    created_at = <Date 2017-07-04.10:19:07.960>
    labels = ['OS-mac', 'tests']
    title = '[3.5] test_first_completed_some_already_completed() of test_concurrent_futures.ProcessPoolWaitTests: time.sleep() fails with "sleep length must be non-negative" in setUp() on x86 Tiger 3.5'
    updated_at = <Date 2017-08-11.00:19:05.794>
    user = 'https://github.com/vstinner'

    bugs.python.org fields:

    activity = <Date 2017-08-11.00:19:05.794>
    actor = 'vstinner'
    assignee = 'none'
    closed = True
    closed_date = <Date 2017-08-11.00:00:24.028>
    closer = 'vstinner'
    components = ['macOS', 'Tests']
    creation = <Date 2017-07-04.10:19:07.960>
    creator = 'vstinner'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 30845
    keywords = []
    message_count = 5.0
    messages = ['297639', '297642', '297747', '299196', '300138']
    nosy_count = 4.0
    nosy_names = ['bquinlan', 'ronaldoussoren', 'vstinner', 'ned.deily']
    pr_nums = ['2564', '2880']
    priority = 'normal'
    resolution = 'out of date'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = None
    url = 'https://bugs.python.org/issue30845'
    versions = ['Python 3.5']

    @vstinner
    Copy link
    Member Author

    vstinner commented Jul 4, 2017

    Code of the setUp() method:

    class ExecutorMixin:
        worker_count = 5
    
        def setUp(self):
            self.t1 = time.time()
            try:
                self.executor = self.executor_type(max_workers=self.worker_count)
            except NotImplementedError as e:
                self.skipTest(str(e))
            self._prime_executor()
    
        def _prime_executor(self):
            # Make sure that the executor is ready to do work before running the
            # tests. This should reduce the probability of timeouts in the tests.
            futures = [self.executor.submit(time.sleep, 0.1)
                       for _ in range(self.worker_count)]
    
            for f in futures:
                f.result()

    I don't understand how the child process can fail with ValueError("sleep length must be non-negative") when running time.sleep(0.1). Code of the sleep function:

    static PyObject *
    time_sleep(PyObject *self, PyObject *obj)
    {
        _PyTime_t secs;
        if (_PyTime_FromSecondsObject(&secs, obj, _PyTime_ROUND_CEILING))
            return NULL;
        if (secs < 0) {
            PyErr_SetString(PyExc_ValueError,
                            "sleep length must be non-negative");
            return NULL;
        }
        if (pysleep(secs) != 0)
            return NULL;
        Py_INCREF(Py_None);
        return Py_None;
    }

    Can it be a major rounding issue in time_sleep()? Or concurrent.futures failed completely to serialized the floating point number 0.1?

    http://buildbot.python.org/all/builders/x86%20Tiger%203.5/builds/324/steps/test/logs/stdio

    0:27:59 load avg: 1.54 [211/398/1] test_concurrent_futures
    test_cancel (test.test_concurrent_futures.FutureTests) ... ok
    test_cancelled (test.test_concurrent_futures.FutureTests) ... ok
    test_done (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_already_cancelled (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_already_failed (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_already_successful (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_raises (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_with_cancel (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_with_exception (test.test_concurrent_futures.FutureTests) ... ok
    test_done_callback_with_result (test.test_concurrent_futures.FutureTests) ... ok
    test_exception_with_success (test.test_concurrent_futures.FutureTests) ... ok
    test_exception_with_timeout (test.test_concurrent_futures.FutureTests) ... ok
    test_repr (test.test_concurrent_futures.FutureTests) ... ok
    test_result_with_cancel (test.test_concurrent_futures.FutureTests) ... ok
    test_result_with_success (test.test_concurrent_futures.FutureTests) ... ok
    test_result_with_timeout (test.test_concurrent_futures.FutureTests) ... ok
    test_running (test.test_concurrent_futures.FutureTests) ... ok
    test_duplicate_futures (test.test_concurrent_futures.ProcessPoolAsCompletedTests) ... 2.20s ok
    test_no_timeout (test.test_concurrent_futures.ProcessPoolAsCompletedTests) ... 0.18s ok
    test_zero_timeout (test.test_concurrent_futures.ProcessPoolAsCompletedTests) ... 2.20s ok
    test_killed_child (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.21s ok
    test_map (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.20s ok
    test_map_chunksize (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.21s ok
    test_map_exception (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.19s ok
    test_map_timeout (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 6.18s ok
    test_max_workers_negative (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.21s ok
    test_no_stale_references (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.20s ok
    test_shutdown_race_issue12456 (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.19s ok
    test_submit (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.18s ok
    test_submit_keyword (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.21s ok
    test_traceback (test.test_concurrent_futures.ProcessPoolExecutorTest) ... 0.20s ok
    test_context_manager_shutdown (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 0.10s ok
    test_del_shutdown (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 0.10s ok
    test_hang_issue12364 (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 1.09s ok
    test_interpreter_shutdown (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 2.13s ok
    test_processes_terminate (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 0.09s ok
    test_run_after_shutdown (test.test_concurrent_futures.ProcessPoolShutdownTest) ... 0.00s ok
    test_all_completed (test.test_concurrent_futures.ProcessPoolWaitTests) ... 0.20s ok
    test_first_completed (test.test_concurrent_futures.ProcessPoolWaitTests) ... 1.69s ok
    test_first_completed_some_already_completed (test.test_concurrent_futures.ProcessPoolWaitTests) ... ERROR
    test_first_exception (test.test_concurrent_futures.ProcessPoolWaitTests) ... 3.20s ok
    test_first_exception_one_already_failed (test.test_concurrent_futures.ProcessPoolWaitTests) ... 2.20s ok
    test_first_exception_some_already_complete (test.test_concurrent_futures.ProcessPoolWaitTests) ... 1.70s ok
    test_timeout (test.test_concurrent_futures.ProcessPoolWaitTests) ... 6.18s ok
    test_duplicate_futures (test.test_concurrent_futures.ThreadPoolAsCompletedTests) ... 2.11s ok
    test_no_timeout (test.test_concurrent_futures.ThreadPoolAsCompletedTests) ... 0.11s ok
    test_zero_timeout (test.test_concurrent_futures.ThreadPoolAsCompletedTests) ... 2.10s ok
    test_default_workers (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.10s ok
    test_map (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.11s ok
    test_map_exception (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.11s ok
    test_map_submits_without_iteration (test.test_concurrent_futures.ThreadPoolExecutorTest)
    Tests verifying bpo-11777. ... 0.11s ok
    test_map_timeout (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 6.10s ok
    test_max_workers_negative (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.10s ok
    test_no_stale_references (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.10s ok
    test_shutdown_race_issue12456 (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.11s ok
    test_submit (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.10s ok
    test_submit_keyword (test.test_concurrent_futures.ThreadPoolExecutorTest) ... 0.10s ok
    test_context_manager_shutdown (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 0.01s ok
    test_del_shutdown (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 0.01s ok
    test_hang_issue12364 (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 1.04s ok
    test_interpreter_shutdown (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 1.74s ok
    test_run_after_shutdown (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 0.00s ok
    test_threads_terminate (test.test_concurrent_futures.ThreadPoolShutdownTest) ... 0.00s ok
    test_all_completed (test.test_concurrent_futures.ThreadPoolWaitTests) ... 0.11s ok
    test_first_completed (test.test_concurrent_futures.ThreadPoolWaitTests) ... 1.60s ok
    test_first_completed_some_already_completed (test.test_concurrent_futures.ThreadPoolWaitTests) ... 1.60s ok
    test_first_exception (test.test_concurrent_futures.ThreadPoolWaitTests) ... 3.10s ok
    test_first_exception_one_already_failed (test.test_concurrent_futures.ThreadPoolWaitTests) ... 2.10s ok
    test_first_exception_some_already_complete (test.test_concurrent_futures.ThreadPoolWaitTests) ... 1.60s ok
    test_pending_calls_race (test.test_concurrent_futures.ThreadPoolWaitTests) ... 0.90s ok
    test_timeout (test.test_concurrent_futures.ThreadPoolWaitTests) ... 6.10s ok

    ======================================================================
    ERROR: test_first_completed_some_already_completed (test.test_concurrent_futures.ProcessPoolWaitTests)
    ----------------------------------------------------------------------

    concurrent.futures.process._RemoteTraceback: 
    """
    Traceback (most recent call last):
      File "/Users/db3l/buildarea/3.5.bolen-tiger/build/Lib/concurrent/futures/process.py", line 175, in _process_worker
        r = call_item.fn(*call_item.args, **call_item.kwargs)
    ValueError: sleep length must be non-negative
    """
    
    The above exception was the direct cause of the following exception:
    
    Traceback (most recent call last):
      File "/Users/db3l/buildarea/3.5.bolen-tiger/build/Lib/test/test_concurrent_futures.py", line 71, in setUp
        self._prime_executor()
      File "/Users/db3l/buildarea/3.5.bolen-tiger/build/Lib/test/test_concurrent_futures.py", line 87, in _prime_executor
        f.result()
      File "/Users/db3l/buildarea/3.5.bolen-tiger/build/Lib/concurrent/futures/_base.py", line 398, in result
        return self.__get_result()
      File "/Users/db3l/buildarea/3.5.bolen-tiger/build/Lib/concurrent/futures/_base.py", line 357, in __get_result
        raise self._exception
    ValueError: sleep length must be non-negative

    Ran 71 tests in 65.994s

    FAILED (errors=1)
    Warning -- multiprocessing.process._dangling was modified by test_concurrent_futures
    Before: <_weakrefset.WeakSet object at 0x1491884>
    After: <_weakrefset.WeakSet object at 0x1567f14>
    Warning -- threading._dangling was modified by test_concurrent_futures
    Before: <_weakrefset.WeakSet object at 0x149161c>
    After: <_weakrefset.WeakSet object at 0x120db24>
    test test_concurrent_futures failed

    @vstinner vstinner added OS-mac tests Tests in the Lib/test dir labels Jul 4, 2017
    @vstinner
    Copy link
    Member Author

    vstinner commented Jul 4, 2017

    New changeset 3df9dec by Victor Stinner in branch 'master':
    bpo-30845: Enhance test_concurrent_futures cleanup (bpo-2564)
    3df9dec

    @vstinner
    Copy link
    Member Author

    vstinner commented Jul 5, 2017

    New changeset 8207c17 by Victor Stinner in branch 'master':
    Revert "bpo-30822: Fix testing of datetime module." (bpo-2588)
    8207c17

    @vstinner
    Copy link
    Member Author

    New changeset a6f0452 by Victor Stinner in branch '3.6':
    bpo-30845: Enhance test_concurrent_futures cleanup (bpo-2564) (bpo-2880)
    a6f0452

    @vstinner
    Copy link
    Member Author

    Python 3.5 doesn't accept bugfixes anymore, so I close this issue.

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    OS-mac tests Tests in the Lib/test dir
    Projects
    None yet
    Development

    No branches or pull requests

    1 participant