Pytest: rm_rf fails for a set of tests

[RonnyPfannschmidt]

i started to observe the following on the features branch:

 pytest.PytestWarning: (rm_rf) error removing /tmp/pytest-of-rpfannsc/garbage-3bad3bc3-af58-4b47-8b7e-ea772115f6ea/test_cache_failure_warns0/.pytest_cache: [Errno 13] Permission denied: '.pytest_cache'

together with the pytest warning configuration this means the "world" breaks very regular

[nicoddemus]

IIRC correctly the previous implementation would silently ignore the error... when refactoring that part we decided to add the warning.

Should we hide this warning by default then? This at least allows users to selectively show the warning if they are investigating why a particular folder is not being deleted...

[RonnyPfannschmidt]

@nicoddemus we should ensure this particular warning never turns into a error

[blueyed]

I've also seen this lately.. in that case the call was open for .pytest-cache (likely as above).
@RonnyPfannschmidt
Can you provide ls -ld of it?
(FWIW rm -rf worked as a workaround to fix it.)

[RonnyPfannschmidt]

i did actually rf it, will do the ls next time i seethe issue

[blueyed]

% sudo ls -ld /tmp/pytest-of-user/garbage-08c601a7-60a4-4e2e-b129-f15308608061/test_cache_failure_warns0/.pytest_cache
d--------- 2 user user 40 Oct 17 14:56 /tmp/pytest-of-user/garbage-08c601a7-60a4-4e2e-b129-f15308608061/test_cache_failure_warns0/.pytest_cache/

% sudo tree -a /tmp/pytest-of-user/garbage-c8d6abb3-cdcc-4640-822f-03f702fee818/tmp/pytest-of-user/garbage-c8d6abb3-cdcc-4640-822f-03f702fee818
├── test_cache_failure_warns0
│   └── .pytest_cache
└── test_cache_writefail_permissions0
    └── .pytest_cache

============================================================================ test session starts =============================================================================
platform linux -- Python 3.7.4, pytest-5.2.2.dev25+g914a9465a.d20191016, py-1.8.1.dev11+g34f716fe, pluggy-0.12.0
hypothesis profile 'default' -> database=DirectoryBasedExampleDatabase('…/Vcs/pytest/.hypothesis/examples')
rootdir: …/Vcs/pytest, inifile: tox.ini, testpaths: testing
plugins: hypothesis-4.23.8, forked-1.0.2, xdist-1.29.0
collected 2673 items

testing/acceptance_test.py .E

=================================================================================== ERRORS ===================================================================================
______________________________________________________ ERROR at setup of TestGeneralUsage.test_plugins_given_as_strings ______________________________________________________

topfd = 11, path = '/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6/test_cache_failure_warns0'
onerror = functools.partial(<function on_rm_rf_error at 0x7fe3af8accb0>, start_path=PosixPath('/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6'))

    def _rmtree_safe_fd(topfd, path, onerror):
        try:
            with os.scandir(topfd) as scandir_it:
                entries = list(scandir_it)
        except OSError as err:
            err.filename = path
            onerror(os.scandir, path, sys.exc_info())
            return
        for entry in entries:
            fullname = os.path.join(path, entry.name)
            try:
                is_dir = entry.is_dir(follow_symlinks=False)
                if is_dir:
                    orig_st = entry.stat(follow_symlinks=False)
                    is_dir = stat.S_ISDIR(orig_st.st_mode)
            except OSError:
                is_dir = False
            if is_dir:
                try:
>                   dirfd = os.open(entry.name, os.O_RDONLY, dir_fd=topfd)
E                   PermissionError: [Errno 13] Permission denied: '.pytest_cache'

/usr/lib/python3.7/shutil.py:426: PermissionError

During handling of the above exception, another exception occurred:

path = '/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6', ignore_errors = False
onerror = functools.partial(<function on_rm_rf_error at 0x7fe3af8accb0>, start_path=PosixPath('/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6'))

    def rmtree(path, ignore_errors=False, onerror=None):
        """Recursively delete a directory tree.

        If ignore_errors is set, errors are ignored; otherwise, if onerror
        is set, it is called to handle the error with arguments (func,
        path, exc_info) where func is platform and implementation dependent;
        path is the argument to that function that caused it to fail; and
        exc_info is a tuple returned by sys.exc_info().  If ignore_errors
        is false and onerror is None, an exception is raised.

        """
        if ignore_errors:
            def onerror(*args):
                pass
        elif onerror is None:
            def onerror(*args):
                raise
        if _use_fd_functions:
            # While the unsafe rmtree works fine on bytes, the fd based does not.
            if isinstance(path, bytes):
                path = os.fsdecode(path)
            # Note: To guard against symlink races, we use the standard
            # lstat()/open()/fstat() trick.
            try:
                orig_st = os.lstat(path)
            except Exception:
                onerror(os.lstat, path, sys.exc_info())
                return
            try:
                fd = os.open(path, os.O_RDONLY)
            except Exception:
                onerror(os.lstat, path, sys.exc_info())
                return
            try:
                if os.path.samestat(orig_st, os.fstat(fd)):
>                   _rmtree_safe_fd(fd, path, onerror)

/usr/lib/python3.7/shutil.py:494: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/usr/lib/python3.7/shutil.py:432: in _rmtree_safe_fd
    _rmtree_safe_fd(dirfd, fullname, onerror)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

topfd = 11, path = '/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6/test_cache_failure_warns0'
onerror = functools.partial(<function on_rm_rf_error at 0x7fe3af8accb0>, start_path=PosixPath('/tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6'))

    def _rmtree_safe_fd(topfd, path, onerror):
        try:
            with os.scandir(topfd) as scandir_it:
                entries = list(scandir_it)
        except OSError as err:
            err.filename = path
            onerror(os.scandir, path, sys.exc_info())
            return
        for entry in entries:
            fullname = os.path.join(path, entry.name)
            try:
                is_dir = entry.is_dir(follow_symlinks=False)
                if is_dir:
                    orig_st = entry.stat(follow_symlinks=False)
                    is_dir = stat.S_ISDIR(orig_st.st_mode)
            except OSError:
                is_dir = False
            if is_dir:
                try:
                    dirfd = os.open(entry.name, os.O_RDONLY, dir_fd=topfd)
                except OSError:
>                   onerror(os.open, fullname, sys.exc_info())
E                   pytest.PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-7a9a0206-064e-466f-9e42-b492c62f00c6/test_cache_failure_warns0/.pytest_cache: [Errno 13] Permission denied: '.pytest_cache'

/usr/lib/python3.7/shutil.py:428: PytestWarning
========================================================================== short test summary info ===========================================================================
ERROR testing/acceptance_test.py::TestGeneralUsage::test_plugins_given_as_strings - pytest.PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-7a9a0206-064...
========================================================================= 1 passed, 1 error in 1.61s =========================================================================

[blueyed]

It should warn about this once at most per test run btw.

It might have been triggered by ctrl-c'ing a previous test run, i.e. there is code that does not behave correctly in this case when creating the temporary directory, since it should never end up with those permissions.
IIRC I've always seen this with .pytest_cache only.

[blueyed]

When defaulting the warning there are followups then:

testing/test_pdb.py::TestPDB::test_pdb_unittest_postmortem
  …/Vcs/pytest/src/_pytest/pathlib.py:53: PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d/test_cache_failure_warns0/.pytest_cache: [Errno 13] Permission denied: '.pytest_cache'
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))

testing/test_pdb.py::TestPDB::test_pdb_unittest_postmortem
  …/Vcs/pytest/src/_pytest/pathlib.py:47: PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d/test_cache_failure_warns0: [Errno 39] Directory not empty: 'test_cache_failure_warns0'
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))

testing/test_pdb.py::TestPDB::test_pdb_unittest_postmortem
  …/Vcs/pytest/src/_pytest/pathlib.py:53: PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d/test_cache_writefail_permissions0/.pytest_cache: [Errno 13] Permission denied: '.pytest_cache'
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))

testing/test_pdb.py::TestPDB::test_pdb_unittest_postmortem
  …/Vcs/pytest/src/_pytest/pathlib.py:47: PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d/test_cache_writefail_permissions0: [Errno 39] Directory not empty: 'test_cache_writefail_permissions0'
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))

testing/test_pdb.py::TestPDB::test_pdb_unittest_postmortem
  …/Vcs/pytest/src/_pytest/pathlib.py:47: PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d: [Errno 39] Directory not empty: '/tmp/pytest-of-user/garbage-fe5e97d1-4ead-4089-af2e-ae93ddaf638d'
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))

[nicoddemus]

Note: we should remove the filter added by https://github.com/pytest-dev/pytest/pull/5993 once this is sorted out.

[blueyed]

It is bad btw that it loses the exceptions context (original source):

Traceback (most recent call last):
  File "/usr/lib/python3.7/shutil.py", line 426, in _rmtree_safe_fd
    dirfd = os.open(entry.name, os.O_RDONLY, dir_fd=topfd)
PermissionError: [Errno 13] Permission denied: '.pytest_cache'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.7/shutil.py", line 494, in rmtree
    _rmtree_safe_fd(fd, path, onerror)
  File "/usr/lib/python3.7/shutil.py", line 432, in _rmtree_safe_fd
    _rmtree_safe_fd(dirfd, fullname, onerror)
  File "/usr/lib/python3.7/shutil.py", line 428, in _rmtree_safe_fd
    onerror(os.open, fullname, sys.exc_info())
  File "…/Vcs/pytest/src/_pytest/pathlib.py", line 53, in on_rm_rf_error
    PytestWarning("(rm_rf) error removing {}: {}".format(path, excvalue))
pytest.PytestWarning: (rm_rf) error removing /tmp/pytest-of-user/garbage-6b7caf83-9fd9-4019-9ff2-f239f8cceddc/test_cache_failure_warns0/.pytest_cache: [Errno 13] Permission denied: '.pytest_cache'

[tarpas]

Hi guys. Did this get fixed recently? I don't understand it much but this diff made it go away:

diff --git a/testing/test_cacheprovider.py b/testing/test_cacheprovider.py
index cbba27e5f..5bfbcf946 100644
--- a/testing/test_cacheprovider.py
+++ b/testing/test_cacheprovider.py
@@ -2,6 +2,7 @@ import os
 import shutil
 import sys
 import textwrap
+import stat

 import py

@@ -45,14 +46,17 @@ class TestNewAPI:
     )
     def test_cache_writefail_permissions(self, testdir):
         testdir.makeini("[pytest]")
+        mode = os.stat(testdir.tmpdir.ensure_dir(".pytest_cache"))[stat.ST_MODE]
         testdir.tmpdir.ensure_dir(".pytest_cache").chmod(0)
         config = testdir.parseconfigure()
         cache = config.cache
         cache.set("test/broken", [])
+        testdir.tmpdir.ensure_dir(".pytest_cache").chmod(mode)

     @pytest.mark.skipif(sys.platform.startswith("win"), reason="no chmod on windows")
     @pytest.mark.filterwarnings("default")
     def test_cache_failure_warns(self, testdir):
+        mode = os.stat(testdir.tmpdir.ensure_dir(".pytest_cache"))[stat.ST_MODE]
         testdir.tmpdir.ensure_dir(".pytest_cache").chmod(0)
         testdir.makepyfile(
             """
@@ -62,6 +66,7 @@ class TestNewAPI:
         """
         )
         result = testdir.runpytest("-rw")
+        testdir.tmpdir.ensure_dir(".pytest_cache").chmod(mode)
         assert result.ret == 1
         # warnings from nodeids, lastfailed, and stepwise
         result.stdout.fnmatch_lines(["*could not create cache path*", "*3 warnings*"])

[blueyed]

Did this get fixed recently?

No, I am seeing this myself from time to time.

Your patch suggests that it might be due to a broken test? (I've thought this would be some race with pytest itsef - wasn't paying enough attention apparently)
Please consider creating a PR from your patch already.

[blueyed]

@tarpas
I'm also happy to pick up your patch, just let me know.

[tarpas]

My hypothesis is that these two tests change the permissions of directories in tmpdir so that the standard teardown is not able to delete them. On MacOS I wasn't even able to rm -Rf them from command line easily.

Why the warning seems to come out during some other test execution I don't know. I tested my solution very briefly so I'm not sure it's the right fix.

Please go ahead with my patch, thanks!

[blueyed]

Cool, https://github.com/pytest-dev/pytest/pull/6136.

The warning only happens when pytest cleans them up, which only happens later (it keeps the most recent ones).