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

Created on 2017-05-11 00:48 by vstinner, last changed 2017-11-09 09:56 by vstinner.

Pull Requests
URL Status Linked Edit
PR 1593 merged vstinner, 2017-05-15 15:53
PR 1978 open jkloth, 2017-06-06 23:15
Messages (11)
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
---
History
Date User Action Args
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