poetry add/update/install can fail on Windows during temp directory cleanup

[Pluckerpluck]

If something goes wrong during an installation, a file is often held open for just a little too long for TemporaryDirectory causing it to error out with errors such as:

[OSError]
[WinError 145] The directory is not empty: 'C:\\Users\\KING~1.KYL\\AppData\\Local\\Temp\\tmp774m6ge1'

...

 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\contextlib.py in __exit__() at line 119
   next(self.gen)
 C:\Users\king.kyle\.poetry\lib\poetry\utils\helpers.py in temporary_directory() at line 35
   yield name
 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\tempfile.py in __exit__() at line 805
   self.cleanup()
 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\tempfile.py in cleanup() at line 809
   _shutil.rmtree(self.name)
 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\shutil.py in rmtree() at line 507
   return _rmtree_unsafe(path, onerror)
 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\shutil.py in _rmtree_unsafe() at line 395
   onerror(os.rmdir, path, sys.exc_info())
 C:\Users\king.kyle\AppData\Local\Continuum\anaconda2\envs\py37\lib\shutil.py in _rmtree_unsafe() at line 393
   os.rmdir(path)

add [-D|--dev] [--git GIT] [--path PATH] [-E|--extras EXTRAS] [--optional] [--python PYTHON] [--platform PLATFORM] [--allow-prereleases] [--dry-run] [--] <name> (<name>)...

This is an incredibly unhelpful error and masks all sorts of other problems.

It is causes by a bug in shutil.rmtree which can fail on Windows from time to time. It can fail for a variety of reasons, but very commonly it's simply a process holding the file active for just a little too long resulting in os.rmdir failing. This is despite the directory actually being empty when you check (i.e. it's just slow).

This is a known error in Python, of which there is no plan to fix: https://bugs.python.org/issue29982

As a result, I suggest the avoidance of using TemporaryDirectory, over which we have no control of the cleanup, and instead use mkdtemp manually, followed by a short loop to try and remove the directory.

In particular in helpers.py:

@contextmanager
def temporary_directory(*args, **kwargs):
    try:
        from tempfile import TemporaryDirectory

        with TemporaryDirectory(*args, **kwargs) as name:
            yield name
    except ImportError:
        name = tempfile.mkdtemp(*args, **kwargs)

        yield name

        shutil.rmtree(name)

should instead be something like:

@contextmanager
def temporary_directory(*args, **kwargs):
    name = tempfile.mkdtemp(*args, **kwargs)

    yield name

    robust_rmtree(name)

def robust_rmtree(path, max_retries=6):
    """Robustly tries to delete paths.

    Retries several times if an OSError occurs.
    If the final attempt fails, the Exception is propagated
    to the caller.
    """
    for i in range(max_retries - 1):
        try:
            shutil.rmtree(path)
            return # Only hits this on success
        except OSError:
            time.sleep(1)

    # Final attempt, pass any Exceptions up to caller.
    shutil.rmtree(path)

This is done in a few other projects:

• EasyBuilders
• Hashdist

The latter is where I ripped the example function.

I'm willing to write a pull request later to test this myself. But I'm writing the issue now as it is a problem that should be dealt with.

[drunkwcodes]

The max_retries=6 (secs) without feedbacks is too long for a failed command to me.
Please add a error message above the sleep(1)

[Pluckerpluck]

First, I should state that the example I presented in the issue was copy pasted is not my actual pull request. It was just an example thrown up for discussion. You should reference my pull request if we're talking about the technical details of the implementation.

---

This isn't actually an error though, and is a fundamental method of dealing with directory deletion in Windows.

So outputting an error doesn't make sense. At most it would be a debug message. I would point out though, that this is 6 seconds until catastrophic failure. If you reach the 6 seconds you will have poetry crash with an error. So it's not like it's just a slow command, it's a slow command followed by a crash which is noticeably more acceptable in practice.

Further, I don't actually know how to output a message from this function in a way that is consistent with poetry, But it's not like there aren't other long running commands that provide very little feedback during their execution (creating a virtual environment is one of these)

The pull request is 3 attempts at 2 seconds each, but this is up for discussion. I do not know how much time is needed to get a near guarantee of directory deletion on Windows, but there is a decent chance we can run it for only 3 attempts at 1 second per.

---

I want to stress though. This fix or something along these lines is a requirement to claim that Poetry supports Windows, as currently in certain situations and setups it will just flat out fail as a result of this problem.

---

Side note: I updated the pull request to match coding standards. It was such a simple change I thought I surely couldn't mess it up. But nope: Two spaces before in-line comments...

[drunkwcodes]

Would you like to use this method to find out which program kept the files?

https://youtu.be/PDab6s7cWqk

P.S If this issue keeps you from trying poetry, it will keeps you from trying poetry forever.

[Pluckerpluck]

I don't think you recognize the problem here. When you mark a file for deletion in Windows, it does not delete immediately. It is held in stasis until all references to the file clear, and then at some arbitrary point in the future it is removed.

rmtree does not wait for this to occur. Which means, from time to time, it will just arbitrarily fail. This can be simply from timing (nested directories almost always cause a problem), or from antivirus taking 0.3 seconds too long to scan the file on access.

As a result, it will error when it tries to delete the parent directory while the files within it are waiting on removal. These will be removed very quickly, within seconds, generally less than 1 second, but this errors regardless.

This is a well known problem with Windows. Many other projects have faced this issue and implement a delayed deletion to deal with it. There is a reason that Poetry gives Directory not empty errors in Windows when completely unrelated problems occur, and it's because of this delayed deletion within Windows.

---

There is no sensible way for me to use Unlocker to determine what is holding it open for the 100ms it's grabbed for. It could simply be the Windows file system!

This is a Windows issue. It is unrelated to my PC in particular, but the windows ecosystem on a whole. The speed of your system can be enough to make something succeed or fail. The speed of your HDD makes a difference. There is no sensible way to force or test for this, you just must know that the problem exists and deal with it.

[drunkwcodes]

But my point seems not that odd: https://stackoverflow.com/questions/24699854/strange-error-when-deleting-directory-from-java-0-bytes-access-denied

You made me search file descriptors without context in poetry and pip for a while...

[Pluckerpluck]

Just to be clear. This is not a problem involving a regular program actually locking a file open for some reason. It is the result of a program responding to a change notification (specifically, the delete notification)

This is basically like having a callback in code:

def on_delete(file):
    # Do some stuff
    print(f"Do some stuff with {file.name}")

That file is in the process of being deleted. DeleteFile returned successful. It's just that some programs are grabbing information from it before this occurs. In particular, this can be the indexing service from Windows itself.

Poetry then fails from trying to delete the parent directory before this occurs. Python was told "yep, that file will be deleted.... at some point", but poetry assumes that means "right now", which means when it tires to remove the parent directory the file is not yet gone and we get the error. The file is removed mere seconds later, but by then it's too late. Poetry has crashed.

---

So that's why you need a retry loop. Either that or you catch the failure, ignore the error, and cleanup tmp files at a later time (because Windows doesn't do that).

Either way, something has to be done here to support this weird quirk of Windows.

[drunkwcodes]

@Pluckerpluck Your example made this a serious issue absolutely.
That probably conflicts with the newest Java's principle.

What's the evidence of the robustness about robust_rmtree()?

[Pluckerpluck]

robust_rmtree() in its very nature can never guarantee removal of a directory. We have to have a timeout put in there somewhere. But it is the same system as used by:

• Easybuilders
• Hashdist

And has been in both of those codebases for over 5 years.

As a "recent" example, rmtree() fails if a subfolder is opened in Explorer on windows due to a 0.8 millisecond wait on the directory. So in the vast majority of cases I expect this to clean up within a second.

Similar code is also included in cpython itself! In particular, while they have agreed to not include this into base Python, they do still need it for their own Windows tests.

Note: They wait for less than 1 second though, starting at 0.001 seconds and increasing exponentially up to a maximum of 1. So maybe the initial wait of 2 seconds it needlessly large, however given that this is running during poetry install and rarely actually occurs (generally at maximum on a single dependency), I think the time is OK.

---

With regards to testing, we used to have a single PC that consistently failed due to this error, and this change means that the system now installs requirements properly. We now have been using this fix for some time and have yet to run into any issues.

The problem is more of an issue with Windows buildbots though, where you can't just "retry" the install in the same way you would on a PC.

[drunkwcodes]

Please minimize the interval and the required runs of the loop.

The name of the function had better be double_rmtree() to reserve the leading "r" for rampage_rmtree().

[Pluckerpluck]

Do you agree it's good to use the same system as CPython? Start at 1ms wait, and exponentially scale to 1 second wait (this means the total possible wait is < 2 seconds). If Python themselves do it, then it must be reasonable.

I don't understand the issue with the name roboust_rmtree() it's a much clearer name than doubel_rmtree() (which kind of sounds like you're removing something exactly twice) and I don't understand why we care about reserving the leading r. Especially given that rmtree already begins with an r and that I have no idea what rampage_rmtree() is...

[drunkwcodes]

If it works with your method for that reason (always), it will only need to run twice exactly.
Please rename it or close it.

[Pluckerpluck]

There is no guarantee it will need only two runs! Python themselves run the check up to 10 times.

This is what CPython does:

• Wait 1ms
• Wait 2ms
• Wait 4ms
• Wait 8ms
• Wait 16ms
• Wait 32ms
• Wait 64ms
• Wait 128ms
• Wait 256ms
• Wait 512ms
• Report failure

This results in a maximum wait of 1 second, but a minimum wait of 1ms. The idea being that you will avoid the Windows issue in the least amount of time needed.

I suggest we implement the system that Python themselves use. There is probably a good reason they choose to do it that way.

Checking only twice means we have to catch the worst case, which means waiting for 1 second every time. While rare that's just a waste of time for no good reason.

---

Again. Why can't this be called robust_rmtree? Or something similar that explains what it does. The name should explain the functionality (it's a more robust rmtree), not the exact implementation.

[Ryuno-Ki]

Similar code is also included in cpython itself! In particular, while they have agreed to not include this into base Python, they do still need it for their own Windows tests.

For reference: Associated bug ticket: https://bugs.python.org/issue15496 - commit referencing it: python/cpython@6f5c5cb (via Blame feature on GitHub)

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[absassi]

This bug still happens, however it looks like #1032 is abandoned.

[arcutright]

Still happens in Poetry 1.1.5, why was #1032 not merged? Poetry is almost unusable because my poetry install fails with an OSError: [WinError 5] Access is denied 9/10 times. My conda environment is medium-large, 287 packages in conda list.

This also appears to be related to #1612 (comment)

Versions:

poetry 1.1.5
poetry-core 1.0.2
using conda 4.9.2
python 3.8.8
pip 21.0.1
windows 10 pro 20H2, build 19042.867

Note that in the output below, I replaced some paths with their equivalent environment variables (%userprofile%, etc)

Example demonstrating issue from fresh environment

> conda --version
conda 4.9.2
> conda create -n py38 python=3.8.8
> conda activate py38
(py38) > python --version
Python 3.8.8
(py38) >pip --version
pip 21.0.1 from %userprofile%\anaconda3\envs\py38\lib\site-packages\pip (python 3.8)

(py38) > conda install poetry
... Success
(py38) > poetry --version
Poetry version 1.1.5

(py38) > poetry install
Installing dependencies from lock file
Warning: The lock file is not up to date with the latest changes in pyproject.toml. You may be getting outdated dependencies. Run update to update them.

Package operations: 113 installs, 2 updates, 2 removals
...
  EnvCommandError

  Command %userprofile%\anaconda3\envs\py38\Scripts\pip.exe install --no-deps -U %localappdata%\pypoetry\Cache\artifacts\d8\37\43\5ceed6677fc301784b0e62604a431e293d12c402f4ca588304e916a04d\pyrsistent-0.17.3.tar.gz errored with the following return code 1, and output:
  Processing %localappdata%\pypoetry\cache\artifacts\d8\37\43\5ceed6677fc301784b0e62604a431e293d12c402f4ca588304e916a04d\pyrsistent-0.17.3.tar.gz
  Building wheels for collected packages: pyrsistent
    Building wheel for pyrsistent (setup.py): started
    Building wheel for pyrsistent (setup.py): finished with status 'done'
    Created wheel for pyrsistent: filename=pyrsistent-0.17.3-cp38-cp38-win_amd64.whl size=70541 sha256=a569dc22032be6292bb79f8f16f23653180fd033595a124961e0ebf76310544c
    Stored in directory: %localappdata%\pip\cache\wheels\a5\ec\eb\1099d304414c3dbb988074a0492d6133e2f9fe79aeabb8e7d3
  Successfully built pyrsistent
  Installing collected packages: pyrsistent
    Attempting uninstall: pyrsistent
      Found existing installation: pyrsistent 0.14.11
      Uninstalling pyrsistent-0.14.11:
        Successfully uninstalled pyrsistent-0.14.11
  ERROR: Could not install packages due to an OSError: [WinError 5] Access is denied: '%localappdata%\\Temp\\pip-uninstall-pvo41oqs\\pvectorc.cp38-win_amd64.pyd'
  Consider using the `--user` option or check the permissions.

  at ~\anaconda3\envs\py38\lib\site-packages\poetry\utils\env.py:1074 in _run
      1070│                 output = subprocess.check_output(
      1071│                     cmd, stderr=subprocess.STDOUT, **kwargs
      1072│                 )
      1073│         except CalledProcessError as e:
    → 1074│             raise EnvCommandError(e, input=input_)
      1075│
      1076│         return decode(output)
      1077│
      1078│     def execute(self, bin, *args, **kwargs):

(py38) > conda deactivate
> conda activate py38
(py38) > poetry install
Installing dependencies from lock file
Warning: The lock file is not up to date with the latest changes in pyproject.toml. You may be getting outdated dependencies. Run update to update them.

Package operations: 109 installs, 1 update, 0 removals
... Success

(py38) > poetry update
Updating dependencies
Resolving dependencies...

Package operations: 0 installs, 12 updates, 0 removals
  • Updating pyrsistent (0.14.11 -> 0.17.3)

  EnvCommandError

  Command %userprofile%\anaconda3\envs\py38\Scripts\pip.exe install --no-deps -U file:///%localappdata%/pypoetry/Cache/artifacts/d8/37/43/5ceed6677fc301784b0e62604a431e293d12c402f4ca588304e916a04d/pyrsistent-0.17.3.tar.gz errored with the following return code 1, and output:
  Processing %localappdata%\pypoetry\cache\artifacts\d8\37\43\5ceed6677fc301784b0e62604a431e293d12c402f4ca588304e916a04d\pyrsistent-0.17.3.tar.gz
  DEPRECATION: Source distribution is being reinstalled despite an installed package having the same name and version as the installed package. pip 21.1 will remove support for this functionality. A possible replacement is use --force-reinstall. You can find discussion regarding this at https://github.com/pypa/pip/issues/8711.
  Building wheels for collected packages: pyrsistent
    Building wheel for pyrsistent (setup.py): started
    Building wheel for pyrsistent (setup.py): finished with status 'done'
    Created wheel for pyrsistent: filename=pyrsistent-0.17.3-cp38-cp38-win_amd64.whl size=69929 sha256=f57e67ff423c007a7454a69802f98795f5820a74302420cae446f532c6a330b5
    Stored in directory: %localappdata%\pip\cache\wheels\a5\ec\eb\1099d304414c3dbb988074a0492d6133e2f9fe79aeabb8e7d3
  Successfully built pyrsistent
  Installing collected packages: pyrsistent
    Attempting uninstall: pyrsistent
      Found existing installation: pyrsistent 0.17.3
      Uninstalling pyrsistent-0.17.3:
        Successfully uninstalled pyrsistent-0.17.3
  ERROR: Could not install packages due to an OSError: [WinError 5] Access is denied: '%localappdata%\\Temp\\pip-uninstall-d38fmiix\\pvectorc.cp38-win_amd64.pyd'
  Consider using the `--user` option or check the permissions.

  at ~\anaconda3\envs\py38\lib\site-packages\poetry\utils\env.py:1074 in _run
      1070│                 output = subprocess.check_output(
      1071│                     cmd, stderr=subprocess.STDOUT, **kwargs
      1072│                 )
      1073│         except CalledProcessError as e:
    → 1074│             raise EnvCommandError(e, input=input_)
      1075│
      1076│         return decode(output)
      1077│
      1078│     def execute(self, bin, *args, **kwargs):

[Pluckerpluck]

It wasn't merged becuase I happend to stop using poetry (it was for work originally) and never got around to adding the tests required to merge the pull request.

I'll tell you what. I'll try to clean it up and update the pull request over this weekend. No promises though. I literally don't use poetry anymore...

Note: You can manually apply this patch yourself to Poetry if you want it.

Edit: Yep... ended up doing nothing. Mostly becuase I completley forgot about this....

[HenriqueAJNB]

Any news about this issue? I'm still having same problem...

[da1910]

The PR python-poetry/poetry-core#460 recreates the patch that should address the issue.

It looks to be a fairly widespread problem with poetry on windows and fails about 10% of our CI builds.

[da1910]

@python-poetry/triage

[mohghaderi]

It is 2023. I just switched to Poetry and this is still a problem.

The following error occurred when trying to handle this error:


  EnvCommandError

  Command C:\Miniconda3\envs\***\python.exe -m pip install --disable-pip-version-check --isolated --no-input --prefix C:\Miniconda3\envs\**** --upgrade --no-deps C:\Users\runneradmin\AppData\Local\pypoetry\Cache\artifacts\2b\25\ee\fa64b49cb[44](https://github.com/****/****/actions/runs/4237515315/jobs/7363564400#step:5:45)c9c392acf26e69ee8314d3b386932de86a99[45](https://github.com/*****/****/actions/runs/4237515315/jobs/7363564400#step:5:46)f4ad2e633\charset_normalizer-2.0.12-py3-none-any.whl errored with the following return code 1, and output: 
  Processing c:\users\runneradmin\appdata\local\pypoetry\cache\artifacts\2b\25\ee\fa64b[49](https://github.com/*****/****/actions/runs/4237515315/jobs/7363564400#step:5:50)cb44c9c392acf26e69ee8314d3b386932de86a9945f4ad2e633\charset_normalizer-2.0.12-py3-none-any.whl

  Installing collected packages: charset-normalizer

    Attempting uninstall: charset-normalizer

      Found existing installation: charset-normalizer 2.1.1

      Uninstalling charset-normalizer-2.1.1:

        Successfully uninstalled charset-normalizer-2.1.1

  ERROR: Could not install packages due to an OSError: [WinError 5] Access is denied: 'C:\\Users\\runneradmin\\AppData\\Local\\Temp\\pip-uninstall-fg75vu21\\normalizer.exe'

  Consider using the --user option or check the permissions.

Any suggestions?

[xmnlab]

Hey .. I can understand that you are frustraded.. but there is a gold rule in all projects in the entire world .. be kind!

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.