classification
Title: test_subprocess: sporadic failure of test_communicate_epipe() on Windows 8
Type: Stage:
Components: Tests, Windows Versions: Python 3.4, Python 3.3, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: gvanrossum, haypo, neologix, pitrou, python-dev, tim.golden
Priority: normal Keywords: buildbot, patch

Created on 2013-11-15 16:29 by haypo, last changed 2014-07-28 22:10 by haypo. This issue is now closed.

Files
File name Uploaded Description Edit
communicate_epipe.patch haypo, 2014-02-18 09:40 review
Messages (11)
msg202959 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2013-11-15 16:29
The test failed on a buildbot, see the message below. By the way, the test should use a value based on test.support.PIPE_MAX_SIZE rather than an hardcoded size of 2**20 bytes.


http://buildbot.python.org/all/builders/x86%20Windows%20Server%202008%20%5BSB%5D%203.x/builds/1661/steps/test/logs/stdio

test_communicate_epipe (test.test_subprocess.ProcessTestCase) ... ERROR
test_communicate_epipe_only_stdin (test.test_subprocess.ProcessTestCase) ... ok


======================================================================
ERROR: test_communicate_epipe (test.test_subprocess.ProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\test\test_subprocess.py", line 1095, in test_communicate_epipe
    p.communicate(b"x" * 2**20)
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\subprocess.py", line 952, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\subprocess.py", line 1188, in _communicate
    self.stdin.write(input)
OSError: [Errno 22] Invalid argument

----------------------------------------------------------------------
(...)
test_communicate_epipe (test.test_subprocess.ProcessTestCase) ... ok
test_communicate_epipe_only_stdin (test.test_subprocess.ProcessTestCase) ... ok
msg204259 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2013-11-24 19:18
I don't know much about subprocess.py and I don't have access to Windows 8.  But it looks like the kind of thing that might happen if the other end of the "pipe" is closed, which might happen if the subprocess exits early, either because it's just fast or because it's encountered some other bug.
msg211501 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-18 09:40
If I add a sleep of 1 second before stdin.write(), the test always fail with OSError(22, "Invalid parameter"). So it becomes obvious that the write fails if the process already exited.

Attached patch should fix the issue. Can someone review it?

The test fails also on Python 3.3.
msg211519 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2014-02-18 16:14
LGTM. Please commit in both repos and add to the list of cherrypicks for
Larry.

On Tue, Feb 18, 2014 at 1:40 AM, STINNER Victor <report@bugs.python.org>wrote:

>
> STINNER Victor added the comment:
>
> If I add a sleep of 1 second before stdin.write(), the test always fail
> with OSError(22, "Invalid parameter"). So it becomes obvious that the write
> fails if the process already exited.
>
> Attached patch should fix the issue. Can someone review it?
>
> The test fails also on Python 3.3.
>
> ----------
> keywords: +patch
> versions: +Python 3.3
> Added file: http://bugs.python.org/file34131/communicate_epipe.patch
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue19612>
> _______________________________________
>
msg211557 - (view) Author: Roundup Robot (python-dev) Date: 2014-02-18 21:08
New changeset 83013a7be836 by Victor Stinner in branch '3.3':
Issue #19612: On Windows, subprocess.Popen.communicate() now ignores
http://hg.python.org/cpython/rev/83013a7be836

New changeset 423cb79640eb by Victor Stinner in branch 'default':
(Merge 3.3) Issue #19612: On Windows, subprocess.Popen.communicate() now
http://hg.python.org/cpython/rev/423cb79640eb
msg211558 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-18 21:10
> LGTM.

Thanks for the review.

> Please commit in both repos and add to the list of cherrypicks for
Larry.

Both repos? You mean Tulip? This issue is specific to subprocess not asyncio (asyncio.subprocess).

This sporadic bug is not new. IMO it exists since Python 3.3.

I'm not sure that it's need to hurry to fix it in Python 3.4.0.
msg211563 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2014-02-18 22:03
Sorry, forget everything I said. (That includes the LGTM, sadly -- as I wrote earlier I don't know this code very well.)
msg211565 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-02-18 22:53
> Sorry, forget everything I said. (That includes the LGTM, sadly -- as I wrote earlier I don't know this code very well.)

Don't worry, I'm confident in my change :)
msg212748 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-03-04 23:15
Oh, it looks like my patch is not enough: the test still fails sometimes :-/ It looks like the process was still running (poll() didn't return None) whereas stdin.write() got an OSError(errno.EINVAL).

http://buildbot.python.org/all/builders/x86%20Windows%20Server%202008%20%5BSB%5D%203.x/builds/2408/steps/test/logs/stdio

======================================================================
ERROR: test_communicate_epipe (test.test_subprocess.ProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\test\test_subprocess.py", line 1095, in test_communicate_epipe
    p.communicate(b"x" * 2**20)
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\subprocess.py", line 951, in communicate
    stdout, stderr = self._communicate(input, endtime, timeout)
  File "E:\home\cpython\buildslave\x86\3.x.snakebite-win2k8r2sp1-x86\build\lib\subprocess.py", line 1187, in _communicate
    self.stdin.write(input)
OSError: [Errno 22] Invalid argument
msg224196 - (view) Author: Roundup Robot (python-dev) Date: 2014-07-28 22:07
New changeset 039ac3f01c4e by Victor Stinner in branch '2.7':
Issue #19612: subprocess.communicate() now also ignores EINVAL when using at
http://hg.python.org/cpython/rev/039ac3f01c4e
msg224198 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-07-28 22:10
I didnd't see the failure recently on Windows, so I close the issue.

I backported the fix on Python 2.7 for the issue #21946.
History
Date User Action Args
2014-07-28 22:10:58hayposetstatus: open -> closed
resolution: fixed
messages: + msg224198

versions: + Python 2.7
2014-07-28 22:07:12python-devsetmessages: + msg224196
2014-03-04 23:15:07hayposetmessages: + msg212748
2014-02-18 22:53:45hayposetmessages: + msg211565
2014-02-18 22:03:55gvanrossumsetmessages: + msg211563
2014-02-18 21:10:43hayposetmessages: + msg211558
2014-02-18 21:08:13python-devsetnosy: + python-dev
messages: + msg211557
2014-02-18 16:14:57gvanrossumsetmessages: + msg211519
2014-02-18 09:40:41hayposetfiles: + communicate_epipe.patch
keywords: + patch
messages: + msg211501

versions: + Python 3.3
2013-11-24 19:18:57gvanrossumsetnosy: gvanrossum, pitrou, haypo, tim.golden, neologix
messages: + msg204259
2013-11-24 12:33:24hayposetnosy: + gvanrossum, pitrou, tim.golden, neologix
2013-11-24 12:32:54hayposettitle: test_subprocess: sporadic failure of test_communicate_epipe() -> test_subprocess: sporadic failure of test_communicate_epipe() on Windows 8
2013-11-15 16:29:59haypocreate