classification
Title: test_multiprocessing_main_handling: "RuntimeError: Timed out waiting for results" on x86 Windows7 3.x
Type: Stage: resolved
Components: Tests, Windows Versions: Python 3.7, Python 3.6, Python 3.5
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: davin, jkloth, matrixise, miss-islington, paul.moore, steve.dower, tim.golden, vstinner, zach.ware
Priority: normal Keywords: patch

Created on 2017-05-11 00:48 by vstinner, last changed 2018-06-27 21:40 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 1593 merged vstinner, 2017-05-15 15:53
PR 1978 closed jkloth, 2017-06-06 23:15
PR 7972 merged vstinner, 2018-06-27 16:42
PR 7973 merged miss-islington, 2018-06-27 20:23
PR 7976 merged vstinner, 2018-06-27 20:29
Messages (16)
msg293470 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-11 00:48
http://buildbot.python.org/all/builders/x86%20Windows7%203.x/builds/597/steps/test/logs/stdio

0:26:29 [156/405/1] test_multiprocessing_main_handling failed
...
test_zipfile_compiled (test.test_multiprocessing_main_handling.ForkServerCmdLineTest) ... skipped "'forkserver' start method not available"
test_basic_script (test.test_multiprocessing_main_handling.SpawnCmdLineTest) ... ok
test_basic_script_no_suffix (test.test_multiprocessing_main_handling.SpawnCmdLineTest) ... FAIL
test_directory (test.test_multiprocessing_main_handling.SpawnCmdLineTest) ... ok
test_directory_compiled (test.test_multiprocessing_main_handling.SpawnCmdLineTest) ... ok
test_ipython_workaround (test.test_multiprocessing_main_handling.SpawnCmdLineTest) ... ok
...

======================================================================
FAIL: test_basic_script_no_suffix (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\test_multiprocessing_main_handling.py", line 169, in test_basic_script_no_suffix
    self._check_script(script_name)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\test_multiprocessing_main_handling.py", line 157, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\support\script_helper.py", line 147, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\support\script_helper.py", line 133, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['D:\\cygwin\\home\\db3l\\buildarea\\3.x.bolen-windows7\\build\\PCbuild\\win32\\python_d.exe', '-X', 'faulthandler', '-E', 'd:\\temp\\tmp3iu335w1\\script', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):

  File "d:\temp\tmp3iu335w1\script", line 34, in <module>

    raise RuntimeError("Timed out waiting for results")

RuntimeError: Timed out waiting for results
---

----------------------------------------------------------------------
Ran 39 tests in 81.399s

FAILED (failures=1, skipped=26)
test test_multiprocessing_main_handling failed
msg293720 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-15 16:14
New changeset 7d6320ba47a229543acc0af6a64bc4e414932273 by Victor Stinner in branch 'master':
bpo-30339: test_multiprocessing_main_handling timeout (#1593)
https://github.com/python/cpython/commit/7d6320ba47a229543acc0af6a64bc4e414932273
msg293807 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-16 22:15
> New changeset 7d6320ba47a229543acc0af6a64bc4e414932273 by Victor Stinner in branch 'master':
> bpo-30339: test_multiprocessing_main_handling timeout (#1593)
> https://github.com/python/cpython/commit/7d6320ba47a229543acc0af6a64bc4e414932273

Sadly, a new build failed at commit fca224f117d25bdfec1bf7160b67438c4fcf6dee, so with the new timeout of 60 seconds:
http://buildbot.python.org/all/builders/x86%20Windows7%203.x/builds/619/steps/test/logs/stdio
msg293904 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-17 23:05
Another failure on AMD64 Windows7 SP1 3.5:
http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.5/builds/145/steps/test/logs/stdio

======================================================================
FAIL: test_directory (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 197, in test_directory
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmpld1_lj4t', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Users\Buildbot\AppData\Local\Temp\tmpld1_lj4t\__main__.py", line 23, in <module>
    raise RuntimeError("Timed out waiting for results")
RuntimeError: Timed out waiting for results
---
msg294167 - (view) Author: Davin Potts (davin) * (Python committer) Date: 2017-05-22 18:10
Patch on issue30317 also addresses this issue in a more flexible way.
msg294950 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-06-01 15:00
New failure:

http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.5/builds/161/steps/test/logs/stdio


======================================================================
FAIL: test_directory (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 197, in test_directory
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmpa4gpo3nq', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Users\Buildbot\AppData\Local\Temp\tmpa4gpo3nq\__main__.py", line 23, in <module>
    raise RuntimeError("Timed out waiting for results")
RuntimeError: Timed out waiting for results
---
msg295310 - (view) Author: Jeremy Kloth (jkloth) * Date: 2017-06-06 23:21
Added PR1978 that resolves this issue on my buildbot at least.  Note that it is against 3.5 as that is the branch that has the issue, it seems.

I'm guessing improvements in startup time on newer Pythons is why it doesn't occur for them.
msg296313 - (view) Author: Jeremy Kloth (jkloth) * Date: 2017-06-19 11:44
Following up as the last run on my 3.5 buildslave:
  http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.5/builds/198
had the timeout again.  It is running at a 50% success rate with the only fault being warnings/errors due to this test.
msg296954 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-06-26 21:56
Similar but difference issue.

http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.5/builds/215/steps/test/logs/stdio

======================================================================
FAIL: test_directory_compiled (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 207, in test_directory_compiled
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmp47s9eead', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):

  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main

    "__main__", mod_spec)

  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code

    exec(code, run_globals)

  File "C:\Users\Buildbot\AppData\Local\Temp\tmp47s9eead\__main__.py", line 23, in <module>

RuntimeError: Timed out waiting for results
---


Second run:


======================================================================
FAIL: test_directory (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 197, in test_directory
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmp3hfxysdu', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Users\Buildbot\AppData\Local\Temp\tmp3hfxysdu\__main__.py", line 23, in <module>
    raise RuntimeError("Timed out waiting for results")
RuntimeError: Timed out waiting for results
---

======================================================================
FAIL: test_directory_compiled (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 207, in test_directory_compiled
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmpvez1m7b1', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Users\Buildbot\AppData\Local\Temp\tmpvez1m7b1\__main__.py", line 23, in <module>
RuntimeError: Timed out waiting for results
---
msg297818 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-07-06 08:53
http://buildbot.python.org/all/builders/AMD64%20Windows7%20SP1%203.5/builds/229/steps/test/logs/stdio


======================================================================
FAIL: test_directory (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 197, in test_directory
    self._check_script(script_dir)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\test_multiprocessing_main_handling.py", line 155, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 150, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\test\support\script_helper.py", line 136, in _assert_python
    err))
AssertionError: Process return code is 1
command line: ['C:\\buildbot.python.org\\3.5.kloth-win64\\build\\PCbuild\\amd64\\python_d.exe', '-X', 'faulthandler', '-E', 'C:\\Users\\Buildbot\\AppData\\Local\\Temp\\tmp7w5hs4kq', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "C:\buildbot.python.org\3.5.kloth-win64\build\lib\runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "C:\Users\Buildbot\AppData\Local\Temp\tmp7w5hs4kq\__main__.py", line 23, in <module>
    raise RuntimeError("Timed out waiting for results")
RuntimeError: Timed out waiting for results
---
msg305947 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-09 09:56
Yet another similar bug on "x86 Windows7 3.x":

http://buildbot.python.org/all/#/builders/58/builds/134

======================================================================
FAIL: test_ipython_workaround (test.test_multiprocessing_main_handling.SpawnCmdLineTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\test_multiprocessing_main_handling.py", line 179, in test_ipython_workaround
    self._check_script(script_name)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\test_multiprocessing_main_handling.py", line 156, in _check_script
    rc, out, err = assert_python_ok(*run_args, __isolated=False)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\support\script_helper.py", line 151, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\support\script_helper.py", line 137, in _assert_python
    res.fail(cmd_line)
  File "D:\cygwin\home\db3l\buildarea\3.x.bolen-windows7\build\lib\test\support\script_helper.py", line 79, in fail
    err))
AssertionError: Process return code is 1
command line: ['D:\\cygwin\\home\\db3l\\buildarea\\3.x.bolen-windows7\\build\\PCbuild\\win32\\python_d.exe', '-X', 'faulthandler', '-E', 'd:\\temp\\tmponku8v2m\\ipython.py', 'spawn']

stdout:
---

---

stderr:
---
Traceback (most recent call last):

  File "d:\temp\tmponku8v2m\ipython.py", line 23, in <module>

    raise RuntimeError("Timed out waiting for results")

RuntimeError: Timed out waiting for results
---
msg311671 - (view) Author: Stéphane Wirtel (matrixise) * (Python triager) Date: 2018-02-05 15:28
TLDR; but there is a new status for the associated PR https://github.com/python/cpython/pull/1978
msg320608 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-06-27 20:21
New changeset 64737e9ae2081e529935ecf07f44e89f362d1c4b by Victor Stinner in branch 'master':
bpo-33913: Fix test_multiprocessing_main_handling (GH-7972)
https://github.com/python/cpython/commit/64737e9ae2081e529935ecf07f44e89f362d1c4b
msg320619 - (view) Author: miss-islington (miss-islington) Date: 2018-06-27 20:41
New changeset 4b1d286ac06f32a5857af1b3141dd4127744b15b by Miss Islington (bot) in branch '3.7':
bpo-33913: Fix test_multiprocessing_main_handling (GH-7972)
https://github.com/python/cpython/commit/4b1d286ac06f32a5857af1b3141dd4127744b15b
msg320622 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-06-27 21:14
New changeset 1d06be8cc55715be8c32ec3b462adfb3a7839dfe by Victor Stinner in branch '3.6':
bpo-33913: Fix test_multiprocessing_main_handling (GH-7972) (GH-7976)
https://github.com/python/cpython/commit/1d06be8cc55715be8c32ec3b462adfb3a7839dfe
msg320629 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-06-27 21:40
I increased timeout from 10 seconds to 1 minute in test_multiprocessing_main_handling, in 3.6, 3.7 and master branches. It should make test failures less likely on buildbots.
History
Date User Action Args
2018-06-27 21:40:46vstinnersetstatus: open -> closed
messages: + msg320629

dependencies: - test_timeout() of test_multiprocessing_spawn.WithManagerTestBarrier fails randomly on x86 Windows7 3.x buildbot
resolution: fixed
stage: patch review -> resolved
2018-06-27 21:14:56vstinnersetmessages: + msg320622
2018-06-27 20:41:41miss-islingtonsetnosy: + miss-islington
messages: + msg320619
2018-06-27 20:29:48vstinnersetpull_requests: + pull_request7587
2018-06-27 20:23:21miss-islingtonsetpull_requests: + pull_request7583
2018-06-27 20:21:55vstinnersetmessages: + msg320608
2018-06-27 16:42:55vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request7581
2018-02-05 15:28:22matrixisesetnosy: + matrixise
messages: + msg311671
2017-11-09 09:56:53vstinnersetmessages: + msg305947
2017-07-06 08:53:42vstinnersetmessages: + msg297818
2017-06-26 21:56:07vstinnersetmessages: + msg296954
2017-06-19 11:44:15jklothsetmessages: + msg296313
2017-06-06 23:21:01jklothsetmessages: + msg295310
2017-06-06 23:15:31jklothsetpull_requests: + pull_request2044
2017-06-01 15:00:29vstinnersetmessages: + msg294950
2017-05-22 18:10:13davinsetnosy: + davin
dependencies: + test_timeout() of test_multiprocessing_spawn.WithManagerTestBarrier fails randomly on x86 Windows7 3.x buildbot
messages: + msg294167
2017-05-17 23:20:48jklothsetnosy: + jkloth
2017-05-17 23:05:27vstinnersetmessages: + msg293904
versions: + Python 3.5, Python 3.6
2017-05-16 22:15:24vstinnersetmessages: + msg293807
2017-05-15 16:14:45vstinnersetmessages: + msg293720
2017-05-15 15:53:08vstinnersetpull_requests: + pull_request1687
2017-05-11 00:48:18vstinnercreate