[Python] Keep context vars values between FastAPI/starlette middlewares depending on the...

I am developing a FastAPI app, and my goal is to record some information in a Request scope and then reuse this information later in log records.

My idea was to use context vars to store the "request context", use a middleware to manipulate the request and set the context var, and finally use a LogFilter to attach the context vars values to the LogRecord.

This is my app skeleton

logger = logging.getLogger(__name__)
app = FastAPI()
app.add_middleware(SetterMiddlware)
app.add_middleware(FooMiddleware)

@app.get("/")
def read_root(setter = Depends(set_request_id)):
print("Adding req_id to body", req_id.get()) # This is 1234567890
logging.info("hello")
return {"Req_id": str(req_id.get())}


and those are my middlewares

class SetterMiddlware(BaseHTTPMiddleware):
async def dispatch(self, request: Request, call_next):
calculated_id = "1234567890"
req_id.set(calculated_id)
request.state.req_id = calculated_id
response = await call_next(request)
return response

class FooMiddleware(BaseHTTPMiddleware):
async def dispatch(self, request: Request, call_next):
response = await call_next(request)
return response


and the Logging Filter

from vars import req_id


class CustomFilter(Filter):
"""Logging filter to attach the user's authorization to log records"""

def filter(self, record: LogRecord) -> bool:

record.req_id = req_id.get()
return True


And finally following a part of my log configuration

...
"formatters": {
"default": {
"format": "%(levelname)-9s %(asctime)s [%(req_id)s]| %(message)s",
"datefmt": "%Y-%m-%d,%H:%M:%S",
},
},
"handlers": {
...
"handlers": {
"console": {
"class": "logging.StreamHandler",
"formatter": "default",
"stream": "ext://sys.stderr",
"filters": [
"voxy_filter",
],
"level": logging.NOTSET,
},
...
"loggers": {
"": {
"handlers": ["console"],
"level": logging.DEBUG,
},
"uvicorn": {"handlers": ["console"], "propagate": False},
},


When SetterMiddlware is the latest added in the app (FooMiddleware commented in the example), my app logs as expected

Adding req_id to body 1234567890
INFO 2025-04-14,15:02:28 [1234567890]| hello
INFO 2025-04-14,15:02:28 [1234567890]| 127.0.0.1:52912 - "GET / HTTP/1.1" 200


But if I add some other middleware after SetterMiddlware, uvicorn logger does not find anymore the context_var req_id set.

Adding req_id to body 1234567890
INFO 2025-04-14,15:03:56 [1234567890]| hello
INFO 2025-04-14,15:03:56 [None]| 127.0.0.1:52919 - "GET / HTTP/1.1" 200


I tried using the package https://starlette-context.readthedocs.io/en/latest/ but I wasn't luckier; it looks like it suffers the same problems.

I would like to know why this behavior happens and how I can fix it, without the constraint of having the SetterMiddleware in the last middleware position.

Continue reading...