Middleware: Code That Runs on Every Request

What will we learn?#

• Which problem there is when you want to do something on every request.
• What Middleware is, and how it is related to the Decorator we already know.
• @app.middleware("http"), call_next, async and await.
• A log and time measurement for every request in the students API, and a Header that is added to every response.

Why do we need this?#

The students API from the previous lesson works. Now we want to know what happens in it: which request arrived, which code came back, and how long it took. The first way that comes to mind — add a log line to every Route:

@app.get("/students")
def list_students():
    logging.info("GET /students")
    return students

@app.get("/students/{student_id}")
def get_student(student_id: int):
    logging.info("GET /students/" + str(student_id))
    ...

Three problems:

1. The same line is copied into every Route — five, ten, fifty times.
2. A new Route where the line was forgotten — is simply not logged.
3. There is no way to know the response code like this — 404 and 400 are created in raise HTTPException, after the log line, and 422 is created even before the Route runs. And also not how long the request took.

Explanation from the basics#

The idea — Middleware#

Middleware = code that wraps every request that reaches the server: it runs before the Route, passes the request on, and runs again after — when the response is already in hand.

Client --request--> Middleware --------> Route (your function)
                    before: start the timer
Client <-response-- Middleware <-------- Route
                    after: status code, duration, log

Like a Decorator — for the whole server#

In the lesson on decorators we wrote a Decorator that measures time: it wraps one function, runs before and after it, and calls it in the middle. Middleware is exactly the same idea — only it wraps all the requests to the server, without touching any Route.

Why do you need to wait correctly?#

The Middleware passes the request to the Route, and then waits for the response. But a server receives many requests at once. If it “gets stuck” and waits for each request until the end, all the others stand in a queue.

async and await#

This is exactly what await is for. Inside the Middleware there is the line:

response = await call_next(request)

• call_next(request) — passes the request on: to the matching Route (or to a 404 if there is none), and returns the response. This is the order to the kitchen.
• await — “let me know when the dish is ready”: wait for the Route’s response, and meanwhile the server is free to handle other requests. When the response is ready, the code continues from the next line.
• async def — await may be written only inside a function defined with async def. That is why the Middleware is defined like this.

request and response#

Syntax#

from fastapi import FastAPI, Request

app = FastAPI()

@app.middleware("http")
async def my_middleware(request: Request, call_next):
    # ... before the route
    response = await call_next(request)     # wait for the route's response
    # ... after the route
    return response                         # always pass the response on

• @app.middleware("http") — registers the function as Middleware for every HTTP request.
• request: Request — Request is imported from fastapi.
• return response — required. Without it the client does not get a response.

First code example#

A log and a time measurement for every request in the students API. At the top of students_memory.py (from the previous lesson) — we only add, no Route changes:

import logging
import time

from fastapi import FastAPI, HTTPException, Request
from pydantic import BaseModel

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s")

app = FastAPI(title="Students API")

@app.middleware("http")
async def log_requests(request: Request, call_next):
    start = time.time()
    response = await call_next(request)
    ms = round((time.time() - start) * 1000, 1)
    logging.info(request.method + " " + request.url.path + " -> "
                 + str(response.status_code) + " (" + str(ms) + " ms)")
    return response

# ... students, StudentIn and all the routes stay exactly the same

Run it (uvicorn students_memory:app --reload), and send requests from Swagger (/docs). The log in the Terminal:

INFO GET /students -> 200 (0.7 ms)
INFO GET /students/99 -> 404 (0.5 ms)
INFO POST /students -> 201 (1.3 ms)
INFO POST /students -> 400 (0.6 ms)
INFO GET /students/abc -> 422 (0.5 ms)

Breaking down the code line by line#

Notice: the times are very short — the data is in a list in memory. When we connect the server to a database, we will see the times go up — and a measurement like this is exactly the way to discover where the server “wastes” time.

Another example#

A Header for every response#

Middleware can also change the response. Here we add to every response a Header named X-Process-Time, with the time it took to handle it:

@app.middleware("http")
async def add_process_time(request: Request, call_next):
    start = time.time()
    response = await call_next(request)
    ms = round((time.time() - start) * 1000, 1)
    response.headers["X-Process-Time"] = str(ms)
    return response

In Swagger, under Response headers, this now appears:

x-process-time: 0.7

• response.headers[...] = ... — like adding a key to a dictionary.
• X- at the start of the name — a convention for a Header of our own, which is not part of the HTTP standard.
• You can have several Middlewares in the same server — every request goes through all of them.

When not Middleware?#

Middleware suits things that every request needs — a log, time measurement, Headers. A rule of one Route — for example “minimum age 16” in POST /students — belongs to the Route itself, and not to code that runs on the whole server.

Common mistake#

Mistake 1: forgetting return response.

@app.middleware("http")
async def log_requests(request: Request, call_next):
    response = await call_next(request)
    logging.info(request.url.path)

The Middleware returns None, and the client gets a 500 — on every request, because Middleware runs on all of them.

Mistake 2: forgetting await.

response = call_next(request)

Without await, you don’t wait for the Route — and response is not a response. The server fails on every request. await before call_next, always.

Mistake 3: def instead of async def. Without async, you cannot use await inside the function: SyntaxError: 'await' outside async function.

Mistake 4: Route logic inside Middleware. if request.url.path == "/students" and ... — Middleware that checks specific paths is usually a sign that the code belongs to a Route.

Practice#

The exercises use only what was taught in this lesson and the lessons before it. Try on your own first, and only then open the solution.

Exercise 1: What runs first?#

@app.middleware("http")
async def trace(request: Request, call_next):
    print("before", request.method, request.url.path)
    response = await call_next(request)
    print("after", response.status_code)
    return response


@app.get("/hello")
def hello():
    print("inside the route")
    return {"message": "hi"}

You send GET /hello. What will be printed, and in which order? And what will be printed for GET /nothing, a path that does not exist?

from fastapi import FastAPI, Request
from fastapi.testclient import TestClient

app = FastAPI()


@app.middleware("http")
async def trace(request: Request, call_next):
    print("before", request.method, request.url.path)
    response = await call_next(request)
    print("after", response.status_code)
    return response


@app.get("/hello")
def hello():
    print("inside the route")
    return {"message": "hi"}


client = TestClient(app)
client.get("/hello")
client.get("/nothing")

before GET /hello
inside the route
after 200
before GET /nothing
after 404

Exercise 2: A log for every request#

Write a Middleware named log_requests that writes to the log, at the INFO level, one line for every request: the Method, the path and the response code — in the format of the expected output.

Use this small application: a list with one student, GET /students and GET /students/{student_id} (which returns 404 for a student that does not exist). Set up the log so that the lines are printed to the screen:

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s", stream=sys.stdout)
logging.getLogger("httpx").setLevel(logging.WARNING)   # hide the test client's own log lines

students = [{"id": 1, "name": "Dana"}]

To test without running a server, send the three requests with FastAPI’s TestClient — a tool that sends requests straight to the application from Python code:

from fastapi.testclient import TestClient

client = TestClient(app)
client.get("/students")
client.get("/students/1")
client.get("/students/99")

Expected output:

INFO GET /students -> 200
INFO GET /students/1 -> 200
INFO GET /students/99 -> 404

import logging
import sys

from fastapi import FastAPI, HTTPException, Request
from fastapi.testclient import TestClient

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s", stream=sys.stdout)
logging.getLogger("httpx").setLevel(logging.WARNING)   # hide the test client's own log lines

app = FastAPI()
students = [{"id": 1, "name": "Dana"}]


@app.middleware("http")
async def log_requests(request: Request, call_next):
    response = await call_next(request)
    logging.info(request.method + " " + request.url.path + " -> " + str(response.status_code))
    return response


@app.get("/students")
def list_students():
    return students


@app.get("/students/{student_id}")
def get_student(student_id: int):
    for student in students:
        if student["id"] == student_id:
            return student
    raise HTTPException(status_code=404, detail="student not found")


client = TestClient(app)
client.get("/students")
client.get("/students/1")
client.get("/students/99")

INFO GET /students -> 200
INFO GET /students/1 -> 200
INFO GET /students/99 -> 404

Exercise 3: A Header with the handling time#

Write a Middleware that measures how long it took to handle the request, and adds to the response a Header named X-Process-Time with the time in milliseconds. The application has one Route, GET / that returns {"message": "hello"}.

Check that the Header arrives — send a request with TestClient (a tool that sends requests straight to the application from Python code) and check the response’s Headers:

from fastapi.testclient import TestClient

client = TestClient(app)
response = client.get("/")
print(response.status_code)
print("Has X-Process-Time:", "x-process-time" in response.headers)

Expected output:

200
Has X-Process-Time: True

import time

from fastapi import FastAPI, Request
from fastapi.testclient import TestClient

app = FastAPI()


@app.middleware("http")
async def add_process_time(request: Request, call_next):
    start = time.time()
    response = await call_next(request)
    ms = round((time.time() - start) * 1000, 1)
    response.headers["X-Process-Time"] = str(ms)
    return response


@app.get("/")
def home():
    return {"message": "hello"}


client = TestClient(app)
response = client.get("/")
print(response.status_code)
print("Has X-Process-Time:", "x-process-time" in response.headers)

200
Has X-Process-Time: True

Exercise 4: async and await#

@app.middleware("http")
async def log_requests(request: Request, call_next):
    start = time.time()
    response = await call_next(request)
    ms = round((time.time() - start) * 1000, 1)
    logging.info(request.url.path + " (" + str(ms) + " ms)")
    return response

1. What does the line response = await call_next(request) do? Explain with the analogy of the waiter and the kitchen.
2. What does the server do while await waits?
3. Why is the function defined with async def and not with def?
4. Do our Routes (list_students, get_student) also need to be async def?

Exercise 5: What is wrong?#

@app.middleware("http")
def log_requests(request: Request, call_next):
    response = call_next(request)
    logging.info(request.url.path)

Find three problems. And when is it not right to use Middleware?

Summary#

• Middleware = code that wraps every request: before the Route, and after it. Like a Decorator — for the whole server.
• @app.middleware("http") + async def + await call_next(request) + return response.
• Before call_next — what is needed before the request (for example, starting to measure). After — there is a response in hand: the code, the Headers, the time.
• Uses: a log for every request, time measurement, Headers for every response.
• Rules of one Route — in the Route, not in Middleware.

Official documentation#

• FastAPI — Middleware
• FastAPI — Concurrency and async / await