disable_existing_loggers not working when reload enabled

[ttecles]

Hi,

I am seeing a strange behaviour when setting the log_config and there is already a log handler set. I have a framework that already sets the format for me so I don't want uvicorn to set formatting and just propagate the errors to the root logger which holds the handlers and the formatters

Here is the code I am using to reproduce it:

import logging
import sys

import uvicorn
from fastapi import FastAPI

app = FastAPI()


@app.get("/")
def read_root():
    return {"Hello": "World"}


if __name__ == "__main__":
    h = logging.StreamHandler(sys.stdout)
    h.setFormatter(logging.Formatter("%(asctime)s %(levelname)-8s %(name)-20s %(message)s"))
    logger = logging.getLogger()
    logger.addHandler(h)
    logger.setLevel(logging.DEBUG)

    uvicorn.run(
        "uvicorn_issue:app",
        host="0.0.0.0",
        port=8000,
        reload=False,
        # Disables the current uvicorn handler and enables propagation to allow the root handler
        # format the log
        log_config={
            "version": 1,
            "disable_existing_loggers": False,
            "loggers": {"uvicorn": {"propagate": True}, "uvicorn.access": {"propagate": True}},
        },
        use_colors=None,
    )

And here is the output when I access http://localhost:8000/:

$ python uvicorn_issue.py 
2024-01-03 07:38:14,313 INFO     uvicorn.error        Started server process [115317]
2024-01-03 07:38:14,313 INFO     uvicorn.error        Waiting for application startup.
2024-01-03 07:38:14,313 INFO     uvicorn.error        Application startup complete.
2024-01-03 07:38:14,314 INFO     uvicorn.error        Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
2024-01-03 07:38:25,685 INFO     uvicorn.access       127.0.0.1:41716 - "GET / HTTP/1.1" 200
^C2024-01-03 07:38:29,866 INFO     uvicorn.error        Shutting down
2024-01-03 07:38:29,967 INFO     uvicorn.error        Waiting for application shutdown.
2024-01-03 07:38:29,967 INFO     uvicorn.error        Application shutdown complete.
2024-01-03 07:38:29,967 INFO     uvicorn.error        Finished server process [115317]

But see what happens if I enable the reload (reload=True) and access the index path http://localhost:8000/:

$ python uvicorn_issue.py 
2024-01-03 07:44:46,072 INFO     uvicorn.error        Will watch for changes in these directories: ['/home/joan/apps/product-images']
2024-01-03 07:44:46,072 INFO     uvicorn.error        Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
2024-01-03 07:44:46,072 INFO     uvicorn.error        Started reloader process [116193] using WatchFiles
^C2024-01-03 07:44:55,304 INFO     uvicorn.error        Stopping reloader process [116193]

I get different uvicorn.error outputs which I guess it's ok since it's using the ChangeReload but I get no access logs which is strange. I have used logging_tree to see what's configured and seems it's not preserving the disable_existing_loggers:

<--""
   Level WARNING
   |
   o<--"asyncio"
   |   Level NOTSET so inherits level WARNING
   |
   o<--[concurrent]
   |   |
   |   o<--"concurrent.futures"
   |       Level NOTSET so inherits level WARNING
   |
   o<--"fastapi"
   |   Level NOTSET so inherits level WARNING
   |
   o<--"uvicorn"
   |   Level NOTSET so inherits level WARNING
   |   |
   |   o<--"uvicorn.access"
   |   |   Level NOTSET so inherits level WARNING
   |   |
   |   o<--"uvicorn.error"
   |       Level NOTSET so inherits level WARNING
   |
   o<--[watchfiles]
       |
       o<--"watchfiles.main"
       |   Level NOTSET so inherits level WARNING
       |
       o<--"watchfiles.watcher"
           Level NOTSET so inherits level WARNING

[mprymek]

It seems to me that you must set level. This works for me:

log_config = {
        'version': 1,
        'disable_existing_loggers': False,
        'loggers': {
            'uvicorn': {
                'level': 'INFO',
                'propagate': True
            },
            'uvicorn.access': {
                'level': 'INFO',
                'propagate': True
            },
            'uvicorn.error': {
                'level': 'INFO',
                'propagate': True
            },
        },
    }