Fix watchfiles file filtering

[br3ndonland]

Description

PR #1437 added file watching with watchfiles to a new module, uvicorn.supervisors.watchfilesreload. The module included a FileFilter class.

uvicorn/uvicorn/supervisors/watchfilesreload.py

Line 11 in b06cc63

class FileFilter:

Currently, the FileFilter class is instantiated when initializing class WatchFilesReload, but not passed to watchfiles.watch(). Instead, watchfiles.watch(watch_filter=None) is used.

uvicorn/uvicorn/supervisors/watchfilesreload.py

Lines 74 to 82 in b06cc63

	self.watch_filter = FileFilter(config)
	self.watcher = watch(
	*self.reload_dirs,
	watch_filter=None,
	stop_event=self.should_exit,
	# using yield_on_timeout here mostly to make sure tests don't
	# hang forever, won't affect the class's behavior
	yield_on_timeout=True,
	)

As a result, watchfiles does not filter out the expected changes. It detects changes to .mypy_cache and .pyc files that should be ignored.

Minimal repro:

mkdir uvicorn-watchfiles && cd $_
python3 -m venv .venv
. .venv/bin/activate
python -m pip install 'uvicorn[standard]==0.19.0' 'fastapi==0.87.0'
mkdir uvicorn_watchfiles
touch uvicorn_watchfiles/{__init__,main}.py

main.py:

#!/usr/bin/env python3
import uvicorn
from fastapi import FastAPI

LOG_LEVEL = "DEBUG"
LOGGING_CONFIG = {
    "version": 1,
    "disable_existing_loggers": True,
    "formatters": {
        "uvicorn": {
            "()": "uvicorn.logging.DefaultFormatter",
            "format": "%(levelprefix)s %(name)-10s %(message)s",
        },
    },
    "handlers": {
        "default": {
            "class": "logging.StreamHandler",
            "formatter": "uvicorn",
            "level": LOG_LEVEL,
            "stream": "ext://sys.stdout",
        }
    },
    "root": {"handlers": ["default"], "level": LOG_LEVEL},
    "loggers": {
        "fastapi": {"propagate": True},
        "uvicorn": {"propagate": True},
        "uvicorn.access": {"propagate": True},
        "uvicorn.asgi": {"propagate": True},
        "uvicorn.error": {"propagate": True},
        "watchfiles.main": {"propagate": True},
    },
}

app = FastAPI()


@app.get("/")
def index():
    return {"home": "index"}


if __name__ == "__main__":
    uvicorn.run(
        "main:app",
        log_config=LOGGING_CONFIG,
        port=8100,
        reload=True,
    )

Start it up:

~/dev/uvicorn-watchfiles via 🐍 v3.10.8 (.venv)
❯ python uvicorn_watchfiles/main.py
INFO:     uvicorn.error Will watch for changes in these directories: ['/Users/brendon/dev/uvicorn-watchfiles']
INFO:     uvicorn.error Uvicorn running on http://127.0.0.1:8100 (Press CTRL+C to quit)
INFO:     uvicorn.error Started reloader process [17460] using WatchFiles
INFO:     uvicorn.error Started server process [17462]
INFO:     uvicorn.error Waiting for application startup.
INFO:     uvicorn.error Application startup complete.

Save main.py, check the server logs, and note that watchfiles is detecting changes to .mypy_cache and .pyc files:

DEBUG:    watchfiles.main 1 change detected: {(<Change.modified: 2>, '/Users/brendon/dev/uvicorn-watchfiles/uvicorn_watchfiles/main.py')}
WARNING:  uvicorn.error WatchFiles detected changes in 'uvicorn_watchfiles/main.py'. Reloading...
INFO:     uvicorn.error Shutting down
INFO:     uvicorn.error Waiting for application shutdown.
INFO:     uvicorn.error Application shutdown complete.
INFO:     uvicorn.error Finished server process [17462]
DEBUG:    watchfiles.main 6 changes detected: {(<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/@plugins_snapshot.json'), (<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/uvicorn_watchfiles/main.meta.json.14bba34c58afcb99'), (<Change.deleted: 3>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/@plugins_snapshot.json.0ceebf87e3a886f7'), (<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/uvicorn_watchfiles/main.meta.json'), (<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/@plugins_snapshot.json.0ceebf87e3a886f7'), (<Change.deleted: 3>, '/Users/brendon/dev/uvicorn-watchfiles/.mypy_cache/3.11/uvicorn_watchfiles/main.meta.json.14bba34c58afcb99')}
INFO:     uvicorn.error Started server process [17481]
INFO:     uvicorn.error Waiting for application startup.
INFO:     uvicorn.error Application startup complete.
DEBUG:    watchfiles.main 3 changes detected: {(<Change.deleted: 3>, '/Users/brendon/dev/uvicorn-watchfiles/uvicorn_watchfiles/__pycache__/main.cpython-310.pyc.4403978160'), (<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/uvicorn_watchfiles/__pycache__/main.cpython-310.pyc.4403978160'), (<Change.added: 1>, '/Users/brendon/dev/uvicorn-watchfiles/uvicorn_watchfiles/__pycache__/main.cpython-310.pyc')}

Changes

This PR will:

• Update the arguments to FileFilter.__call__ to match those expected by watchfiles.watch().
• Pass the FileFilter instance to watchfiles.watch().

When the changes from this PR are used with the minimal repro above, watchfiles will correctly filter out changes to .mypy_cache and .pyc files.

~/dev/uvicorn-watchfiles via 🐍 v3.10.8 (.venv) took 30m39s
❯ python uvicorn_watchfiles/main.py
INFO:     uvicorn.error Will watch for changes in these directories: ['/Users/brendon/dev/uvicorn-watchfiles']
INFO:     uvicorn.error Uvicorn running on http://127.0.0.1:8100 (Press CTRL+C to quit)
INFO:     uvicorn.error Started reloader process [17571] using WatchFiles
INFO:     uvicorn.error Started server process [17573]
INFO:     uvicorn.error Waiting for application startup.
INFO:     uvicorn.error Application startup complete.
DEBUG:    watchfiles.main 1 change detected: {(<Change.modified: 2>, '/Users/brendon/dev/uvicorn-watchfiles/uvicorn_watchfiles/main.py')}
WARNING:  uvicorn.error WatchFiles detected changes in 'uvicorn_watchfiles/main.py'. Reloading...
INFO:     uvicorn.error Shutting down
INFO:     uvicorn.error Waiting for application shutdown.
INFO:     uvicorn.error Application shutdown complete.
INFO:     uvicorn.error Finished server process [17573]
INFO:     uvicorn.error Started server process [17586]
INFO:     uvicorn.error Waiting for application startup.
INFO:     uvicorn.error Application startup complete.

Tests pass without any changes, but it would be great to update the tests to prevent this problem from recurring.

In the future, we could simplify file filtering by removing the FileFilter class and using watchfiles filters instead. The main limitation is that watchfiles filters accept regular expressions for pattern matching (with re.compile). Uvicorn accepts globs instead of regexes.

Related

• Switch from watchgod to watchfiles #1437
• FileNotFoundError during development samuelcolvin/watchfiles#207

[Kludex]

cc @samuelcolvin

[samuelcolvin]

Are you sure what this doesn't mean we're calling the filter logic twice on every reload?

[br3ndonland]

Are you sure what this doesn't mean we're calling the filter logic twice on every reload?

Thank you for pointing that out @samuelcolvin. It was being called twice:

1. watchfiles.main._prep_changes
2. uvicorn.supervisors.watchfilesreload.WatchFilesReload.should_restart

I've dropped the duplicate call from should_restart.

I've also added a test that patches over FileFilter.__call__ and tracks the call count.

[samuelcolvin]

Humm, but I would still recommend the previous approach, since it avoids calling Path twice and iterating over changes unnecessarily.

I'm not sure why you were seeing reloads from changes which should have been ignored as I thought the old solution was correct.

It could definitely do with a comment explaining why we don't pass the filter to watch though.

[br3ndonland]

We're having to call Path twice because of watchfiles.

• watchfiles expects the type signature of the watch_filter argument to watchfiles.watch() to be Optional[Callable[[Change, str], bool]]
• watchfiles returns each FileChange as a two-tuple, with the file path as str (Tuple[Change, str]).

Happy to get some PRs to watchfiles if that helps.

[samuelcolvin]

Okay, I've looked into this and as i thought, the implementation is already correct, this PR should be closed.

Changes to .pyc files etc. that should be ignored are already being ignored, the only side effect of those changes is a log message if you manually enable logging of the watchfiles.main logger.

The change you've proposed here causes extra unnecessary processing in python which IMHO is worse than a log message on a logger which is not enabled by default.

The other solution here would be a wholesale change to how reload file filtering works so we could pass FileFilter.__call__ to watch which I think is unnecessary.

[samuelcolvin]

Happy to get some PRs to watchfiles if that helps.

IMHO watchfiles is fine as it is, it minimises the amount of python logic by operating on raw strings, not Paths. For most applications that's fine, if you really want to work with Path, disable built-in filtering with filter=None and post process changes, as we do here.

[samuelcolvin]

watchfiles expects the type signature of the watch_filter argument to watchfiles.watch() to be Optional[Callable[[Change, str], bool]]

One of the reasons we do that is so we could move the calls to the filter function into rust in future, hence I don't want to change the signature.

[Kludex]

ping @br3ndonland 👀

[br3ndonland]

🤷

[samuelcolvin]

Thanks @br3ndonland for reporting this, definitely worth investigating this and confirming things are working as I thought.

👍