Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[3.8] bpo-37424: Avoid a hang in subprocess.run timeout output capture (GH-14490) #15897

Merged
merged 1 commit into from
Sep 11, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 27 additions & 9 deletions Lib/subprocess.py
Original file line number Diff line number Diff line change
Expand Up @@ -489,11 +489,20 @@ def run(*popenargs,
with Popen(*popenargs, **kwargs) as process:
try:
stdout, stderr = process.communicate(input, timeout=timeout)
except TimeoutExpired:
except TimeoutExpired as exc:
process.kill()
stdout, stderr = process.communicate()
raise TimeoutExpired(process.args, timeout, output=stdout,
stderr=stderr)
if _mswindows:
# Windows accumulates the output in a single blocking
# read() call run on child threads, with the timeout
# being done in a join() on those threads. communicate()
# _after_ kill() is required to collect that and add it
# to the exception.
exc.stdout, exc.stderr = process.communicate()
else:
# POSIX _communicate already populated the output so
# far into the TimeoutExpired exception.
process.wait()
raise
except: # Including KeyboardInterrupt, communicate handled that.
process.kill()
# We don't call process.wait() as .__exit__ does that for us.
Expand Down Expand Up @@ -1050,12 +1059,16 @@ def _remaining_time(self, endtime):
return endtime - _time()


def _check_timeout(self, endtime, orig_timeout):
def _check_timeout(self, endtime, orig_timeout, stdout_seq, stderr_seq,
skip_check_and_raise=False):
"""Convenience for checking if a timeout has expired."""
if endtime is None:
return
if _time() > endtime:
raise TimeoutExpired(self.args, orig_timeout)
if skip_check_and_raise or _time() > endtime:
raise TimeoutExpired(
self.args, orig_timeout,
output=b''.join(stdout_seq) if stdout_seq else None,
stderr=b''.join(stderr_seq) if stderr_seq else None)


def wait(self, timeout=None):
Expand Down Expand Up @@ -1843,10 +1856,15 @@ def _communicate(self, input, endtime, orig_timeout):
while selector.get_map():
timeout = self._remaining_time(endtime)
if timeout is not None and timeout < 0:
raise TimeoutExpired(self.args, orig_timeout)
self._check_timeout(endtime, orig_timeout,
stdout, stderr,
skip_check_and_raise=True)
raise RuntimeError( # Impossible :)
'_check_timeout(..., skip_check_and_raise=True) '
'failed to raise TimeoutExpired.')

ready = selector.select(timeout)
self._check_timeout(endtime, orig_timeout)
self._check_timeout(endtime, orig_timeout, stdout, stderr)

# XXX Rewrite these to use non-blocking I/O on the file
# objects; they are no longer using C stdio!
Expand Down
21 changes: 21 additions & 0 deletions Lib/test/test_subprocess.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
import errno
import tempfile
import time
import traceback
import selectors
import sysconfig
import select
Expand Down Expand Up @@ -1557,6 +1558,26 @@ def test_stderr_with_capture_output_arg(self):
self.assertIn('stderr', c.exception.args[0])
self.assertIn('capture_output', c.exception.args[0])

# This test _might_ wind up a bit fragile on loaded build+test machines
# as it depends on the timing with wide enough margins for normal situations
# but does assert that it happened "soon enough" to believe the right thing
# happened.
@unittest.skipIf(mswindows, "requires posix like 'sleep' shell command")
def test_run_with_shell_timeout_and_capture_output(self):
"""Output capturing after a timeout mustn't hang forever on open filehandles."""
before_secs = time.monotonic()
try:
subprocess.run('sleep 3', shell=True, timeout=0.1,
capture_output=True) # New session unspecified.
except subprocess.TimeoutExpired as exc:
after_secs = time.monotonic()
stacks = traceback.format_exc() # assertRaises doesn't give this.
else:
self.fail("TimeoutExpired not raised.")
self.assertLess(after_secs - before_secs, 1.5,
msg="TimeoutExpired was delayed! Bad traceback:\n```\n"
f"{stacks}```")


@unittest.skipIf(mswindows, "POSIX specific tests")
class POSIXProcessTestCase(BaseTestCase):
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
Fixes a possible hang when using a timeout on `subprocess.run()` while
capturing output. If the child process spawned its own children or
otherwise connected its stdout or stderr handles with another process, we
could hang after the timeout was reached and our child was killed when
attempting to read final output from the pipes.