우선 현재는 개발단계기 때문에 모니터링 환경 (Prometheus/Grafana, ELK, Cloud Logging 등등,,,) 전혀 구축을 하지 않았으며, 클라우드 인프라를 이용하지 않고 온프레미스를 구축 중입니다.
즉 , 로깅을 직접 해야된다는 뜻..
사실 개발은 여러 개발자, 여러 서버를 각자 개인의 개발자가 확인해서 문제를 잡으면 되지만,, 전체 흐름에서 언제 터지는지 확인을 하는게 에러 잡기 가장 편하더라구요. 또한, 저희는 엔진엑스도 분리된 서버에 있고, 요청이 여러 대의 서버를 거쳐 들어오기 때문에
“어디서 터졌는지”를 감으로 찾는 게 불가능해집니다. 특히 운영 중에는 “에러가 났다”보다 더 무서운 게, 에러가 났는데 어느 지점에서 문제가 시작됐는지 추적이 안 되는 상황이더라구요.
그래서 저는 이 단계에서부터 로깅을 단순한 디버깅용이 아니라,
- 요청이 어느 서버로 들어왔는지
- 어떤 유저/어떤 jobId로 시작된 작업인지
- 어떤 단계에서 지연되거나 실패했는지
- 누가(어떤 IP/어떤 환경) 요청을 보냈는지
이런 것들을 “전체 흐름 기준으로” 남기도록 설계를 시작했습니다. 결국 개발자가 여러 명이고 서버가 여러 대일수록, 각자 로컬에서 문제를 잡는 것보다 한 줄의 로그만 봐도 전체 흐름에서 어디가 끊겼는지 알 수 있게 만드는 게 에러를 잡는 데 훨씬 편했습니다.
Next.js 의 프론트 쪽은 아직 붙이진 않았지만,,, FastAPI 와 Spring 딴은 제가 코드 리뷰를 담당하고 수정하고 있는 중이라 해당 에러 로깅의 포맷을 통일 시켰고, Spring은 예전에 IP 별 로깅을 해본적 있지만, FastAPI 는 처음이라 기록용으로 남겨보려 합니다.
우선 첫 번째로, FastAPI에 요청이 들어오면 어떤 경로를 거쳐 컨트롤러까지 도달하는지부터 정리해보려 합니다.
현재 구조에서 클라이언트의 요청은 바로 FastAPI로 들어오지 않습니다.
(서버 외부 IP 에서 들어오는 요청, 도메인을 통해?) 대부분의 요청은 다음과 같은 흐름을 거쳐 들어옵니다.
외부 요청 → 엔진엑스(Nginx) → 내부 네트워크 → FastAPI 서버 → Controller
이때 중요한 포인트는, FastAPI 입장에서 보면 이미 한 번 이상 프록시를 거친 요청이라는 점입니다.
엔진엑스는 단순히 트래픽을 전달하는 역할만 하는 게 아니라,
- TLS 종료
- 경로 기반 라우팅
- 내부 서버로의 프록시 전달
- 클라이언트 IP 전달 (X-Forwarded-For)
같은 역할을 함께 수행합니다.
그래서 FastAPI에서 요청을 처음 받는 시점에는 이미 다음과 같은 정보들이 함께 들어오게 됩니다.
- 실제 클라이언트 IP (X-Forwarded-For 헤더)
- 요청이 들어온 경로와 메서드
- 내부적으로 라우팅된 서버 정보
이 요청은 FastAPI 내부에서 곧바로 컨트롤러로 떨어지지 않고, 미들웨어 체인을 먼저 통과하게 됩니다.
이제 실제 코드 레벨에서,
FastAPI에 요청이 들어왔을 때 무엇을 가장 먼저 세팅하는지를 살펴보겠습니다.
FastAPI 애플리케이션을 생성하기 전에, 가장 먼저 호출하는 함수가 있습니다.
이 함수는 단순히 로그 레벨을 설정하는 용도가 아니라, 이 서비스 전체에서 사용할 로그 포맷과 규칙을 고정시키는 역할을 합니다.
즉,
- 어떤 형식으로 로그를 찍을지
- request_id 같은 공통 필드를 어디서든 찍을 수 있게 할지
- stdout 기준으로 로그를 남길지
- 다른 서버(Spring, Worker)와 포맷을 맞출지
같은 것들을 이 시점에서 전부 결정합니다.
FastAPI 앱이 생성된 이후에 로깅을 건드리기 시작하면,
이미 일부 로그는 기본 포맷으로 찍혀버리기 때문에
로깅 초기화는 반드시 앱 생성 이전에 수행하는 게 중요합니다.
다음이 이번 로깅 설계에서 가장 중요한 부분입니다.
여기서 핵심은 미들웨어의 역할 분리입니다.
처음에는 흔히 생각하는 방식대로 “접속 IP를 찍는 Access Log 미들웨어”를 바로 붙일까 고민했지만, 이 단계에서는 일부러 주석 처리해두었습니다.
이유는 간단합니다.
지금 필요한 건 “누가 몇 번 요청했는지”보다 “이 요청이 어떤 흐름으로 흘러가고 있는지”를 파악하는 것이었기 때문입니다.
그래서 먼저 붙인 게 RequestContextASGIMiddleware입니다.
이 미들웨어의 역할은,
- 요청이 들어오는 순간
- request_id 생성
- 실제 클라이언트 IP 추출
- 요청 시작 시각 기록
- 이 정보를 context 단위로 묶어서 저장
이렇게 세팅된 컨텍스트는 이후 컨트롤러, 서비스 레이어, 워커 호출, 외부 API 호출까지 모두 동일하게 이어집니다.
즉, 이 구조에서는
- 컨트롤러에서 로그를 찍든
- 서비스 로직에서 로그를 찍든
- 에러가 터지든
항상 같은 request_id, 같은 client_ip가 로그에 자동으로 포함됩니다.
Access Log 미들웨어를 나중으로 미룬 것도 이 때문입니다.
Access Log는 “결과 요약”에 가깝고, Request Context는 “전체 흐름의 기준점”이기 때문에
이 두 개를 같은 레이어에서 섞어버리면 로그가 오히려 읽기 어려워집니다.
그래서 현재 단계에서는,
- RequestContext → 반드시 필요
- AccessLog → 추후 트래픽/운영 상황 보고 도입
이렇게 명확히 선을 그어두었습니다.
이 시점에서 FastAPI는 단순한 API 서버가 아니라
“요청 하나를 기준으로 전체 서버 흐름을 추적할 수 있는 엔트리 포인트”
이제 FastAPI에서 요청 컨텍스트를 실제로 어떻게 잡고 있는지를 코드 기준으로 살펴보겠습니다.
FastAPI는 내부적으로 ASGI 스펙을 따르기 때문에,
HTTP 요청뿐만 아니라 lifespan, websocket 등 다양한 타입의 이벤트가 들어옵니다.
그래서 가장 먼저 하는 일은
“이 요청이 HTTP 요청인지 아닌지”를 명확히 구분하는 것입니다.
로깅과 요청 추적의 대상은 HTTP 요청이기 때문에, 그 외의 타입은 그대로 다음 단계로 넘깁니다.
FastAPI에서 요청 흐름을 단순화해서 보면 다음과 같습니다.
- ASGI 서버(Uvicorn)가 요청을 수신
- FastAPI 애플리케이션 레벨 미들웨어 실행
- 의존성 주입(Dependency Injection)
- 라우터 매칭
- 컨트롤러(Endpoint 함수) 실행
다음은 실제 클라이언트 IP를 추출하는 부분입니다.
headers = {k.decode(): v.decode() for k, v in scope.get("headers", [])}
xff = headers.get("x-forwarded-for")
if xff:
ip = xff.split(",")[0].strip()
else:
client = scope.get("client")
ip = client[0] if client else "-"이 부분이 운영에서 굉장히 중요합니다.
온프레미스 환경 + Nginx 분리 구조에서는
FastAPI 서버가 직접 클라이언트 요청을 받지 않습니다.
실제 흐름은 보통 다음과 같습니다.
Client → Nginx → (여러 프록시) → FastAPI이 구조에서 scope["client"]에 들어오는 IP는 거의 항상 프록시 서버의 IP입니다.
그래서 실제 클라이언트 IP를 얻기 위해서는 X-Forwarded-For 헤더를 우선적으로 확인해야 합니다.
X-Forwarded-For는 다음과 같은 형태를 가질 수 있습니다.
X-Forwarded-For: client_ip, proxy1_ip, proxy2_ip이 경우 가장 앞에 있는 IP가
실제 요청을 보낸 클라이언트 IP이기 때문에,
xff.split(",")[0].strip()로 첫 번째 값만 사용합니다.
만약 프록시 환경이 아니거나 헤더가 없는 경우에는 fallback으로 scope["client"]를 사용합니다.
이렇게 하면,
- 프록시 환경에서도
- 로컬 테스트 환경에서도
- 예상치 못한 상황에서도
IP 값이 항상 하나의 규칙으로 결정됩니다.
이제 이 IP 값을 컨텍스트 변수(ContextVar)에 저장합니다.
token = request_ip.set(ip)여기서 중요한 포인트는
전역 변수(Global)가 아니라 ContextVar를 사용한다는 점입니다.
FastAPI는 비동기 환경이기 때문에, 전역 변수로 IP를 저장하면 요청이 섞이는 순간 바로 사고가 납니다.
ContextVar를 사용하면, 요청 A에서 설정한 IP는 요청 B에 절대 영향을 주지 않고 동일한 요청 흐름 안에서만 유지됩니다.
즉, 이 시점부터
- 컨트롤러
- 서비스 레이어
- OCR 워커 호출
- 외부 API 호출
어디에서 로그를 찍더라도
request_ip.get()만 호출하면 항상 같은 IP를 얻을 수 있습니다.
마지막으로 중요한 부분이 이 try / finally 블록입니다.
try:
await self.app(scope, receive, send)
finally:
request_ip.reset(token)요청 처리가 정상적으로 끝나든, 중간에 예외가 발생하든 상관없이 컨텍스트는 반드시 원래 상태로 복구됩니다.
이걸 해주지 않으면, 이전 요청의 IP가, 다음 요청 로그에 섞이는 아주 치명적인 버그가 발생할 수 있습니다.
운영 환경에서는 이런 버그가 “가끔 로그가 이상하게 찍히는 문제”로 나타나기 때문에 원인 추적이 정말 어렵습니다.
그래서 컨텍스트 설정은 반드시 reset까지 한 쌍으로 관리해야 합니다.
이렇게 하면, 로그를 예쁘게 볼 수 있습니다.
(추가적으로 저는 , Spring, Next , FastAPI ,Vllm 전체적으로 코드를 쓰고 읽을줄 알아서 전체 통합 로그 파일로 보는게 편하더라구요. 그래서 .sh 로 도커 컴포즈 안의 모든 컴포넌트의 로그들을 time stamp 로 나열해 보게끔 설정해두었습니다.)
#!/bin/bash
PROJECT_NAME="본인 프로젝트 이름 설정"
LEVEL="$1"
case "$LEVEL" in
debug)
docker compose -p $PROJECT_NAME logs -f --timestamps | grep -i debug
;;
info)
docker compose -p $PROJECT_NAME logs -f --timestamps | grep -i info
;;
error)
docker compose -p $PROJECT_NAME logs -f --timestamps | egrep -i "error|exception|failed|traceback"
;;
"")
# 인자 없으면 전체 로그
docker compose -p $PROJECT_NAME logs -f --timestamps
;;
*)
echo "Usage: $0 [debug|info|error]"
exit 1
;;
esac
