classification
Title: subprocess.run timeout does not function if shell=True and capture_output=True
Type: behavior Stage: commit review
Components: Library (Lib) Versions: Python 3.7
process
Status: closed Resolution: fixed
Dependencies: Superseder: subprocess.run with stderr connected to a pipe won't timeout when killing a never-ending shell commanad
View: 30154
Assigned To: gregory.p.smith Nosy List: gregory.p.smith, haizaar, martin.panter, miss-islington, twouters, vstinner, xtreak
Priority: normal Keywords: patch

Created on 2019-06-27 06:59 by haizaar, last changed 2019-09-17 23:40 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 14490 merged gregory.p.smith, 2019-07-01 00:03
PR 15897 merged miss-islington, 2019-09-11 09:23
PR 15898 merged miss-islington, 2019-09-11 09:23
Messages (11)
msg346712 - (view) Author: haizaar (haizaar) Date: 2019-06-27 06:59
Consider the following:

subprocess.run('sleep 10', shell=True, timeout=.1, capture_output=True)

It should raise after 0.1 seconds, but it does not - it waits 10 seconds till sleep finishes and only then raises "subprocess.TimeoutExpired: Command 'sleep 10' timed out after 0.1 seconds"

Removing 'capture_output=True' or converting command string to list (and removing shell=True) makes it work.

I'm using Python 3.7.3 on Ubuntu 16.04. Reproduces on official docker Python 3.7.3 image alpine3.8.
msg346714 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python triager) Date: 2019-06-27 07:17
On mac this exits immediately with 0.1 seconds as timeout but reproducible on Ubuntu with master.
msg346718 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2019-06-27 08:37
Same thing going on as in Issue 30154. The shell is probably spawning the “sleep” command as a child process (grandchild of Python), and waiting for it to exit. When Python times out, it will kill the shell process, leaving the grandchild as an orphan. The “sleep” process will still be running and probably holds the “stdout” and/or “stderr” pipes open, and Python will wait indefinitely to be sure it has captured all the output to those pipes.

Also see Issue 26534 proposes APIs to kill a process group rather than the single child process.
msg346735 - (view) Author: haizaar (haizaar) Date: 2019-06-27 13:11
Thanks for looking at it.

My original code had "tar" running, which is a child of the shell as well... I assume running exec in the shell may help somewhat, but not a cure obviously.

I'm all for killing the process group. "Run something and get it's about" should be simple enough without requiring a programmer to know all POSIX process semantics.
msg346948 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2019-07-01 00:09
Issue 30154 that I've marked as a duplicate demonstrates this problem without using shell=True.  The solution I proposed handles that via the additional small timeout on the cleanup side, but still has the caveat that the grandchild processes keep running unless the caller used start_new_session=True.

See the PR.

We cannot reasonably determine when start_new_session=True should be a default behavior.  And I worry that doing it when it should not be will cause unexpected new problems with existing code.
msg351775 - (view) Author: Thomas Wouters (twouters) * (Python committer) Date: 2019-09-11 09:23
New changeset 580d2782f70f8e0bed7ec20abb03d740cb83b5da by T. Wouters (Gregory P. Smith) in branch 'master':
bpo-37424: Avoid a hang in subprocess.run timeout output capture (GH-14490)
https://github.com/python/cpython/commit/580d2782f70f8e0bed7ec20abb03d740cb83b5da
msg351792 - (view) Author: miss-islington (miss-islington) Date: 2019-09-11 10:05
New changeset 872c85a1796290baef89a20dbde819c4da45830c by Miss Islington (bot) in branch '3.8':
bpo-37424: Avoid a hang in subprocess.run timeout output capture (GH-14490)
https://github.com/python/cpython/commit/872c85a1796290baef89a20dbde819c4da45830c
msg351793 - (view) Author: miss-islington (miss-islington) Date: 2019-09-11 10:06
New changeset 5fe153c21de020f37712910b0dcce93341bba272 by Miss Islington (bot) in branch '3.7':
bpo-37424: Avoid a hang in subprocess.run timeout output capture (GH-14490)
https://github.com/python/cpython/commit/5fe153c21de020f37712910b0dcce93341bba272
msg351813 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-11 10:55
On Windows, the following pattern _can_ hang:

proc = subprocess.Popen(cmd, stdout=subprocess.PIPE)
try:
  return proc.communicate(timeout=1.0)
except TimeoutExpired:
  proc.kill()
  return proc.communicate() # <== HERE

Even if the first child process is killed, communicate() waits until the pipe is closed. If the child process spawned a 3rd process before being killed, the second .communicate() calls hangs until the 3rd process exit or close its stdout.

I'm not sure if subprocess.run() should do anything about this case, but it was at least for your information.

I'm fighting against this issue in bpo-37531.

IMHO it's an issue of the Windows implementation of Popen.communicate(): it's implemented with a blocking call to stdout.read() run in a thread. The thread cannot be interrupted in any way and will until complete once stdout is closed.

Again, if the direct child process spawned other processes, stdout is only closed in the main parent process once all child processes exit or at least closed their stdout.

Maybe another issue should be opened to avoid blocking with the following pattern on Windows:

proc.kill()
proc.communicate()
msg351912 - (view) Author: Gregory P. Smith (gregory.p.smith) * (Python committer) Date: 2019-09-11 14:42
Thanks.  I believe this issue is fixed but you've identified follow-on issues.  lets follow up on those in their own bugs.
msg352677 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-17 23:40
> On Windows, the following pattern _can_ hang: (...)

I created bpo-38207 "subprocess: On Windows, Popen.kill() + Popen.communicate() is blocking until all processes using the pipe close the pipe" to track this issue.
History
Date User Action Args
2019-09-17 23:40:17vstinnersetmessages: + msg352677
2019-09-11 14:42:27gregory.p.smithsetstatus: open -> closed
resolution: fixed
messages: + msg351912

stage: patch review -> commit review
2019-09-11 10:55:18vstinnersetnosy: + vstinner
messages: + msg351813
2019-09-11 10:06:00miss-islingtonsetmessages: + msg351793
2019-09-11 10:05:17miss-islingtonsetnosy: + miss-islington
messages: + msg351792
2019-09-11 09:23:25miss-islingtonsetpull_requests: + pull_request15539
2019-09-11 09:23:18miss-islingtonsetkeywords: + patch
stage: patch review
pull_requests: + pull_request15538
2019-09-11 09:23:08twouterssetnosy: + twouters
messages: + msg351775
2019-07-04 19:57:28gregory.p.smithsetstage: resolved -> (no value)
2019-07-04 19:57:22gregory.p.smithsetstatus: closed -> open
assignee: gregory.p.smith
resolution: duplicate -> (no value)
2019-07-01 00:09:59gregory.p.smithsetmessages: + msg346948
2019-07-01 00:07:00gregory.p.smithlinkissue30154 superseder
2019-07-01 00:06:43gregory.p.smithlinkissue26534 superseder
2019-07-01 00:04:26gregory.p.smithlinkissue5115 superseder
2019-07-01 00:03:26gregory.p.smithsetpull_requests: + pull_request14307
2019-06-27 13:11:23haizaarsetmessages: + msg346735
2019-06-27 08:37:07martin.pantersetstatus: open -> closed

superseder: subprocess.run with stderr connected to a pipe won't timeout when killing a never-ending shell commanad

nosy: + martin.panter
messages: + msg346718
resolution: duplicate
stage: resolved
2019-06-27 07:17:18xtreaksetnosy: + gregory.p.smith, xtreak
messages: + msg346714
2019-06-27 06:59:50haizaarcreate