classification
Title: test_subprocess hangs randomly on Windows with Python 3.x
Type: Stage: resolved
Components: Tests, Windows Versions: Python 3.7
process
Status: closed Resolution: out of date
Dependencies: Superseder:
Assigned To: Nosy List: paul.moore, serhiy.storchaka, steve.dower, tim.golden, vstinner, zach.ware
Priority: normal Keywords: buildbot

Created on 2017-10-23 17:54 by vstinner, last changed 2018-05-29 21:57 by vstinner. This issue is now closed.

Messages (8)
msg304831 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-23 17:54
test_subprocess hanged on the build 46 of x86 Windows7 3.x:

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

(...)
1:29:55 [405/407] test_cmath passed -- running: test_subprocess (1249 sec)
1:29:58 [406/407] test_pstats passed -- running: test_subprocess (1252 sec)

The buildbot is slow which might have caused a timing issue.
msg305630 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-06 11:14
Sadly, the AMD64 Windows10 3.x buildbot worker is also sick:

http://buildbot.python.org/all/#/builders/3/builds/117

1:15:30 [405/407] test_urllibnet passed -- running: test_subprocess (3338 sec)
1:15:52 [406/407] test_bytes passed -- running: test_subprocess (3361 sec)
command timed out: 1200 seconds without output running ['Tools\\buildbot\\test.bat', '-x64', '-j2', '--timeout', '900'], attempting to kill
program finished with exit code 1
elapsedTime=5757.133000
msg307317 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-11-30 14:29
Bug occurred on AMD64 Windows8.1 Refleaks 3.6:

http://buildbot.python.org/all/#/builders/64/builds/52

...
running: test_subprocess (134462 sec)
running: test_subprocess (134492 sec)
running: test_subprocess (134522 sec)
running: test_subprocess (134552 sec)
running: test_subprocess (134582 sec)
running: test_subprocess (134612 sec)
running: test_subprocess (134642 sec)
program finished with exit code 1
msg308865 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-12-21 11:13
The bug still occurs randomly:

http://buildbot.python.org/all/#/builders/38/builds/122

1:34:03 [404/406] test_typing passed -- running: test_subprocess (4577 sec)
1:34:22 [405/406] test_winreg passed -- running: test_subprocess (4596 sec)
command timed out: 1200 seconds without output running ['Tools\\buildbot\\test.bat', '-x64', '-j2', '--timeout', '900'], attempting to kill
program finished with exit code 1
elapsedTime=6864.917000
msg311174 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-01-29 21:18
The test still hangs sometimes. Today on AMD64 Windows10 3.x:

http://buildbot.python.org/all/#/builders/3/builds/563

1:24:46 [409/414] test_tokenize passed (489 sec) -- running: test_subprocess (4242 sec)
1:24:50 [410/414] test_codecencodings_cn passed -- running: test_subprocess (4246 sec)
1:25:14 [411/414] test_codecmaps_kr passed -- running: test_subprocess (4270 sec)
1:25:28 [412/414] test_runpy passed -- running: test_subprocess (4284 sec)
1:25:36 [413/414] test_tempfile passed -- running: test_subprocess (4292 sec)
minkernel\crts\ucrt\src\appcrt\lowio\write.cpp(49) : Assertion failed: (_osfile(fh) & FOPEN)
command timed out: 1200 seconds without output running ['Tools\\buildbot\\test.bat', '-x64', '-j2', '--timeout', '900'], attempting to kill
program finished with exit code 1
elapsedTime=6338.784000
msg311202 - (view) Author: Steve Dower (steve.dower) * (Python committer) Date: 2018-01-30 00:09
It's an assert, so it only affects debug builds - releases are not impacted.

I'm guessing there's a test that spawns a subprocess and doesn't initialize it properly for tests (specifically the part where we disable assertions on Windows).
msg311602 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2018-02-04 15:22
When ran tests in 3.8 on Windows I got a number of dialpog windows with the following text:

---------------------------
Microsoft Visual C++ Runtime Library
---------------------------
Debug Assertion Failed!

Program: C:\py\cpython3.8\PCBuild\win32\python_d.exe
File: minkernel\crts\ucrt\src\appcrt\lowio\osfinfo.cpp
Line: 258

Expression: _osfile(fh) & FOPEN

For information on how your program can cause an assertion
failure, see the Visual C++ documentation on asserts.

(Press Retry to debug the application)

And tests are hung.

When ran tests in 3.7 on Windows I got multiple messages "minkernel\crts\ucrt\src\appcrt\lowio\write.cpp(49) : Assertion failed: (_osfile(fh) & FOPEN)" on output. This may be related.
msg318110 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-05-29 21:57
I didn't see the failure recently, I close the issue.
History
Date User Action Args
2018-05-29 21:57:42vstinnersetstatus: open -> closed
resolution: out of date
messages: + msg318110

stage: resolved
2018-02-04 15:22:17serhiy.storchakasetnosy: + serhiy.storchaka
messages: + msg311602
2018-01-30 00:09:27steve.dowersetmessages: + msg311202
2018-01-29 21:18:19vstinnersetmessages: + msg311174
2017-12-21 11:13:22vstinnersetmessages: + msg308865
2017-11-30 14:29:09vstinnersetmessages: + msg307317
2017-11-06 11:14:06vstinnersettitle: test_subprocess hangs randomly on x86 Windows7 3.x -> test_subprocess hangs randomly on Windows with Python 3.x
nosy: + paul.moore, tim.golden, zach.ware, steve.dower

messages: + msg305630

components: + Windows
2017-10-23 17:54:49vstinnercreate