RuntimeError: Already borrowed when using context managers

[bellini666]

Bug Description

This issue was originally reported in watchfiles, but the maintainer there said that it is probably an issue with this lib, maybe related to #1205

The issue is that I get RuntimeError: Already borrowed when exiting a code that uses a context manager

Steps to Reproduce

I created this small script which will raise the issue everytime I finish the process:

import asyncio
import signal

import watchfiles


async def watch_files():
    async for changes in watchfiles.awatch("/tmp/foobar"):
        pass


async def main():
    exit_event = asyncio.Event()

    loop = asyncio.get_running_loop()
    for s in [signal.SIGINT, signal.SIGTERM]:
        loop.add_signal_handler(s, exit_event.set)

    print("1) Initiating watch_files")
    task = asyncio.create_task(watch_files())
    await exit_event.wait()

    print("2) SIGINT detected, canceling the task")
    task.cancel()
    done_event = asyncio.Event()
    task.add_done_callback(lambda t: done_event.set())

    print("3) Waiting for the task to finish")
    await done_event.wait()
    print("4) task finished")


if __name__ == "__main__":
    print("** Before main")
    asyncio.run(main())
    print("** After main")

Just create a venv, install watchfiles in it and run the script. Close it with ctrl+C or by sending or kill -2 <PID>

Backtrace

future: <Task finished name='Task-9' coro=<Agent.process_door_events() done, defined at /home/bellini/dev/2u/nomad/nomad/agents/base.py:176> exception=RuntimeError('Already borrowed')>
Traceback (most recent call last):
  File "/home/bellini/dev/2u/nomad/nomad/agents/base.py", line 181, in process_door_events
    async for door_opened in self.listen_for_door_events():
  File "/home/bellini/dev/2u/nomad/nomad/agents/dev.py", line 66, in listen_for_door_events
    async for changes in watchfiles.awatch(self._incoming_file):
  File "/home/bellini/dev/2u/nomad/.venv/lib/python3.10/site-packages/watchfiles/main.py", line 222, in awatch
    with RustNotify([str(p) for p in paths], debug, force_polling, poll_delay_ms) as watcher:
RuntimeError: Already borrowed

Your operating system and version

Debian Sid

Your Python version (python --version)

Python 3.10.5

Your Rust version (rustc --version)

rustc 1.59.0

Your PyO3 version

The one used by watchfiles

How did you install python? Did you use a virtualenv?

apt

Additional Info

No response

[samuelcolvin]

I think it could be related to this code:

    /// https://github.com/PyO3/pyo3/issues/1205#issuecomment-1164096251 for advice on `__enter__`
    pub fn __enter__(slf: Py<Self>) -> Py<Self> {
        slf
    }

But I really don't know.

[samuelcolvin]

@davidhewitt any chance this could be fixed by reverting to the #1205 (comment) solution?

I guess @bellini666 trying out a build using PyRef instead of Py would at least tell us if __enter__ was the problem.

I'd be happier if we knew in what situation this happens and why.

[davidhewitt]

I would think that more likely the &mut access for .close() and __exit__ would be the source of the problem. @bellini666 are you able to perform any debugging to figure out the call stack when the exception is raised?

Py is almost certainly unrelated as it wouldn't even trigger the throw - the error is caused by the framework calling PyCell::try_borrow_mut() when a PyRef is live.

[bellini666]

@davidhewitt just send me the instructions and I can try :)

[mejrs]

@davidhewitt just send me the instructions and I can try :)

You can try the following to (hopefully) get a better error message:

1. Fork the watchfiles repository
2. Replace the pyo3 dependency with:

pyo3 = { git = "https://github.com/mejrs/pyo3", branch ="debug_pycell", features = ["abi3-py37", "extension-module", "debug_pycell"] }

3. Compile the extension and run your snippet with it installed.

I would try it myself, but your repro doesn't work on windows unfortunately (signal support is rather bad on it)

[samuelcolvin]

Watchfiles does work on windows, but no one other than @bellini666 has reported this error, so you probably won't see the error.

[bellini666]

@mejrs @samuelcolvin I'll try the instructions here.

Just so I know, how exactly am I supposed to build and run watchfiles from source? I never worked with a python package with rust extensions before (and I'm not used to rust itself), so I'm not really sure the steps I should follow.

[davidhewitt]

@bellini666 you should be able to do the following:

• install Rust from rustup.rs
• clone watch files repository
• cd into the cloned repo
• make virtualenv
• make the change @mejrs provided above
• pip install . to build the local watch files
• run this new watchfiles and trigger your bug

If you get stuck at any point feel free to ask here - the point of PyO3 is to make building Rust & Python software straightforward ☺️

[bellini666]

Hi @davidhewitt , sorry for not being able to do this soon.

I got ModuleNotFoundError when running the test:

❯ python3 xxx.py 
Traceback (most recent call last):
  File "/tmp/watchfiles/xxx.py", line 4, in <module>
    import watchfiles
  File "/tmp/watchfiles/watchfiles/__init__.py", line 2, in <module>
    from .main import Change, awatch, watch
  File "/tmp/watchfiles/watchfiles/main.py", line 11, in <module>
    from ._rust_notify import RustNotify
ModuleNotFoundError: No module named 'watchfiles._rust_notify'

I did install it in the venv using just pip install .. Is there something missing? Here is the output:

❯ pip install .
Processing /tmp/watchfiles
  Installing build dependencies ... done
  Getting requirements to build wheel ... done
  Preparing metadata (pyproject.toml) ... done
Collecting anyio<4,>=3.0.0
  Using cached anyio-3.6.1-py3-none-any.whl (80 kB)
Collecting sniffio>=1.1
  Using cached sniffio-1.2.0-py3-none-any.whl (10 kB)
Collecting idna>=2.8
  Using cached idna-3.3-py3-none-any.whl (61 kB)
Building wheels for collected packages: watchfiles
  Building wheel for watchfiles (pyproject.toml) ... done
  Created wheel for watchfiles: filename=watchfiles-0.0.0-cp37-abi3-linux_x86_64.whl size=2687211 sha256=a7c34688df16158acc945f19fd3a8e0533f8afdcb4512c62487bd11c25f4b1a0
  Stored in directory: /tmp/pip-ephem-wheel-cache-xy2ovwn2/wheels/36/d3/ee/b4f1a55f15ae5410a37f47414ad08c63994ae0557e9dd3c4f3
Successfully built watchfiles
Installing collected packages: sniffio, idna, anyio, watchfiles
Successfully installed anyio-3.6.1 idna-3.3 sniffio-1.2.0 watchfiles-0.0.0

[messense]

@bellini666 Try pip install -e ..

[samuelcolvin]

@messense is correct, but just to give some context, ModuleNotFoundError is because the binary module - the bit of watchfiles which is compiled from rust, can't be found. Either it didn't compile correctly, or python is looking for it in the wrong place.

[davidhewitt]

In this case, it's because pip install . put the binary module into your virtualenv's site-packages folder and then import watchfiles was loading the local source which didn't have the binary module in it.

@messense I wonder if we should make pip install <path> with the maturin pep 517 backend put a copy of the binary module into the original Python source (the location it would go with pip install -e <path>). I think it would avoid this trap?

[samuelcolvin]

Or a symlink?

[davidhewitt]

Imo there's not a 1:1 relationship between the source and virtualenv lib dir - the same source could be used for many virtualenvs. I don't think the overhead of making a copy is likely to matter?

[davidhewitt]

...maybe a symlink to the target/ dir though?

[adamreichold]

...maybe a symlink to the target/ dir though?

This is what I personally like to go for when working on mixed Rust-Python packages, so that I can immediately import after cargo build.

[messense]

I wonder if we should make pip install with the maturin pep 517 backend put a copy of the binary module into the original Python source (the location it would go with pip install -e ). I think it would avoid this trap?

I'd like to take a look at how setuptools handles this before making the change.

[messense]

Taking hiredis-py as an example, looks like setuptools does the same as maturin currently.

$ pip install .
Processing /Users/messense/Projects/hiredis-py
  Preparing metadata (setup.py) ... done
Building wheels for collected packages: hiredis
  Building wheel for hiredis (setup.py) ... done
  Created wheel for hiredis: filename=hiredis-2.0.0-cp39-cp39-macosx_12_0_arm64.whl size=24683 sha256=86eb40187ac9a12c7207603879b4c66de4aac6d5f69b4f94e4ca134a6689294c
  Stored in directory: /Users/messense/Library/Caches/pip/wheels/8a/65/26/c52a303875a91e19d401a8aa5d20317422b76f647db8608423
Successfully built hiredis
Installing collected packages: hiredis
Successfully installed hiredis-2.0.0

$ ls hiredis/
__init__.py __pycache__ hiredis.pyi py.typed    version.py

$ ls hiredis/__pycache__/
version.cpython-39.pyc

$ python
Python 3.9.11 (main, Mar 21 2022, 19:37:23)
[Clang 13.1.6 (clang-1316.0.21.2)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import hiredis
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/Users/messense/Projects/hiredis-py/hiredis/__init__.py", line 1, in <module>
    from .hiredis import Reader, HiredisError, ProtocolError, ReplyError
ModuleNotFoundError: No module named 'hiredis.hiredis'

[davidhewitt]

Ok, in which case probably best to keep consistency with setuptools for now, thanks for checking 👍

[bellini666]

Hey guys,

The issue suddenly is not happening anymore.. I tried at the weekend in my personal computer (which also runs Debian Sid) and was unable to reproduce the issue. I tried now in my office computer, which I could reproduce the issue 100% of the times and I also can't.

What changed since I opened the issue is that Debian updated the python3 package from 3.10.4 to 3.10.5. Maybe it fixed it?

Strange that searching for RuntimeError at the python changelog there's a fix for this exact problem in 3.10.6 mentioning that it was happening on Windows. My issue was not on Windows and also I'm still using 3.10.5 =P

Either way, this can probably be closed.

[messense]

Feel free to reopen if it happens again.

[07pepa]

as you can se this is reliebly hapening even on fresh docker instalation....

samuelcolvin/watchfiles#200

please try to solve it

[adamreichold]

as you can se this is reliebly hapening even on fresh docker instalation....

samuelcolvin/watchfiles#200

please try to solve it

@07pepa The next step here is still #2525 (comment) done by someone who is able to reproduce this, so that we can get a backtrace of the Rust side to figure where the exception originates and determine whether something in PyO3 or in watchfiles needs to be changed.

[07pepa]

ok i will try over next few weekends... and if i get it done in docker you will get dockerfile as well (to help fixing it)

[wbadart]

Hey all- I've reproduced this on a fresh watchfiles clone (samuelcolvin/watchfiles@014b258). Here's my updated Cargo.toml:

diff --git a/Cargo.toml b/Cargo.toml
index 2e2395a..1dd4065 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -25,7 +25,8 @@ include = [
 [dependencies]
 crossbeam-channel = "0.5.4"
 notify = "5.0.0"
-pyo3 = {version = "0.17.3", features = ["extension-module", "abi3-py37"]}
+# pyo3 = {version = "0.17.3", features = ["extension-module", "abi3-py37"]}
+pyo3 = { git = "https://github.com/mejrs/pyo3", branch ="debug_pycell", features = ["abi3-py37", "extension-module", "debug_pycell"] }
 
 [lib]
 name = "_rust_notify"

and Cargo.lock in case it's helpful.

diff --git a/Cargo.lock b/Cargo.lock index 9ac837b..f40deb3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -240,9 +240,8 @@ dependencies = [

[[package]]
name = "pyo3"
-version = "0.17.3"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "268be0c73583c183f2b14052337465768c07726936a260f480f0857cb95ba543"
+version = "0.16.5"
+source = "git+https://github.com/mejrs/pyo3?branch=debug_pycell#17720185fa913cc14b85a5a10ea630ac4b6fd9be"
dependencies = [
"cfg-if",
"indoc",
@@ -257,9 +256,8 @@ dependencies = [

[[package]]
name = "pyo3-build-config"
-version = "0.17.3"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "28fcd1e73f06ec85bf3280c48c67e731d8290ad3d730f8be9dc07946923005c8"
+version = "0.16.5"
+source = "git+https://github.com/mejrs/pyo3?branch=debug_pycell#17720185fa913cc14b85a5a10ea630ac4b6fd9be"
dependencies = [
"once_cell",
"target-lexicon",
@@ -267,9 +265,8 @@ dependencies = [

[[package]]
name = "pyo3-ffi"
-version = "0.17.3"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "0f6cb136e222e49115b3c51c32792886defbfb0adead26a688142b346a0b9ffc"
+version = "0.16.5"
+source = "git+https://github.com/mejrs/pyo3?branch=debug_pycell#17720185fa913cc14b85a5a10ea630ac4b6fd9be"
dependencies = [
"libc",
"pyo3-build-config",
@@ -277,9 +274,8 @@ dependencies = [

[[package]]
name = "pyo3-macros"
-version = "0.17.3"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "94144a1266e236b1c932682136dc35a9dee8d3589728f68130c7c3861ef96b28"
+version = "0.16.5"
+source = "git+https://github.com/mejrs/pyo3?branch=debug_pycell#17720185fa913cc14b85a5a10ea630ac4b6fd9be"
dependencies = [
"proc-macro2",
"pyo3-macros-backend",
@@ -289,9 +285,8 @@ dependencies = [

[[package]]
name = "pyo3-macros-backend"
-version = "0.17.3"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c8df9be978a2d2f0cdebabb03206ed73b11314701a5bfe71b0d753b81997777f"
+version = "0.16.5"
+source = "git+https://github.com/mejrs/pyo3?branch=debug_pycell#17720185fa913cc14b85a5a10ea630ac4b6fd9be"
dependencies = [
"proc-macro2",
"quote",

Running this script:

#!/usr/bin/env python3
import asyncio, watchfiles

async def watch():
    async for changes in watchfiles.awatch("."):
        for change in changes:
            print(change)

async def main():
    asyncio.create_task(watch())
    await asyncio.sleep(1)

asyncio.run(main())

I get this output:

unhandled exception during asyncio.run() shutdown
task: <Task finished name='Task-2' coro=<watch() done, defined at ./foo.py:4> exception=RuntimeError('Already borrowed')>
Traceback (most recent call last):
  File "./foo.py", line 5, in watch
    async for changes in watchfiles.awatch("."):
  File "watchfiles/main.py", line 238, in awatch
    with RustNotify([str(p) for p in paths], debug, force_polling, poll_delay_ms, recursive) as watcher:
RuntimeError: Already borrowed

A little about my system:

$ python -c 'import platform; print(platform.platform()); print(platform.version())'
macOS-12.6.1-x86_64-i386-64bit
Darwin Kernel Version 21.6.0: Thu Sep 29 20:12:57 PDT 2022; root:xnu-8020.240.7~1/RELEASE_X86_64
$ pip show watchfiles
Name: watchfiles
Version: 0.0.0
...
$ python -c 'import sys; print(sys.version)'
3.11.0 (main, Nov  9 2022, 20:11:02) [Clang 14.0.0 (clang-1400.0.29.202)]

Please let me know if there's something I should try to coax a little more information from the underlying Rust code.

[adamreichold]

I tried this and it does reproduce here as well, but I don't think this is a PyO3 issue.

The program blocks in RustWatcher::watch via

raw_changes = await anyio.to_thread.run_sync(watcher.watch, debounce, step, timeout, stop_event_)

from watchfile's main.py:245. RustNotify::watch takes &self, i.e. borrows the PyCell<RustNotify> backing watcher, and releases the GIL to sleep via

py.allow_threads(|| sleep(step_time));

in lib.rs:258 during which the main program shuts down thereby trying to call the context manager method RustNotify::__exit__ which takes &mut self, i.e. trying to take a conflicting borrow of the same PyCell<RustNotify>.

I think the fix here is to adjust RustNotify::watch to take slf: &PyCell<Self> instead of &self and to explicit borrow that cell whenever it wants access its state and to make sure to not keep that borrow while releasing the GIL. (This might also imply that the initial checking if the watcher has been closed must be repeated after the GIL is re-acquired.)

[samuelcolvin]

thanks so much both of you for looking into this. Would be wonderful if someone could submit a PR to watchfiles, otherwise I'll try to get to it when I have time.