[Python] contextvars로 비동기 요청 로그가 섞이지 않게 만든 이유

접근 방식: 스레드가 아니라 태스크를 기준으로 보기

asyncio는 한 스레드에서 여러 요청을 번갈아 실행할 수 있어. 그래서 스레드 로컬에 저장한 값은 다른 요청이 덮어쓸 위험이 있어.

ContextVar 값은 현재 실행 컨텍스트에 속해. await로 실행권이 바뀌어도 각 태스크는 자신의 컨텍스트를 다시 사용해.

방식	구분 기준	비동기 요청 격리
함수 인자	호출 경로	명시적으로 보장
threading.local()	스레드	같은 스레드에서는 부족
ContextVar	실행 컨텍스트	태스크별 유지

코드 예제: 미들웨어에서 설정하고 로그에 주입하기

순수 ASGI 미들웨어로 요청 전체를 감싸면 응답 처리와 FastAPI 백그라운드 작업까지 같은 컨텍스트에서 실행돼. 종료할 때는 토큰으로 이전 값을 복원해야 해.

1. 헤더의 요청 ID를 읽거나 새 UUID를 생성해.
2. ContextVar.set()이 반환한 토큰을 보관해.
3. 요청이 끝나면 reset()으로 컨텍스트를 복원해.

import asyncio
import logging
from contextvars import ContextVar
from uuid import uuid4

from fastapi import FastAPI

request_id_var: ContextVar[str] = ContextVar(
    "request_id",
    default="-",
)

class RequestIdMiddleware:
    def __init__(self, app):
        self.app = app

    async def __call__(self, scope, receive, send):
        if scope["type"] != "http":
            await self.app(scope, receive, send)
            return

        headers = dict(scope["headers"])
        request_id = headers.get(b"x-request-id")

        if request_id is None:
            request_id = str(uuid4())
        else:
            request_id = request_id.decode("utf-8")

        token = request_id_var.set(request_id)

        try:
            await self.app(scope, receive, send)
        finally:
            request_id_var.reset(token)

class RequestIdFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id_var.get()
        return True

handler = logging.StreamHandler()
handler.addFilter(RequestIdFilter())
handler.setFormatter(
    logging.Formatter(
        "%(asctime)s %(levelname)s "
        "[request_id=%(request_id)s] %(message)s"
    )
)

logger = logging.getLogger("app")
logger.setLevel(logging.INFO)
logger.addHandler(handler)

app = FastAPI()
app.add_middleware(RequestIdMiddleware)

@app.get("/orders/{order_id}")
async def read_order(order_id: int):
    logger.info("주문 조회 시작")
    await asyncio.sleep(0.1)
    logger.info("주문 조회 완료")
    return {"order_id": order_id}

asyncio.create_task()는 생성 순간의 컨텍스트를 복사해. 태스크를 만든 뒤 부모의 값을 바꿔도 이미 생성된 태스크에는 반영되지 않아.

async def worker():
    logger.info("백그라운드 실행")

token = request_id_var.set("request-A")
task = asyncio.create_task(worker())

request_id_var.set("request-B")
await task  # worker에는 request-A가 기록돼

request_id_var.reset(token)

실전 체크리스트와 선택 기준

요청 수명 안에서 실행되는 작업은 ContextVar와 잘 맞아. 큐에 넣거나 요청 종료 뒤 독립 실행되는 작업이라면 request_id를 메시지 데이터로 명시하는 편이 안전해.

• set()의 토큰을 반드시 finally에서 복원해.
• 태스크 생성 시점에 어떤 컨텍스트가 복사되는지 확인해.
• 새 스레드나 외부 작업 큐로 값이 자동 전파된다고 가정하지 마.
• 로그 포맷이 요구하는 필드는 필터에서 항상 기본값까지 채워.
• 동시 요청 테스트로 서로 다른 ID가 섞이지 않는지 검증해.

함수의 핵심 계약에 필요한 값은 명시적 인자로 전달하는 게 좋아. 로깅·트레이싱처럼 호출 계층 전체에 걸친 부가 정보는 contextvars가 코드 오염을 줄여줘.