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

Miss Islington (bot) webhook-mailer at python.org
Wed Sep 11 06:05:18 EDT 2019


https://github.com/python/cpython/commit/872c85a1796290baef89a20dbde819c4da45830c
commit: 872c85a1796290baef89a20dbde819c4da45830c
branch: 3.8
author: Miss Islington (bot) <31488909+miss-islington at users.noreply.github.com>
committer: GitHub <noreply at github.com>
date: 2019-09-11T03:05:14-07:00
summary:

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.
(cherry picked from commit 580d2782f70f8e0bed7ec20abb03d740cb83b5da)

Co-authored-by: Gregory P. Smith <greg at krypto.org>

files:
A Misc/NEWS.d/next/Library/2019-07-04-13-00-20.bpo-37424.0i1MR-.rst
M Lib/subprocess.py
M Lib/test/test_subprocess.py

diff --git a/Lib/subprocess.py b/Lib/subprocess.py
index aed7292541e0..85b9ea078546 100644
--- a/Lib/subprocess.py
+++ b/Lib/subprocess.py
@@ -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.
@@ -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):
@@ -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!
diff --git a/Lib/test/test_subprocess.py b/Lib/test/test_subprocess.py
index e58d0925df3b..69ac584667d3 100644
--- a/Lib/test/test_subprocess.py
+++ b/Lib/test/test_subprocess.py
@@ -10,6 +10,7 @@
 import errno
 import tempfile
 import time
+import traceback
 import selectors
 import sysconfig
 import select
@@ -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):
diff --git a/Misc/NEWS.d/next/Library/2019-07-04-13-00-20.bpo-37424.0i1MR-.rst b/Misc/NEWS.d/next/Library/2019-07-04-13-00-20.bpo-37424.0i1MR-.rst
new file mode 100644
index 000000000000..b98a17e241e0
--- /dev/null
+++ b/Misc/NEWS.d/next/Library/2019-07-04-13-00-20.bpo-37424.0i1MR-.rst
@@ -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.



More information about the Python-checkins mailing list