2

I am trying out uvicorn and whenever the server is run, it says INFO:uvicorn.error:Application. How can I see what is causing the error? How do I print the error in the log?

» uvicorn serve:app --reload --log-level debug
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [207627] using statreload
INFO:     Started server process [207629]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:uvicorn.error:Application startup complete.

I have tried log-level but it doesnt seem to work

» uvicorn serve:app --reload --log-level trace
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [207665] using statreload
INFO:     Started server process [207667]
INFO:     Waiting for application startup.
TRACE:    ASGI [1] Started scope={'type': 'lifespan', 'asgi': {'version': '3.0', 'spec_version': '2.0'}}
TRACE:    ASGI [1] Receive {'type': 'lifespan.startup'}
TRACE:    ASGI [1] Send {'type': 'lifespan.startup.complete'}
TRACE:uvicorn.asgi:ASGI [1] Send {'type': 'lifespan.startup.complete'}
INFO:     Application startup complete.
INFO:uvicorn.error:Application startup complete.

3 Answers3

3

The reason you can't find the error is that it's not an error, it is the name of the logger (set in uvicorn/main.py):

logger = logging.getLogger("uvicorn.error")

If you look inside the startup() function of that module there is a logger.info(... which generates that log message you're seeing using the logger named uvicorn.error.

There's an open (at the time of writing it is open) issue about the logger name being confusing (but the good news is it's just a name not an error): https://github.com/encode/uvicorn/issues/562

Ben
  • 1,759
  • 1
  • 19
  • 23
1

Ben explained part of the reason. I don't deem a bug of uvicorn, but questioner didn't configure logger correctly.

Uvicorn have some internal loggers like uvicorn, uvicorn:access, uvicorn.error, uvicorn.asgi. And uvicorn.error logger propagates the msg by default.

INFO: Application startup complete. is logged by uvicorn.error logger. INFO:uvicorn.error:Application startup complete. is logged by some parent logger, probably root handler.

The solution is to stop a msg handled by two logger.

  1. Stop setting up handler for parent logger, probably root logger. (preferred)

  2. Or Disable uvicorn.error propagating.

    logger = logging.getLogger("uvicorn.error")
logger.propagate = False
Simba
  • 23,537
  • 7
  • 64
  • 76
0

I created another solution for this. I created a class NameFilter which filter out the different logger names and rename them directly.

logger.py > Usage

name_filter = NameFilter()
console_handler.addFilter(name_filter)

logger.py > Class

class NameFilter(logging.Filter):
    def filter(self, record):
        if record.name == 'uvicorn.error':
            record.name = 'fastapi'
        return True
SpendTimeCoding
  • 1