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

subprocess's Popen closes stdout/stderr filedescriptors used in another thread when Popen errors #63051

Closed
janwijbrand mannequin opened this issue Aug 27, 2013 · 16 comments
Labels
stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error

Comments

@janwijbrand
Copy link
Mannequin

janwijbrand mannequin commented Aug 27, 2013

BPO 18851
Nosy @gpshead, @pitrou
Files
  • subprocess_issue18851.patch
  • subprocess_issue18851_2.patch
  • subprocess_issue18851_3.patch
  • subprocess_issue18851_3.patch
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2013-08-30.22:13:48.780>
    created_at = <Date 2013-08-27.12:06:55.796>
    labels = ['type-bug', 'library']
    title = "subprocess's Popen closes stdout/stderr filedescriptors used in another thread when Popen errors"
    updated_at = <Date 2013-09-03.09:22:31.954>
    user = 'https://bugs.python.org/janwijbrand'

    bugs.python.org fields:

    activity = <Date 2013-09-03.09:22:31.954>
    actor = 'janwijbrand'
    assignee = 'none'
    closed = True
    closed_date = <Date 2013-08-30.22:13:48.780>
    closer = 'pitrou'
    components = ['Library (Lib)']
    creation = <Date 2013-08-27.12:06:55.796>
    creator = 'janwijbrand'
    dependencies = []
    files = ['31498', '31501', '31502', '31509']
    hgrepos = []
    issue_num = 18851
    keywords = ['patch']
    message_count = 16.0
    messages = ['196276', '196393', '196396', '196397', '196416', '196422', '196443', '196448', '196449', '196463', '196471', '196472', '196582', '196586', '196588', '196831']
    nosy_count = 6.0
    nosy_names = ['gregory.p.smith', 'pitrou', 'neologix', 'python-dev', 'janwijbrand', 'Jeong-Min.Lee']
    pr_nums = []
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'behavior'
    url = 'https://bugs.python.org/issue18851'
    versions = ['Python 2.7', 'Python 3.3', 'Python 3.4']

    @janwijbrand
    Copy link
    Mannequin Author

    janwijbrand mannequin commented Aug 27, 2013

    An internal library that heavily uses subprocess.Popen() started failing its automated tests when we upgraded from Python 2.7.3 to Python 2.7.5. This library is used in a threaded environment. After debugging the issue, I was able to create a short Python script that demonstrates the error seen as in the failing tests.

    This is the script (called "threadedsubprocess.py"):

    ===

    import time
    import threading
    import subprocess
    
    def subprocesscall():
        p = subprocess.Popen(
            ['ls', '-l'],
            stdin=subprocess.PIPE,
            stdout=subprocess.PIPE,
            stderr=subprocess.PIPE,
            )
        time.sleep(2) # simulate the Popen call takes some time to complete.
        out, err = p.communicate()
        print 'succeeding command in thread:', threading.current_thread().ident
    
    def failingsubprocesscall():
        try:
            p = subprocess.Popen(
                ['thiscommandsurelydoesnotexist'],
                stdin=subprocess.PIPE,
                stdout=subprocess.PIPE,
                stderr=subprocess.PIPE,
                )
        except Exception as e:
            print 'failing command:', e, 'in thread:', threading.current_thread().ident

    print 'main thread is:', threading.current_thread().ident

    subprocesscall_thread = threading.Thread(target=subprocesscall)
    subprocesscall_thread.start()
    failingsubprocesscall()
    subprocesscall_thread.join()

    ===

    Note: this script does not exit with an IOError when ran from Python 2.7.3. It does fail at least 50% of the times when ran from Python 2.7.5 (both on the same Ubuntu 12.04 64-bit VM).

    The error that is raised on Python 2.7.5 is this:

    ==
    /opt/python/2.7.5/bin/python ./threadedsubprocess.py 
    main thread is: 139899583563520
    failing command: [Errno 2] No such file or directory 139899583563520
    Exception in thread Thread-1:
    Traceback (most recent call last):
      File "/opt/python/2.7.5/lib/python2.7/threading.py", line 808, in __bootstrap_inner
        self.run()
      File "/opt/python/2.7.5/lib/python2.7/threading.py", line 761, in run
        self.__target(*self.__args, **self.__kwargs)
      File "./threadedsubprocess.py", line 13, in subprocesscall
        out, err = p.communicate()
      File "/opt/python/2.7.5/lib/python2.7/subprocess.py", line 806, in communicate
        return self._communicate(input)
      File "/opt/python/2.7.5/lib/python2.7/subprocess.py", line 1379, in _communicate
        self.stdin.close()
    IOError: [Errno 9] Bad file descriptor

    close failed in file object destructor:
    IOError: [Errno 9] Bad file descriptor

    When comparing the subprocess module from Python 2.7.3 to Python 2.7.5 I see the Popen()'s __init__() call indeed now explicitly closes the stdin, stdout and stderr file descriptors in case executing the command somehow fails. This seems to be an intended fix applied in Python 2.7.4 to prevent leaking file descriptors (http://hg.python.org/cpython/file/ab05e7dd2788/Misc/NEWS#l629).

    The diff between Python 2.7.3 and Python 2.7.5 that seems to be relevant to this issue is in the Popen __init__():

    ==
    @@ -671,12 +702,33 @@
    c2pread, c2pwrite,
    errread, errwrite) = self._get_handles(stdin, stdout, stderr)

    -        self._execute_child(args, executable, preexec_fn, close_fds,
    -                            cwd, env, universal_newlines,
    -                            startupinfo, creationflags, shell,
    -                            p2cread, p2cwrite,
    -                            c2pread, c2pwrite,
    -                            errread, errwrite)
    +        try:
    +            self._execute_child(args, executable, preexec_fn, close_fds,
    +                                cwd, env, universal_newlines,
    +                                startupinfo, creationflags, shell,
    +                                p2cread, p2cwrite,
    +                                c2pread, c2pwrite,
    +                                errread, errwrite)
    +        except Exception:
    +            # Preserve original exception in case os.close raises.
    +            exc_type, exc_value, exc_trace = sys.exc_info()
    +
    +            to_close = []
    +            # Only close the pipes we created.
    +            if stdin == PIPE:
    +                to_close.extend((p2cread, p2cwrite))
    +            if stdout == PIPE:
    +                to_close.extend((c2pread, c2pwrite))
    +            if stderr == PIPE:
    +                to_close.extend((errread, errwrite))
    +
    +            for fd in to_close:
    +                try:
    +                    os.close(fd)
    +                except EnvironmentError:
    ==

    Note: I think to see a similar change in the subprocess.Popen() __init__() from Python-3.3.0 to Python-3.3.1.

    @janwijbrand janwijbrand mannequin added stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error labels Aug 27, 2013
    @neologix
    Copy link
    Mannequin

    neologix mannequin commented Aug 28, 2013

    Yes, the problem is that the pipes FDs are closed twice if fork() succeeds, but exec() fails.

    They're closed in _execute_child():
    1286 if p2cread is not None and p2cwrite is not None:
    1287 os.close(p2cread)
    1288 if c2pwrite is not None and c2pread is not None:
    1289 os.close(c2pwrite)
    1290 if errwrite is not None and errread is not None:
    1291 os.close(errwrite)

    And then again in Popen.__init__:
    716 if stdin == PIPE:
    717 to_close.extend((p2cread, p2cwrite))
    718 if stdout == PIPE:
    719 to_close.extend((c2pread, c2pwrite))
    720 if stderr == PIPE:
    721 to_close.extend((errread, errwrite))

    @pitrou
    Copy link
    Member

    pitrou commented Aug 28, 2013

    I wonder how the closing works under Windows. os.close() is called on handles returned by _get_handles(), but those are Windowns HANDLE values, not C file descriptors: os.close() probably fails on them (don't have a Windows VM to check, sorry). I guess the HANDLEs are then leaked...

    @pitrou
    Copy link
    Member

    pitrou commented Aug 28, 2013

    Here is a patch for 2.7. I don't know how to write a test for it, though.

    @pitrou
    Copy link
    Member

    pitrou commented Aug 28, 2013

    Ok, here is a fixed patch for Windows under 2.7.

    @pitrou
    Copy link
    Member

    pitrou commented Aug 28, 2013

    Updated patch with test.

    @gpshead
    Copy link
    Member

    gpshead commented Aug 29, 2013

    fyi - i am unable to reproduce this when using subprocess32 instead of subprocess. https://pypi.python.org/pypi/subprocess32

    That is what i recommend _anyone_ using Python 2.x use instead.

    Regardless if this was reintroduced in 2.7.5 we need to re-fix it.

    i haven't tested 3.2 or 3.3 or default yet (given the backport isn't showing the problem i'm hoping they don't either but they need testing).

    @pitrou
    Copy link
    Member

    pitrou commented Aug 29, 2013

    Gregory, it seems fixed indeed under Unix but I'm not sure about Windows. Read what I wrote above: apparently the cleanup code calls os.close() on a Windows HANDLE; then conveniently it swallows the exception :-)

    Also, the Windows version of _execute_child doesn't set _closed_child_pipe_fds.

    @pitrou
    Copy link
    Member

    pitrou commented Aug 29, 2013

    (in any case, the test is probably worth adding)

    @neologix
    Copy link
    Mannequin

    neologix mannequin commented Aug 29, 2013

    Rietveld's choking on git diffs.

    @pitrou
    Copy link
    Member

    pitrou commented Aug 29, 2013

    Ha, sorry. Here is a non-git patch.

    @pitrou
    Copy link
    Member

    pitrou commented Aug 29, 2013

    Sorry, wrong patch. Uploading again.

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Aug 30, 2013

    New changeset 43749cb6bdbd by Antoine Pitrou in branch '2.7':
    Issue bpo-18851: Avoid a double close of subprocess pipes when the child process fails starting.
    http://hg.python.org/cpython/rev/43749cb6bdbd

    @python-dev
    Copy link
    Mannequin

    python-dev mannequin commented Aug 30, 2013

    New changeset c11754defe1c by Antoine Pitrou in branch '3.3':
    Forward port new tests from Issue bpo-18851.
    http://hg.python.org/cpython/rev/c11754defe1c

    New changeset 290ca31d4cfe by Antoine Pitrou in branch 'default':
    Forward port new tests from Issue bpo-18851.
    http://hg.python.org/cpython/rev/290ca31d4cfe

    @pitrou
    Copy link
    Member

    pitrou commented Aug 30, 2013

    Committed after applying Charles-François's suggested fixes. Thanks!

    @pitrou pitrou closed this as completed Aug 30, 2013
    @janwijbrand
    Copy link
    Mannequin Author

    janwijbrand mannequin commented Sep 3, 2013

    Thanks you for the swift followup!

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    stdlib Python modules in the Lib dir type-bug An unexpected behavior, bug, or error
    Projects
    None yet
    Development

    No branches or pull requests

    2 participants