FastAPI uvicorn not logging errors

Question

I am learning fastapi, and I am starting a uvicorn server on localhost. Whenever there is an error/exception, I am not getting the traceback. All I am getting is : INFO: 127.0.0.1:56914 - "POST /create/user/ HTTP/1.1" 500 Internal Server Error

So, It is difficult to debug, I am trying out logging module of python

 import logging
 log = logging.getLogger("uvicorn")
 log.setLevel(logging.DEBUG)

I have also tried starting uvicorn with debug parameter

if __name__ == "__main__":
    dev = 1
    print("printing")
    if dev == 1:
        uvicorn.run('main:app', host="127.0.0.1", port=5000, log_level="info", reload=True, debug=True)
    if dev == 2:
        uvicorn.run('main:app', host="127.0.0.1", port=5000, log_level="info", workers=2)


still the same problem persists. I am in development phase and I need to error traceback,please guide. 

Answer 1

Solution / Fix

Now, when you execute uvicorn by the in-Python command uvicorn.run(app), this is your next move:

take the ucivorn default logging config and add the handler from your application to it:

config = {}

# this is default (site-packages\uvicorn\main.py)
config['log_config'] = {
            'version': 1, 'disable_existing_loggers': True,
            'formatters': {'default': {'()': 'uvicorn.logging.DefaultFormatter', 'fmt': '%(levelprefix)s %(message)s', 'use_colors': None},
                           'access': {'()': 'uvicorn.logging.AccessFormatter', 'fmt': '%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s'}},
            'handlers': {'default': {'formatter': 'default', 'class': 'logging.StreamHandler', 'stream': 'ext://sys.stderr'},
                         'access': {'formatter': 'access', 'class': 'logging.StreamHandler', 'stream': 'ext://sys.stdout'}},
            'loggers': {'uvicorn': {'handlers': ['default'], 'level': 'INFO'},
                        'uvicorn.error': {'level': 'INFO', 'handlers': ['default'], 'propagate': True},
                        'uvicorn.access': {'handlers': ['access'], 'level': 'INFO', 'propagate': False},
                        },
        }

# add your handler to it (in my case, I'm working with quart, but you can do this with Flask etc. as well, they're all the same)
config['log_config']['loggers']['quart'] = {'handlers': ['default'], 'level': 'INFO'}

this will keep the logger from quart/Flask/etc. enabled when uvicorn starts. Alternatively, you can set disable_existing_loggers to False. But this will keep all loggers enabled and then you will probable get more messages than you wish.

Finally, pass the config to uvicorn:

uvicorn.run(app, **config)

Explanation

When uvicorn's logging config has set disable_existing_loggers to True, all other loggers will be disabled. This also means that the logger quart and Flask use (which prints the traceback) get disabled. You can either set the config to NOT disable other loggers, or re-add them to the config so uvicorn doesn't disable them in the first place.

Answer 2

For "500 Internal Server Error" occurring during a post request, if you invoke FastAPI in debug mode:

app = FastAPI(debug=True)

Retry the request with Chrome dev tools Network tab open. When you see the failing request show up (note - my route url was '/rule' here):

Click on it, and you'll see the Traceback text in the Fetch/XHR / Response tab window.

You can quickly verify it by inserting "assert False" in your post handler.