This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: test_subprocess failure
Type: behavior Stage: needs patch
Components: Library (Lib), Tests Versions: Python 3.3
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: rnk Nosy List: pitrou, rnk, rosslagerwall
Priority: normal Keywords: buildbot

Created on 2011-03-14 17:13 by pitrou, last changed 2022-04-11 14:57 by admin. This issue is now closed.

Messages (9)
msg130859 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-03-14 17:13
http://www.python.org/dev/buildbot/all/builders/x86%20debian%20parallel%203.x/builds/1678/steps/test/logs/stdio



======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home2/buildbot2/slave/3.x.loewis-parallel/build/Lib/test/test_subprocess.py", line 133, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCasePOSIXPurePython)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home2/buildbot2/slave/3.x.loewis-parallel/build/Lib/test/test_subprocess.py", line 133, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ContextManagerTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home2/buildbot2/slave/3.x.loewis-parallel/build/Lib/test/test_subprocess.py", line 133, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'
msg130860 - (view) Author: Reid Kleckner (rnk) (Python committer) Date: 2011-03-14 17:26
I can't reproduce this.  I've tested on:
64-bit Linux (Debian lenny)
OS X 10.6
Windows Vista 32-bit

It seems reasonable to me that the interpreter should be able to
initialize and write to stdout in less than half a second, but it
seems to be failing consistently on that builder.  I'd really rather
not make the timeout longer, since it will increase testing time for
everyone.  Is there something about that builder that makes
initialization take longer?
msg130861 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-03-14 17:31
> It seems reasonable to me that the interpreter should be able to
> initialize and write to stdout in less than half a second

Well, we have some very slow buildbots and others which seem quite loaded too.
(this one should be very fast but perhaps there's some other stuff going on in the background)

In my experience such a low timeout value may be enough for light in-process stuff such as lock.acquire() or select(), but if you spawn a whole new process you should let the system breathe a bit more. I know this also unfortunately increases the test runtime, but try to bump it up to at least 1.5 seconds.
msg130868 - (view) Author: Reid Kleckner (rnk) (Python committer) Date: 2011-03-14 18:15
I increased the timeout in [fd2b3eac6756] and the buildbot is passing now:
http://python.org/dev/buildbot/all/builders/x86%20debian%20parallel%203.x
msg130929 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-03-14 23:23
There seems to be another kind, sporadic, of failure on the same buildbot:

test test_subprocess failed -- Traceback (most recent call last):
  File "/home2/buildbot2/slave/3.x.loewis-parallel/build/Lib/test/test_subprocess.py", line 626, in test_wait_timeout
    self.assertEqual(p.wait(timeout=2), 0)
  File "/home2/buildbot2/slave/3.x.loewis-parallel/build/Lib/subprocess.py", line 1489, in wait
    raise TimeoutExpired(self.args)
subprocess.TimeoutExpired: <unprintable TimeoutExpired object>

http://www.python.org/dev/buildbot/all/builders/x86%20debian%20parallel%203.x/builds/1683/steps/test/logs/stdio
msg131093 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-03-16 08:40
Other failures on the Sparc debian buildbot (which is quite slow):

======================================================================
ERROR: test_wait_timeout (test.test_subprocess.ProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 630, in test_wait_timeout
    self.assertEqual(p.wait(timeout=2), 0)
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/subprocess.py", line 1489, in wait
    raise TimeoutExpired(self.args)
subprocess.TimeoutExpired: <unprintable TimeoutExpired object>

======================================================================
ERROR: test_wait_timeout (test.test_subprocess.ProcessTestCasePOSIXPurePython)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 630, in test_wait_timeout
    self.assertEqual(p.wait(timeout=2), 0)
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/subprocess.py", line 1489, in wait
    raise TimeoutExpired(self.args)
subprocess.TimeoutExpired: <unprintable TimeoutExpired object>

======================================================================
ERROR: test_wait_timeout (test.test_subprocess.ProcessTestCaseNoPoll)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 630, in test_wait_timeout
    self.assertEqual(p.wait(timeout=2), 0)
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/subprocess.py", line 1489, in wait
    raise TimeoutExpired(self.args)
subprocess.TimeoutExpired: <unprintable TimeoutExpired object>

======================================================================
ERROR: test_wait_timeout (test.test_subprocess.ContextManagerTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 630, in test_wait_timeout
    self.assertEqual(p.wait(timeout=2), 0)
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/subprocess.py", line 1489, in wait
    raise TimeoutExpired(self.args)
subprocess.TimeoutExpired: <unprintable TimeoutExpired object>

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 135, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCasePOSIXPurePython)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 135, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ProcessTestCaseNoPoll)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 135, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'

======================================================================
FAIL: test_check_output_timeout (test.test_subprocess.ContextManagerTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/pybot/buildarea-sid/3.x.klose-debian-sparc/build/Lib/test/test_subprocess.py", line 135, in test_check_output_timeout
    self.assertEqual(c.exception.output, b'BDFL')
AssertionError: b'' != b'BDFL'


http://www.python.org/dev/buildbot/all/builders/sparc%20Debian%203.x/builds/119
msg131177 - (view) Author: Reid Kleckner (rnk) (Python committer) Date: 2011-03-16 21:15
:(  Thanks for spotting these.  Is there an easier way for me to be notified if these particular tests fail?  Some of these are not in the "stable" builder set.

Sorry to leave the builders broken for so long.  I just upped the timeouts to 3 seconds.  I guess the issue is that the builders are slow and also heavily loaded, so processes just don't get to start up as quick as we'd like them too.

It might be worth adding some plumbing to have the child process signal the parent when it's initialized, but that seems like it's going to add a whole bunch more complexity to the test.

Will close in a few days if there are no more broken buildbots.
msg131179 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-03-16 21:19
> Thanks for spotting these.  Is there an easier way for me to be
> notified if these particular tests fail?

Not really. There is no infrastructure to notify test failures to
specific e-mails depending on which test failed.

>   Some of these are not in the "stable" builder set.

Indeed, because they are not stable enough :)
But they can all be viewed here:
http://www.python.org/dev/buildbot/all/waterfall?category=3.x.stable&category=3.x.unstable
Also, you can use bbreport to get a convenient view from the command
line: http://code.google.com/p/bbreport/

Thank you!
msg137508 - (view) Author: Ross Lagerwall (rosslagerwall) (Python committer) Date: 2011-06-03 09:15
All stable buildbots appear to be green, so closing...
History
Date User Action Args
2022-04-11 14:57:14adminsetgithub: 55713
2011-06-03 09:15:25rosslagerwallsetstatus: open -> closed

nosy: + rosslagerwall
messages: + msg137508

resolution: fixed
2011-03-16 21:19:13pitrousetnosy: pitrou, rnk
messages: + msg131179
2011-03-16 21:15:52rnksetnosy: pitrou, rnk
messages: + msg131177
2011-03-16 08:40:17pitrousetnosy: pitrou, rnk
messages: + msg131093
2011-03-14 23:23:26pitrousetstatus: closed -> open
nosy: pitrou, rnk
messages: + msg130929
2011-03-14 18:15:36rnksetstatus: open -> closed
nosy: pitrou, rnk
messages: + msg130868
2011-03-14 17:31:32pitrousetnosy: pitrou, rnk
messages: + msg130861
2011-03-14 17:26:33rnksetnosy: pitrou, rnk
messages: + msg130860
2011-03-14 17:13:58pitroucreate