[MacOS] Race condition in Process.get_connections randomly raises AccessDenied #1901

gimperiale · 2021-01-06T13:46:20Z

Summary

OS: MacOS Big Sur. I did not test this issue on other OSs.
Architecture: Intel 64bit
Psutil version: 5.8.0
Python version: 3.8.6
Type: core

Description

The following code starts a vanilla HTTP server, which runs in the foreground (doesn't fork/daemonize) and listens on a single TCP/IP port. The wrapper waits for the subprocess to start listening before it returns:

import psutil
import subprocess

def start_server(argv):
    proc = subprocess.Popen(argv)
    pproc = psutil.Process(proc.pid)
    while True:
        for conn in pproc.connections():
            if conn.status == "LISTEN":
                return proc
        time.sleep(0.01)

Expected behaviour

The above code either

returns after a while, or
raises psutil.NoSuchProcess, if the subprocess dies before it opens the port, or
hangs forever, if for some weird reason the subprocess fails to listen on the port and doesn't die as a consequence

Observed behaviour

Occasionally, if the subprocess dies in the middle of a call to Process.connections(), the above code raises psutil.AccessDenied. This makes no sense to me as I'm the user that started the process to begin with.
I know for sure that the subprocess died before it even started tampering with its sockets.

Stack trace:

myscript.py:8: in start_server
    for conn in pproc.connections():
lib/python3.8/site-packages/psutil/__init__.py:1162: in connections
    return self._proc.connections(kind)
lib/python3.8/site-packages/psutil/_psosx.py:344: in wrapper
    return fun(self, *args, **kwargs)
lib/python3.8/site-packages/psutil/_psosx.py:534: in connections
    rawlist = cext.proc_connections(self.pid, families, types)
lib/python3.8/contextlib.py:131: in __exit__
    self.gen.throw(type, value, traceback)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

proc = <psutil._psosx.Process object at 0x7fa70f88dec0>

    @contextlib.contextmanager
    def catch_zombie(proc):
        """There are some poor C APIs which incorrectly raise ESRCH when
        the process is still alive or it's a zombie, or even RuntimeError
        (those who don't set errno). This is here in order to solve:
        https://github.com/giampaolo/psutil/issues/1044
        """
        try:
            yield
        except (OSError, RuntimeError) as err:
            if isinstance(err, RuntimeError) or err.errno == errno.ESRCH:
                try:
                    # status() is not supposed to lie and correctly detect
                    # zombies so if it raises ESRCH it's true.
                    status = proc.status()
                except NoSuchProcess:
                    raise err
                else:
                    if status == _common.STATUS_ZOMBIE:
                        raise ZombieProcess(proc.pid, proc._name, proc._ppid)
                    else:
>                       raise AccessDenied(proc.pid, proc._name)
E                       psutil.AccessDenied: psutil.AccessDenied (pid=16109)

lib/python3.8/site-packages/psutil/_psosx.py:378: AccessDenied

The text was updated successfully, but these errors were encountered:

Signed-off-by: Giampaolo Rodola <[email protected]>

giampaolo · 2021-01-07T01:36:06Z

I submitted a PR (#1903) which I think should solve this issue, but since I cannot reproduce it, it would be good it you try it first. Can you clone the repo and try that branch? Here's how to do it:

git clone [email protected]:giampaolo/psutil.git
cd psutil
git checkout osx-list-fds-refact
make install

gimperiale · 2021-01-07T02:02:43Z

@marouane-miftah can I leave the retest to you?

marouane-miftah · 2021-01-07T07:35:21Z

@marouane-miftah can I leave the retest to you?

yes

marouane-miftah · 2021-01-07T08:59:44Z

@marouane-miftah can I leave the retest to you?

I am still getting the same error with the new branch.

giampaolo · 2021-01-07T10:37:50Z

I added some debug prints. Please git pull and run your script like this, then paste the output & traceback:

PSUTIL_DEBUG=1 python3 yourscript.py

marouane-miftah · 2021-01-07T16:09:39Z

@giampaolo, hope this helps.

I added some debug prints. Please git pull and run your script like this, then paste the output & traceback:
PSUTIL_DEBUG=1 python3 yourscript.py

../../miniconda3/envs/x/lib/python3.8/site-packages/pshell/procs.py:241: in wait_for_server
conn.laddr.port for conn in proc.connections() if conn.status == "LISTEN"
../../miniconda3/envs/x/lib/python3.8/site-packages/psutil/init.py:1162: in connections
return self._proc.connections(kind)
../../miniconda3/envs/x/lib/python3.8/site-packages/psutil/_psosx.py:344: in wrapper
return fun(self, *args, **kwargs)
../../miniconda3/envs/x/lib/python3.8/site-packages/psutil/_psosx.py:534: in connections
rawlist = cext.proc_connections(self.pid, families, types)
../../miniconda3/envs/x/lib/python3.8/contextlib.py:131: in exit
self.gen.throw(type, value, traceback)

proc = <psutil._psosx.Process object at 0x7fc4206c1240>

@contextlib.contextmanager
def catch_zombie(proc):
    """There are some poor C APIs which incorrectly raise ESRCH when
    the process is still alive or it's a zombie, or even RuntimeError
    (those who don't set errno). This is here in order to solve:
    https://github.com/giampaolo/psutil/issues/1044
    """
    try:
        yield
    except (OSError, RuntimeError) as err:
        if isinstance(err, RuntimeError) or err.errno == errno.ESRCH:
            try:
                # status() is not supposed to lie and correctly detect
                # zombies so if it raises ESRCH it's true.
                status = proc.status()
            except NoSuchProcess:
                raise err
            else:
                if status == _common.STATUS_ZOMBIE:
                    raise ZombieProcess(proc.pid, proc._name, proc._ppid)
                else:

                  raise AccessDenied(proc.pid, proc._name)

E psutil.AccessDenied: psutil.AccessDenied (pid=23261)

../../miniconda3/envs/x/lib/python3.8/site-packages/psutil/_psosx.py:378: AccessDenied
----------------------------------------------------------------------------------------- Captured stderr setup ------------------------------------------------------------------------------------------
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP
psutil-debug> sysctl(KERN_PROCARGS2) -> EINVAL translated to NSP

giampaolo · 2021-01-07T16:16:29Z

Mmm no. I don't see any debug message and the original OSError exception coming from the C extension module got swallowed / hidden for some reason. It doesn't look like your running this script directly (is this a test suite run?).
You should run it from the shell (and possibly not using conda) as in:

PSUTIL_DEBUG=1 python3 yourscript.py

marouane-miftah · 2021-01-07T17:29:14Z

@giampaolo, I have run it as you described but I am note getting any extra DEBUG messages

I also tried export the env variable first as so, and can verify that it was set properly at the end after the error is triggered.

export PSUTIL_DEBUG=1; python myscript.py 
Traceback (most recent call last):
 (application traceback)
OSError: [Errno 48] error while attempting to bind on address ('::', 48588, 0, 0): address already in use
Traceback (most recent call last):
  File "lib/python3.8/site-packages/psutil/_psosx.py", line 365, in catch_zombie
    yield
  File "lib/python3.8/site-packages/psutil/_psosx.py", line 534, in connections
    rawlist = cext.proc_connections(self.pid, families, types)
ProcessLookupError: [Errno 3] No such process (originated from proc_pidinfo())

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "myscript.py", line 28, in <module>
    start_server(cmd_args)
  File "myscript.py", line 10, in start_server
    for conn in pproc.connections():
  File "lib/python3.8/site-packages/psutil/__init__.py", line 1162, in connections
    return self._proc.connections(kind)
  File "lib/python3.8/site-packages/psutil/_psosx.py", line 344, in wrapper
    return fun(self, *args, **kwargs)
  File "lib/python3.8/site-packages/psutil/_psosx.py", line 534, in connections
    rawlist = cext.proc_connections(self.pid, families, types)
  File "lib/python3.8/contextlib.py", line 131, in __exit__
    self.gen.throw(type, value, traceback)
  File "lib/python3.8/site-packages/psutil/_psosx.py", line 378, in catch_zombie
    raise AccessDenied(proc.pid, proc._name)
psutil.AccessDenied: psutil.AccessDenied (pid=31489)

echo $PSUTIL_DEBUG 
1

This was done in order to solve #1044 and #1100 ...but its logic duplicates the one in wrap_exceptions() decorator. Also, this should solve #1901 as it did erroneously translated NSP in AD. Signed-off-by: Giampaolo Rodola <[email protected]>

giampaolo · 2021-01-08T20:56:16Z

OK, I pushed some changes into osx-list-fds-refact branch. Can you retry?

marouane-miftah · 2021-01-08T22:00:39Z

sorry @giampaolo still the same error.

giampaolo · 2021-01-08T22:16:45Z

Mmm weird.
This is my test case:

$ cat foo.py
import psutil
import subprocess

proc = subprocess.Popen(["python3", "server.py"])
pproc = psutil.Process(proc.pid)
while True:
    for conn in pproc.connections():
        if conn.status == "LISTEN":
            break

$ cat server.py
import socket
sock = socket.socket()
sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
sock.bind(('127.0.0.1', 8080))
sock.listen(10)

Run:

$ git rev-parse HEAD
7fb7ac3bc0986eb2e18a3179a695b081d92a19e6
$ make test TSCRIPT=foo.py

Before the patch it raised AccessDenied, now it raises NoSuchProcess (as it should).

no-response · 2021-04-23T16:10:49Z

This issue has been automatically closed because there has been no response for more information from the original author. Please reach out if you have or find the answers requested so that this can be investigated further.

Signed-off-by: Giampaolo Rodola <[email protected]>

no-response · 2021-10-05T17:19:02Z

This issue has been automatically closed because there has been no response for more information from the original author. Please reach out if you have or find the answers requested so that this can be investigated further.

) (#1903)

giampaolo · 2021-10-05T17:32:27Z

PR merged. This issue should have been fixed.

gimperiale added the bug label Jan 6, 2021

github-actions bot added macos tests labels Jan 6, 2021

giampaolo added a commit that referenced this issue Jan 6, 2021

#1901 / macOS: better err msg on proc_pidinfo()

f95276d

Signed-off-by: Giampaolo Rodola <[email protected]>

giampaolo mentioned this issue Jan 7, 2021

[macOS] dynamic set buffer size for process connections/fds (fixes #1901) #1903

Merged

giampaolo added the need-more-info label Apr 9, 2021

no-response bot closed this as completed Apr 23, 2021

giampaolo reopened this Oct 5, 2021

giampaolo added a commit that referenced this issue Oct 5, 2021

update HISTORY for #1901 / #1903

b3a1f04

Signed-off-by: Giampaolo Rodola <[email protected]>

no-response bot closed this as completed Oct 5, 2021

giampaolo added a commit that referenced this issue Oct 5, 2021

[macOS] dynamic set buffer size for process connections/fds (fixes #1901

e15922b

) (#1903)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[MacOS] Race condition in Process.get_connections randomly raises AccessDenied #1901

[MacOS] Race condition in Process.get_connections randomly raises AccessDenied #1901

gimperiale commented Jan 6, 2021

giampaolo commented Jan 7, 2021 •

edited

Loading

gimperiale commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021

giampaolo commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021 •

edited

Loading

giampaolo commented Jan 7, 2021 •

edited

Loading

marouane-miftah commented Jan 7, 2021

giampaolo commented Jan 8, 2021

marouane-miftah commented Jan 8, 2021

giampaolo commented Jan 8, 2021 •

edited

Loading

no-response bot commented Apr 23, 2021

no-response bot commented Oct 5, 2021

giampaolo commented Oct 5, 2021

[MacOS] Race condition in Process.get_connections randomly raises AccessDenied #1901

[MacOS] Race condition in Process.get_connections randomly raises AccessDenied #1901

Comments

gimperiale commented Jan 6, 2021

Summary

Description

Expected behaviour

Observed behaviour

giampaolo commented Jan 7, 2021 • edited Loading

gimperiale commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021

giampaolo commented Jan 7, 2021

marouane-miftah commented Jan 7, 2021 • edited Loading

giampaolo commented Jan 7, 2021 • edited Loading

marouane-miftah commented Jan 7, 2021

giampaolo commented Jan 8, 2021

marouane-miftah commented Jan 8, 2021

giampaolo commented Jan 8, 2021 • edited Loading

no-response bot commented Apr 23, 2021

no-response bot commented Oct 5, 2021

giampaolo commented Oct 5, 2021

giampaolo commented Jan 7, 2021 •

edited

Loading

marouane-miftah commented Jan 7, 2021 •

edited

Loading

giampaolo commented Jan 7, 2021 •

edited

Loading

giampaolo commented Jan 8, 2021 •

edited

Loading