FastAPI uvicorn not logging errors

Question

I am learning fastapi, and I am starting a uvicorn server on localhost. Whenever there is an error or an 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 the error traceback, please guide.

I'm on it... I am currently tracing it back to the "uvicorn.error" logger which logs to stderr by default, but I got the same problem, but it definitely originates from a logging config where uvicorn.error is changed. — TheClockTwister, Mar 13 '21 at 04:01

score 13 · Answer 1 · edited Dec 07 '22 at 14:01

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.

where can i find all the formatters like `%(client_addr)s %(request_line)s %(status_code)s` for "uvicorn.error"? i couldn't find them on uvicorn docs. — Naveen Reddy Marthala, Feb 03 '22 at 14:05
Maybe they just copied it from Flask or Quart and you need to look there, I couldn't find documentation on it either and just used it :D — TheClockTwister, Feb 04 '22 at 15:32

score 7 · Answer 2 · answered Dec 04 '21 at 03:59

7

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.

answered Dec 04 '21 at 03:59

Mark Seagoe

480
8
15

This is great, but I still want to see the same stuff in my terminal. – Automatico Feb 13 '23 at 08:11

score 1 · Answer 3 · answered Feb 13 '23 at 08:21

1

There is most likely a more elegant way of doing this, but a simple-ish hack is to make a middleware which just prints exceptions;

import traceback

...

async def catch_exceptions_middleware(request: Request, call_next):
    try:
        return await call_next(request)
    except Exception as e:
        print(traceback.format_exc())
        raise e


app.middleware('http')(catch_exceptions_middleware)

# Then your normal endpoint code;
@app.get('/error-endpoint')
def endpoint():
    a = 1 / 0
    return {"result": a}

ref: How to catch and print the full exception traceback without halting/exiting the program?

answered Feb 13 '23 at 08:21

Automatico

12,420
9
82
110

If this prints to the terminal then this would be a better way I agree. Too bad there's not just some built in config setting to do it, seems like everyone would need this. – Mark Seagoe May 03 '23 at 23:11
What if the `endpoint()` method includes try-except itself? – Benyamin Jafari Jul 25 '23 at 08:19
@BenyaminJafari That should not change anything. If you decide to raise it "out" again, then this method would catch it again. you can have nested try-excepts. – Automatico Jul 28 '23 at 18:38
@MarkSeagoe I meant If the `end_point()` method would have try-except itself, your top method isn't called. So I think the best way is to put `traceback.print_exc()` inside of any exception in the methods. – Benyamin Jafari Jul 29 '23 at 07:23

FastAPI uvicorn not logging errors

3 Answers3

Solution / Fix

Explanation