bpo-37424: Avoid a hang in subprocess.run timeout output capture (GH-14490)

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.
This commit is contained in:
Gregory P. Smith 2019-09-11 04:23:05 -05:00 committed by T. Wouters
parent 3fb1363fe8
commit 580d2782f7
3 changed files with 53 additions and 9 deletions

View File

@ -489,11 +489,20 @@ def run(*popenargs,
with Popen(*popenargs, **kwargs) as process: with Popen(*popenargs, **kwargs) as process:
try: try:
stdout, stderr = process.communicate(input, timeout=timeout) stdout, stderr = process.communicate(input, timeout=timeout)
except TimeoutExpired: except TimeoutExpired as exc:
process.kill() process.kill()
stdout, stderr = process.communicate() if _mswindows:
raise TimeoutExpired(process.args, timeout, output=stdout, # Windows accumulates the output in a single blocking
stderr=stderr) # 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. except: # Including KeyboardInterrupt, communicate handled that.
process.kill() process.kill()
# We don't call process.wait() as .__exit__ does that for us. # We don't call process.wait() as .__exit__ does that for us.
@ -1050,12 +1059,16 @@ class Popen(object):
return endtime - _time() 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.""" """Convenience for checking if a timeout has expired."""
if endtime is None: if endtime is None:
return return
if _time() > endtime: if skip_check_and_raise or _time() > endtime:
raise TimeoutExpired(self.args, orig_timeout) 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): def wait(self, timeout=None):
@ -1843,10 +1856,15 @@ class Popen(object):
while selector.get_map(): while selector.get_map():
timeout = self._remaining_time(endtime) timeout = self._remaining_time(endtime)
if timeout is not None and timeout < 0: 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) 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 # XXX Rewrite these to use non-blocking I/O on the file
# objects; they are no longer using C stdio! # objects; they are no longer using C stdio!

View File

@ -10,6 +10,7 @@ import os
import errno import errno
import tempfile import tempfile
import time import time
import traceback
import selectors import selectors
import sysconfig import sysconfig
import select import select
@ -1557,6 +1558,26 @@ class RunFuncTestCase(BaseTestCase):
self.assertIn('stderr', c.exception.args[0]) self.assertIn('stderr', c.exception.args[0])
self.assertIn('capture_output', 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") @unittest.skipIf(mswindows, "POSIX specific tests")
class POSIXProcessTestCase(BaseTestCase): class POSIXProcessTestCase(BaseTestCase):

View File

@ -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.