watchfiles icon indicating copy to clipboard operation
watchfiles copied to clipboard

_rust_notify.WatchfilesRustInternalError: error in underlying watcher: IO error for operation on <python path>: No such file or directory (os error 2)

Open pavdwest opened this issue 1 year ago • 19 comments

Description

Details

This error occurs on uvicorn startup in a docker environment (based on python:3.11-slim) when using the uvicorn --reload flag. The path is pointing to the python3 executable of my virtual environment i.e. /backend/app/.ignore/venv/bin/python3.

Full stack trace:

Attaching to backend-1
backend-1  | INFO:     Will watch for changes in these directories: ['/backend/app/src']
backend-1  | INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
backend-1  | INFO:     Started reloader process [1] using WatchFiles
backend-1  | Traceback (most recent call last):
backend-1  |   File "/opt/venv/bin/uvicorn", line 8, in <module>
backend-1  |     sys.exit(main())
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/click/core.py", line 1157, in __call__
backend-1  |     return self.main(*args, **kwargs)
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/click/core.py", line 1078, in main
backend-1  |     rv = self.invoke(ctx)
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/click/core.py", line 1434, in invoke
backend-1  |     return ctx.invoke(self.callback, **ctx.params)
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/click/core.py", line 783, in invoke
backend-1  |     return __callback(*args, **kwargs)
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/uvicorn/main.py", line 410, in main
backend-1  |     run(
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/uvicorn/main.py", line 572, in run
backend-1  |     ChangeReload(config, target=server.run, sockets=[sock]).run()
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/uvicorn/supervisors/basereload.py", line 52, in run
backend-1  |     for changes in self:
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/uvicorn/supervisors/basereload.py", line 71, in __next__
backend-1  |     return self.should_restart()
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/uvicorn/supervisors/watchfilesreload.py", line 84, in should_restart
backend-1  |     changes = next(self.watcher)
backend-1  |   File "/opt/venv/lib/python3.10/site-packages/watchfiles/main.py", line 121, in watch
backend-1  |     raw_changes = watcher.watch(debounce, step, rust_timeout, stop_event)
backend-1  | _rust_notify.WatchfilesRustInternalError: error in underlying watcher: IO error for operation on /backend/app/.ignore/venv/bin/python3: No such file or directory (os error 2)

Workaround

Specifically adding watchfiles==0.21.0 as a dependency to my project resolves the issue.

Example Code

No response

Watchfiles Output

No response

Operating System & Architecture

docker on WSL2

Environment

docker on WSL2

Python & Watchfiles Version

0.21.0

Rust & Cargo Version

No response

pavdwest avatar Jun 10 '24 09:06 pavdwest

I am encountering the same issue with the python:3.12 image in a Docker environment.

[INFO    ] uvicorn.error                Started reloader process [1] using WatchFiles
2024-07-11T07:46:39.569087513Z Traceback (most recent call last):
2024-07-11T07:46:39.569115724Z   File "/usr/local/bin/uvicorn", line 8, in <module>
2024-07-11T07:46:39.569144685Z     sys.exit(main())
2024-07-11T07:46:39.569283202Z              ^^^^^^
2024-07-11T07:46:39.569294901Z   File "/usr/local/lib/python3.12/site-packages/click/core.py", line 1157, in __call__
2024-07-11T07:46:39.569837086Z     return self.main(*args, **kwargs)
2024-07-11T07:46:39.569989674Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.569999019Z   File "/usr/local/lib/python3.12/site-packages/click/core.py", line 1078, in main
2024-07-11T07:46:39.570281225Z     rv = self.invoke(ctx)
2024-07-11T07:46:39.570345184Z          ^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.570351464Z   File "/usr/local/lib/python3.12/site-packages/click/core.py", line 1434, in invoke
2024-07-11T07:46:39.570876094Z     return ctx.invoke(self.callback, **ctx.params)
2024-07-11T07:46:39.570959284Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.570965594Z   File "/usr/local/lib/python3.12/site-packages/click/core.py", line 783, in invoke
2024-07-11T07:46:39.571316660Z     return __callback(*args, **kwargs)
2024-07-11T07:46:39.571370793Z            ^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.571414922Z   File "/usr/local/lib/python3.12/site-packages/uvicorn/main.py", line 409, in main
2024-07-11T07:46:39.571692182Z     run(
2024-07-11T07:46:39.571695338Z   File "/usr/local/lib/python3.12/site-packages/uvicorn/main.py", line 570, in run
2024-07-11T07:46:39.571900914Z     ChangeReload(config, target=server.run, sockets=[sock]).run()
2024-07-11T07:46:39.572028074Z   File "/usr/local/lib/python3.12/site-packages/uvicorn/supervisors/basereload.py", line 52, in run
2024-07-11T07:46:39.572163893Z     for changes in self:
2024-07-11T07:46:39.572166135Z   File "/usr/local/lib/python3.12/site-packages/uvicorn/supervisors/basereload.py", line 71, in __next__
2024-07-11T07:46:39.572287645Z     return self.should_restart()
2024-07-11T07:46:39.572317381Z            ^^^^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.572319028Z   File "/usr/local/lib/python3.12/site-packages/uvicorn/supervisors/watchfilesreload.py", line 84, in should_restart
2024-07-11T07:46:39.572481425Z     changes = next(self.watcher)
2024-07-11T07:46:39.572510339Z               ^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.572512022Z   File "/usr/local/lib/python3.12/site-packages/watchfiles/main.py", line 121, in watch
2024-07-11T07:46:39.572657979Z     raw_changes = watcher.watch(debounce, step, rust_timeout, stop_event)
2024-07-11T07:46:39.572720183Z                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-07-11T07:46:39.572757959Z _rust_notify.WatchfilesRustInternalError: error in underlying watcher: IO error for operation on /code/.venv/bin/python: No such file or directory (os error 2)

Downgrading from "0.22.0" to "0.21.0" fix the problem.

renaudcepre avatar Jul 11 '24 07:07 renaudcepre

Does the file being watched exist?

samuelcolvin avatar Aug 07 '24 11:08 samuelcolvin

The error message points to an IO issue for /code/.venv/bin/python. I think it's unusual for the watcher to monitor the python executable itself. Using the same virtual environment but downgrading resolves the issue, which suggests that python exists and the problem might be related to compatibility with the newer version. For the rest of the files, it's my FastAPI app, and I don't change any files when I downgrade. 🤷

renaudcepre avatar Aug 08 '24 16:08 renaudcepre

thanks, I assume v0.23 has the same issue?

samuelcolvin avatar Aug 08 '24 16:08 samuelcolvin

thanks, I assume v0.23 has the same issue?

I am getting same error, also Docker on WSL2 (Ubuntu 22.04).

I get error on 0.22.0 and 0.23.0 but not 0.21.0

BakerNet avatar Aug 09 '24 21:08 BakerNet

I found that because I am mounting my root folder to the docker container, having a virtual environment in my local root will break watchfiles in the container.

The workaround I am using to fix this: Mount an empty volume at /<root path>/.venv on the container so that watchefiles doesn't see the virtual environment from my local

BakerNet avatar Aug 10 '24 00:08 BakerNet

Thanks so much for the feedback, please could you try with force_polling and see if the error still occurs?

samuelcolvin avatar Aug 10 '24 08:08 samuelcolvin

Thanks so much for the feedback, please could you try with force_polling and see if the error still occurs?

force_pulling appears to be on - running _default_force_polling(None) returns True

Edit: Btw, my errors are actually resolved if I WATCHFILES_FORCE_POLLING=disabled 🤷

BakerNet avatar Aug 12 '24 18:08 BakerNet

Maybe this has the same cause as #294?

samuelcolvin avatar Aug 12 '24 21:08 samuelcolvin

Maybe this has the same cause as https://github.com/samuelcolvin/watchfiles/issues/294?

I can't tell. However, I did some testing, and the change that broke it is upgrading notify in the Cargo deps. When I re-build with notify = "5.2.0" the errors are resolved.

BakerNet avatar Aug 13 '24 01:08 BakerNet

I found that because I am mounting my root folder to the docker container, having a virtual environment in my local root will break watchfiles in the container.

The workaround I am using to fix this: Mount an empty volume at /<root path>/.venv on the container so that watchefiles doesn't see the virtual environment from my local

For reference, I'm also mounting an empty volume at /<root>/.../.ignored/ and creating both my local and container .venv folders in there. In fact it's used for all things I don't want synced between the containers and local. This has been my setup from the start so I'm a bit confused as to why this would work for you but not for me.

pavdwest avatar Aug 23 '24 07:08 pavdwest

I've encountered the issue without using the Docker. I was tinkering with the FastHTML library (https://docs.fastht.ml/). A couple of seconds after uvicorn starts, a similar error is thrown, even though I am not even using Docker:

_rust_notify.WatchfilesRustInternalError: error in underlying watcher: IO error for operation on /home/my_username/.docker/features.json: No such file or directory (os error 2)

A similar error occurs when running py-shiny (https://shiny.posit.co/py/) applications, which is also using uvicorn and starlette under the hood. I run both using VS Code in WSL.

Downgrading watchfiles to 0.21.0 resolves the issue.

kovla avatar Aug 25 '24 07:08 kovla

I think this is related to https://github.com/notify-rs/notify/issues/581, I think we need to either ignore this error, or return a "file deleted" event.

samuelcolvin avatar Aug 25 '24 07:08 samuelcolvin

@kovla can you confirm if which watcher is being used? Is it the polling watcher, like @BakerNet experienced.

You can run watchfiles with verbose true I think to get the poller printed.

samuelcolvin avatar Aug 25 '24 07:08 samuelcolvin

@kovla can you confirm if which watcher is being used? Is it the polling watcher, like @BakerNet experienced.

I could, potentially, if you were to describe the procedure. I am simply running an app (Shiny, fastHTML, etc), without understanding the fine nuances of what is happening in the background (uvicorn, starlette, etc).

kovla avatar Aug 25 '24 08:08 kovla

Turns out there's no env var to enable debug, but I think I have enough to fix this.

samuelcolvin avatar Aug 25 '24 09:08 samuelcolvin

I think this is fixed by #301, but I don't have windows or WSL, so I can't test it.

Please can someone who has experienced his error install watchfiles from #301 and check if it is indeed fixed.

samuelcolvin avatar Aug 26 '24 18:08 samuelcolvin

@samuelcolvin I wouldn't call this a very thorough test, but I did install the new version from a wheel, and the error does NOT pop up where it used to previously. Just before the installation I was able to trigger the error with v0.23 (within 10 seconds or so after uvicorn launch), and with the new version I did not get any errors after about 3 minutes of interacting with the app.

kovla avatar Aug 26 '24 20:08 kovla

That's great news, thank you.

I'll wait a day or two to see if someone else can also check it and confirm the error is gone, then make a release.

samuelcolvin avatar Aug 27 '24 08:08 samuelcolvin

This issue still persists on Windows WSL2, any quick fixes for it?

UPDATE : Had to Install Rust through the CLI to fix this

gssakash-SxT avatar Aug 29 '24 06:08 gssakash-SxT

It should be fixed with the latest release on pypi.

samuelcolvin avatar Aug 29 '24 07:08 samuelcolvin

This issue still persists on Windows WSL2 Ubuntu 22.04, as part of unicorn[standart]

octrow avatar Dec 25 '24 16:12 octrow

I get permission error with same rust error. The issue is that

 command: uvicorn main:app --host 0.0.0.0 --port 8000 --reload --log-level debug --lifespan on --reload-exclude postgres_data 

the reload-exclude doesn't seem to work in latest version.

vishesh-bimacred avatar Jan 30 '25 18:01 vishesh-bimacred

This issue is closed, if you're having problems, please create a new issue.

samuelcolvin avatar Jan 31 '25 04:01 samuelcolvin