FastAPI Server Errors And Logs — Take Back Control

Keywords: Python, FastAPI, Server Errors, Logs, Exception Handlers, AWS Lambda, AWS Cloud Watch

We are here to understand how FastAPI handles server errors and logs. After reading this:

• You will better understand HTTP status codes
• You will get to know FastAPIs exception handlers and what happens when your server runs into an error
• You will be able to control this behavior
• You will have an improved version of FastAPI logs — with request time measurement and extra details on Internal Server Error and Request Validation
• You will have better logs for AWS Lambda

Before reading this make sure you are familiar with the FastAPI documentation on handling errors:

• https://fastapi.tiangolo.com/tutorial/handling-errors/

Plus, if you prefer to read code than words, check the GitHub repository:

• https://github.com/roy-pstr/fastapi-custom-exception-handlers-and-logs

Agenda

1. HTTP response status code and FastAPI
2. FastAPI built-in exceptions handlers
3. Examples of FastAPI exception handling
4. Code to control FastAPI exception handling and improve logging

HTTP Response Status Codes and FastAPI

The response status code of an HTTP server gives information on how the server handled a client request. Status codes are grouped into five classes:

1. Informational responses (100 – 199)
2. Successful responses (200 – 299)
3. Redirection messages (300 – 399)
4. Client error responses (400 – 499)
5. Server error responses (500 – 599)

(See https://developer.mozilla.org/en-US/docs/Web/HTTP/Status for a complete reference)

When you build an HTTP server it is your responsibility to use the protocol (in other words, you really can set the status code value to anything, like return 500 on success 😱). Anyway, you better stick to the protocol. Of course that any HTTP server framework will have some built-in support in this protocol. For example, with FastAPI, returning a response without mentioning any specific status code will assume success and use status code 200.

FastAPI has a default behavior also for server and some client errors. It will use status codes 500, 422, and 404 in specific cases for you. Let's understand when it will happen and how you can control this.

FastAPI Built-In Exceptions Handlers

FastAPI has built-in exception handlers for HTTPException and ValidationError. It means that whenever one of these exceptions occurs, FastAPI catches it and returns an HTTP response with a corresponding status code and details about the error. Let's break it down into cases:

1. Pydantic Validation Error (422) — This is a client-side error and it returns a response with a status code 422. This error is caused by the data the client sends. Pydantic validates the path parameters, query parameters, and body data — so any validation error there will raise this exception.
2. HTTP Exception (≥500)— This is a server-side error and it can happen in two ways:

• You explicitly raise an HTTP Exception from your code. This case is when you use “try and except” block and raise HTTP Exception to indicate that a certain server error occurred. Here you choose the status code value (≥500) that will be returned.
• Implicit raised by FastAPI. It happens when a pythonic exception (E.g. ValueError) is raised from within your code. FastAPI will catch the exception and turn it into a response with status code 500 and message detail of “Internal Server Error”. In this case, you should also see python trace back in your logs (which is super important to understand what happened).

The last built-in handler is for “404 Not Found” response. This one indicates that a client tried to access a path in your server that does not exist.

A Code Example Of FastAPI Exception Handling

Let’s walk through a code example that will help us understand how FastAPI handles exceptions.

• Create a python project and install fastapi["all"] with your favorite python package manager.
• Create main.py with the following code:

from fastapi import FastAPI
app = FastAPI()
@app.get("/divide")
def do_divide(a: int, b: int):
    return a/b
@app.get("/divide_with_explicit_exception")
def do_divide_with_explicit_exception(a: int, b: int):
    try:
        return a/b
    except ZeroDivisionError:
        raise HTTPException(status_code=500, detail="Division by zero is not allowed")

• Start the server

uvicorn main:app --reload

Logs in your terminal on server start

• Open another terminal window and run the following requests from the server:

curl -X GET "http://localhost:8000/divide?a=1&b=2"
curl -X GET "http://localhost:8000/divide?a=1.5&b=2"
curl -X GET "http://localhost:8000/divide_with_explicit_exception?a=1&b=0"
curl -X GET "http://localhost:8000/divide?a=1&b=0"

• This should be your server logs:

FastAPI logs

• The first log is for a successful response
• The second is for client-side error — invalid request input data (in this case b must be an integer)
• The third is for server-side error that is handled explicitly by you. Here it is on you to add more details so you will understand what caused this because there are no traces.
• The fourth is for server-side error that is handled implicitly by FastAPI. Here the “Internal Server Error” does not tell you much, but the traces should tell the story.

Looks good right? indeed. But it can be better. For example, a time measurement can be added to each log. “422 Unprocessable Entity” can be more verbose, printing the client input data so we can easily figure out what data was invalid. And “500 Internal Server Error” is worth nothing without further explanation.

There is one more thing, when deploying FastAPI application on AWS Lambda you will not see any of these logs. It has something to do with how uvicron define its loggers. It will look like this:

FastAPI service logs on cloud watch from lambda deployment. Where are all the logs we see in our terminal???

Let’s see how you can improve all those.

Control FastAPI Exception Handling And Improve Logging

We are going to replace all FastAPI’s default logs (which are actually uvicorns’) with the exact same logs (+some additions), but this time created by us. This will gain you the ability to customize them in the future.

Those are the results you will get:

1. Add to the regular INFO response log a time measurement in milliseconds:

Original

Ours — more verbose about the time it took to process the request

2. Add INFO log with body data and query parameters when 422 occurs:

Original

Ours — more verbose about the client input data

3. Add error type and message to the response log:

Original

Ours — more verbose about the reason for the error (this information is found also at the end of the traceback)

4. I mentioned before the problem with FastAPI’s logs doesn’t appear in AWS Cloud Watch logs — this is solved with this implementation.

Let’s start

• Create logger.py with the following code:

import logging

# Disable uvicorn access logger
uvicorn_access = logging.getLogger("uvicorn.access")
uvicorn_access.disabled = True

logger = logging.getLogger("uvicorn")
logger.setLevel(logging.getLevelName(logging.DEBUG))

• You can change the logging level of course ( logging.debug ).
• Create middleware.py with the following code:

import http
import time

from fastapi import Request

from logger import logger


async def log_request_middleware(request: Request, call_next):
    """
    This middleware will log all requests and their processing time.
    E.g. log:
    0.0.0.0:1234 - GET /ping 200 OK 1.00ms
    """
    logger.debug("middleware: log_request_middleware")
    url = f"{request.url.path}?{request.query_params}" if request.query_params else request.url.path
    start_time = time.time()
    response = await call_next(request)
    process_time = (time.time() - start_time) * 1000
    formatted_process_time = "{0:.2f}".format(process_time)
    host = getattr(getattr(request, "client", None), "host", None)
    port = getattr(getattr(request, "client", None), "port", None)
    try:
        status_phrase = http.HTTPStatus(response.status_code).phrase
    except ValueError:
        status_phrase=""
    logger.info(f'{host}:{port} - "{request.method} {url}" {response.status_code} {status_phrase} {formatted_process_time}ms')
    return response

• Create exception_handlers.py with the following code:

import sys

from typing import Union

from fastapi import Request
from fastapi.exceptions import RequestValidationError, HTTPException
from fastapi.exception_handlers import http_exception_handler as _http_exception_handler
from fastapi.exception_handlers import (
    request_validation_exception_handler as _request_validation_exception_handler,
)
from fastapi.responses import JSONResponse
from fastapi.responses import PlainTextResponse
from fastapi.responses import Response

from logger import logger

async def request_validation_exception_handler(request: Request, exc: RequestValidationError) -> JSONResponse:
    """
    This is a wrapper to the default RequestValidationException handler of FastAPI.
    This function will be called when client input is not valid.
    """
    logger.debug("Our custom request_validation_exception_handler was called")
    body = await request.body()
    query_params = request.query_params._dict  # pylint: disable=protected-access
    detail = {"errors": exc.errors(), "body": body.decode(), "query_params": query_params}
    logger.info(detail)
    return await _request_validation_exception_handler(request, exc)


async def http_exception_handler(request: Request, exc: HTTPException) -> Union[JSONResponse, Response]:
    """
    This is a wrapper to the default HTTPException handler of FastAPI.
    This function will be called when a HTTPException is explicitly raised.
    """
    logger.debug("Our custom http_exception_handler was called")
    return await _http_exception_handler(request, exc)


async def unhandled_exception_handler(request: Request, exc: Exception) -> PlainTextResponse:
    """
    This middleware will log all unhandled exceptions.
    Unhandled exceptions are all exceptions that are not HTTPExceptions or RequestValidationErrors.
    """
    logger.debug("Our custom unhandled_exception_handler was called")
    host = getattr(getattr(request, "client", None), "host", None)
    port = getattr(getattr(request, "client", None), "port", None)
    url = f"{request.url.path}?{request.query_params}" if request.query_params else request.url.path
    exception_type, exception_value, exception_traceback = sys.exc_info()
    exception_name = getattr(exception_type, "__name__", None)
    logger.error(
        f'{host}:{port} - "{request.method} {url}" 500 Internal Server Error <{exception_name}: {exception_value}>'
    )
    return PlainTextResponse(str(exc), status_code=500)

• Add these changes to main.py file:

from fastapi import FastAPI
from starlette.exceptions import HTTPException
from fastapi.exceptions import RequestValidationError
from exception_handlers import request_validation_exception_handler, http_exception_handler, unhandled_exception_handler
from middleware import log_request_middleware

app = FastAPI()

app.middleware("http")(log_request_middleware)
app.add_exception_handler(RequestValidationError, request_validation_exception_handler)
app.add_exception_handler(HTTPException, http_exception_handler)
app.add_exception_handler(Exception, unhandled_exception_handler)

• Your files structure should be like this:

|fastapi-exceptions-project
  |--exception_handlers.py
  |--logger.py
  |--main.py
  |--middleware.py

• You are all set! Test it with the same curl commands from before and check the server logs (You can remove all the logger.debug later. This is just for… debug).
• By the way, it also solves the AWS lambda logs problem. This time all those logs will also appear in your cloud watch:

AWS Cloud Watch logs. This time with the FastAPI logs we use to see in our terminal.

To Sum It All Up

You now should feel much more confident putting FastAPI service in production, knowing that you understand what happens on server errors and what logs you will see.

• You can find all the code in this repository

https://github.com/roy-pstr/fastapi-custom-exception-handlers-and-logs

Feel free to leave comments and feedback,

Thanks,

Roy.

Resources

GitHub - tiangolo/fastapi: FastAPI framework, high performance, easy to learn, fast to code, ready…

GitHub - encode/uvicorn: An ASGI web server, for Python. 🦄

HTTP response status codes - HTTP | MDN