FastAPI sync endpoints can lose correlation IDs across AnyIO worker threads #124

Summary

On current master and the published json-logging==1.5.1, application logs emitted from a synchronous FastAPI (def) endpoint contain "correlation_id": "-", and json_logging.get_correlation_id() returns "-", while the HTTP request instrumentation log for the same request has the real correlation ID. This reproduces on every request; it is not intermittent.

Minimal reproduction

import logging
import sys

import json_logging
from fastapi import FastAPI

app = FastAPI()
json_logging.init_fastapi(enable_json=True)
json_logging.init_request_instrument(app)

logger = logging.getLogger("app")
logger.setLevel(logging.INFO)
logger.addHandler(logging.StreamHandler(sys.stdout))

@app.get("/sync")
def sync_endpoint():
    logger.info("inside sync endpoint")
    return {"correlation_id": json_logging.get_correlation_id()}

Request:

GET /sync
X-Correlation-ID: repro-123

Expected: the application log and json_logging.get_correlation_id() both return repro-123, matching the request instrumentation log.

Observed on master / 1.5.1 (Python 3.12, FastAPI 0.146, Starlette 1.9):

The same happens with X-Request-ID, and without any header: the request log then gets a generated ID while the application log still gets "-". async def endpoints are not affected.

Root cause

FastAPI/Starlette execute synchronous endpoints in AnyIO worker threads. RequestUtil.get_request_from_call_stack() looks for the request object in the current thread's Python frames, and the worker thread's stack does not contain it.

Propagating the request into worker threads exposes a second problem. The lazy check → generate → store sequence for a missing correlation ID is not synchronised, so two worker threads of the same request can create two different IDs when no header is present.

Workarounds on 1.5.1

• Declare request: Request on the sync endpoint (this puts the request object into the worker thread's stack), or call json_logging.get_correlation_id(request=request).
• Make the endpoint async def.

Relationship to earlier issues

• #80 (2021) reported the same symptom: a def FastAPI route running in a worker thread, an application log with "-", and a generated ID in the request log. It was closed after the reporter wrote that re-running the code worked. No code change or root cause was recorded, and the request-lookup code has not changed since, apart from a class rename. The remedy suggested there, get_correlation_id() without a request argument, still returns "-" in sync endpoints. Why it worked for that reporter cannot be determined from the thread. This issue tracks the defect as reproduced on the current code.
• #60 documented a related thread-context limitation for Connexion/Flask (executor threads).

Scope / acceptance criteria

• On the tested Python 3.9–3.13 versions, sync and async FastAPI endpoints emit the request's actual correlation ID.
• Different concurrent requests remain isolated, and concurrent workers within one request share the same ID.
• Request context is reset after the request; URLs excluded from request logging still give application logs the correlation ID; setups without request instrumentation keep the previous frame lookup.
• Other framework integrations, custom framework plugins and shared logging utilities remain unchanged.
• Python 3.8 and earlier keep the previous behaviour, rather than enabling a change that could not be verified on those runtimes.

Proposed fix

PR #123 is a FastAPI-only fix:

• ContextVar request propagation: the current request is kept in a FastAPI-specific context variable for the request's lifetime.
• Eager ID resolution: a missing correlation ID is created once per request, so workers of one request share it.
• Python boundary: both are enabled only on Python 3.9+.

The PR includes deterministic regression tests: concurrent requests, two workers of one request, context reset, the disabled-feature fallback, and the custom-plugin contract. CI covers Python 3.9–3.13 and the framework smoke tests, and passes on the current head. Review and merge are tracked in the PR.