pythonexceptionloggingfastapiuvicorn

How to log a request in FastAPI when an exception occurs which is handled inside submodule?


Imagine I have a FastAPI backend application exposing the following test endpoint:

@router.post("/my_test")
async def post_my_test(request: Request):
    a = do_stuff(request.var1)
    b = do_different_stuff(request.var2)
    return a + b

Inside my do_stuff() and do_different_stuff() a lot of (nested) business logic is executed. E.g. inside do_stuff we call another method which calls another method etc. When reaching the lowest level the resulting method does some calculation

async def calc_it(m, n):
    try:
        return m/n
    except ZeroDivisionError:
        logging.exception("Error occurred")
        return -1

Inside this method we explicitly handle the resulting error (let's assume it might be somewhat expected that in rare cases this happens). If this happens I woult want to log the complete request object from the top-level endpoint. I see the following possibilities on achieving this.

  1. Propagate the information that the error occured to the top-level method e.g. return -1, "err_occured" all the way up and log it inside post_my_test
  2. Propagate the whole request object all the way down to all low-level methods which execute stuff and log the request object inside calc_it
  3. Use some type of FastAPI Middleware object to intercept request and response or a separate Exception handler app.add_exception_handler(Exception, my_exception_handler) --> However I still want to handle the error (e.g. in this case return -1) inside the low-level method because I want to explicitly configure different fallback values in a lot of instances.

The 1. and 2. choice would obviously work however I have the feeling there should/could be some better solutions than propagating this all the way down/up. The 3. choice using a basic middleware won't work as it never sees the exception when we catch it with the low-level method try except statement.

I have the feeling there surely exists a smarter way of handling this. E.g. is there some global variable on a request-level I could modify which could pass the information that this complete request should be logged or not or are there any other ways of achieving this functionality without cluttering my code with up and down propagating information?

Thanks in advance for your help!

EDIT: I stumbled upon Is there a FastAPI way to access current Request data globally?? and Request context in FastAPI? which employ ContextVars to pass the data using imports. As clarified in my comment I could thus set the request object as ContextVar. So I basically pass the complete request object to all my methods down the line. Is this some kind of anti-pattern? (It feels kinda strange to pass a potentially huge object like this) IMO it could be better to pass the flag with this kind of information ("log_this_request") up to the endpoint logic using ContextVars, however as I'm using asnycio tasks I'm only able to pass it down to tasks but not "back up" to their parent.


Solution

  • Yes - the correct answer would be " 2- Propagate the whole request object all the way down to all low-level methods which execute stuff and log the request object inside calc_it" - but instead of propagating it through function arguments to every intermediate function, use a separate data-storage which is unique per-request, so each function being run inside a request can access it.

    This "data storage" happens to be implemented in the languague through the contextvars mechanism - and, as you found out, FastApi already makes use of those so that any function can retrieve information about the request which triggered it to be called.

    As it turns out, you are worried about passing a huge object along: keep in mind that all Python passes along (or store in the contextvar, for this matter) is a reference to the object (the request object in this case) - so, no extra memory is allocated beyond the few bytes needed to note the reference itself.

    Note however, that architecture wise it might not be interesting that calc_it would have to know about fastapi requests in order to log the error - (this way you keep low coupling in your system, allowing you to change the HTTP-API fraework in the future) So you could make use of your own contextvariables to indicate an error took place - and the top-level function would check that after the nested-calls return, and log it from there. (It is in a layer which "knows" about requests). If you find using raw contextvar.ContextVar complicated, the extracontext package I authored had a stable-release last week, and can wrap contextvars in a "more Pythonic" API, providing a namespace, for example.