uvicorn
uvicorn copied to clipboard
encode
Duplicate logs when use logging.basicConfig in application
Checklist
- [X] The bug is reproducible against the latest release or
master. - [X] There are no similar issues or pull requests to fix it yet.
Describe the bug
When use logging.basicConfig to config logging in application, uvicorn logs will duplicate in console.
Steps to reproduce the bug
app.py:
import logging
from fastapi import FastAPI
logging.basicConfig(level=logging.INFO)
app = FastAPI(debug=True)
run it:
uvicorn app:app
Expected behavior
expect no duplicate logs.
Actual behavior
uvicorn.error logs duplicated:
INFO: Started server process [85610]
INFO:uvicorn.error:Started server process [85610]
INFO: Waiting for application startup.
INFO:uvicorn.error:Waiting for application startup.
INFO: Application startup complete.
INFO:uvicorn.error:Application startup complete.
INFO: Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:uvicorn.error:Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
Debugging material
I think the uvicorn logger should not propagate, because it already handled by uvicorn handler. And the behavior of gunicorn is no duplicate logs.
Add "propagate": False to https://github.com/encode/uvicorn/blob/master/uvicorn/config.py#L107 can fix the issue.
"uvicorn": {"handlers": ["default"], "level": "INFO", "propagate": False},
Environment
Running uvicorn 0.15.0 with CPython 3.9.7 on Darwin
Additional context
Maybe related: https://github.com/encode/uvicorn/issues/614
...
Debugging material
I think the uvicorn logger should not propagate, because it already handled by uvicorn handler. And the behavior of gunicorn is no duplicate logs.
Add
"propagate": Falseto https://github.com/encode/uvicorn/blob/master/uvicorn/config.py#L107 can fix the issue. ...
Adding propagate = False is not a fix. It turs off all uvicorn's logs.
Adding
propagate = Falseis not a fix. It turs off all uvicorn's logs.
@gretkierewicz That's not correct, propagate = False just stop propagate logs to ancestors, the log message still handled by uvicorn log handers.
Python Docs also note that If you attach a handler to a logger and one or more of its ancestors, it may emit the same record multiple times. :
https://docs.python.org/3/library/logging.html#logging.Logger.propagate
propagate If this attribute evaluates to true, events logged to this logger will be passed to the handlers of higher level (ancestor) loggers, in addition to any handlers attached to this logger. Messages are passed directly to the ancestor loggers’ handlers - neither the level nor filters of the ancestor loggers in question are considered.
If this evaluates to false, logging messages are not passed to the handlers of ancestor loggers.
The constructor sets this attribute to True.
Note If you attach a handler to a logger and one or more of its ancestors, it may emit the same record multiple times. In general, you should not need to attach a handler to more than one logger - if you just attach it to the appropriate logger which is highest in the logger hierarchy, then it will see all events logged by all descendant loggers, provided that their propagate setting is left set to True. A common scenario is to attach handlers only to the root logger, and to let propagation take care of the rest.
@matthew-viglione My workaround in the meantime has been:
uvicorn_logger = logging.getLogger("uvicorn")
uvicorn_logger.removeHandler(uvicorn_logger.handlers[0])
