Repository navigation
fix(core): traceId 를 실제로 쓸 수 있게 — 로그 출력·필터 순서·큐 전파 - #262
Merged
Merged
Conversation
문서가 주장하는 동작이 코드에 있는지 전수 대조하다 나왔다(#260 의 "README 는 Discord 알림이 있다는데 코드엔 없던" 건과 같은 종류를 찾던 중). 분산 추적은 **배선은 돼 있는데 쓸 수가 없는** 상태였다. 세 군데가 끊겨 있었다. ## 1. MDC 를 채우는데 로그에 안 나온다 TraceIdFilter 가 요청마다 MDC 에 traceId 를 넣지만, **로그 패턴이 MDC 를 참조하지 않았다.** logback 설정 파일도 logging 설정도 없어 Spring Boot 기본 패턴이 그대로 쓰였다. 그래서 운영 로그에서 traceId 가 보이는 줄은 메시지 문자열에 직접 박아 넣은 SecurityConfig·GlobalExceptionHandler 몇 줄뿐이고 나머지는 전부 추적 불가였다. MDC 를 채우는 코드가 사실상 아무 일도 하지 않고 있었다. logging.pattern.console 에 %X{traceId:-no-trace} 를 넣었다. traceId 가 없는 흐름(스케줄러 스위퍼)은 no-trace 로 뜬다 — 빈칸이면 "추적이 끊긴 것"과 "원래 요청이 없는 것"이 구분되지 않는다. JSON 은 넣지 않았다. docs 가 JSON 이라고 적어 뒀지만 그런 설정이 존재한 적이 없고, 로그 수집기도 없다. 실제로 읽는 경로는 docker logs 라 평문이 낫다. 문서를 사실에 맞게 고쳤다. ## 2. 인증 실패에는 traceId 가 null 이었다 운영 로그: Authentication failed. code=AUTH_INVALID_TOKEN, traceId=null, uri=/api/.env @order 가 없어 Spring Boot 가 LOWEST_PRECEDENCE 로 등록했고, Spring Security 체인은 -100 이라 보안 체인이 먼저 돈다. 인증 실패는 그 안에서 끝나므로 TraceIdFilter 에 닿지 못한다. **추적 ID 가 가장 필요한 순간(인증 실패·공격 스캔)에 정확히 빠져 있었다.** @order(HIGHEST_PRECEDENCE) 를 붙였다. ## 3. 큐를 건너면 추적이 끊겼다 엔벨로프는 처음부터 traceId 를 실어 왔는데 **컨슈머가 MDC 로 되돌리지 않았다.** 그래서 콜백 처리 로그에 traceId 가 없고, 이어서 발행하는 메시지는 RabbitMessagePublisher 가 새 traceId 를 만들어 붙였다 — 그 코드의 주석도 "RabbitListener / EventListener 등에서 MDC 미주입 흐름" 이라고 적고 있다. docs/observability.md §1 의 "한 요청의 모든 후속 처리에 동일 traceId 전파" 는 성립하지 않았다. @RabbitListener 5개를 TraceContext.runWithTraceId 로 감쌌다. finally 로 반드시 지운다 — 스레드 풀이 재사용되므로 남기면 다음 메시지 로그에 엉뚱한 traceId 가 묻는다. ## 테스트 TraceContextTest 4개 (작업 중 설정·종료 후 정리·예외 시에도 정리·예외 전파· 빈 값이면 새로 생성), TraceIdFilterOrderTest 1개. 순서 애노테이션은 지워져도 컴파일·테스트가 통과하고 **운영에서도 조용하다** — 그래서 테스트로 고정했다. 백엔드 전체 333건 통과, 0 실패. ## 남은 것 AI 서버 로그에는 아직 traceId 가 없다(uvicorn 기본 액세스 로그). userId 도 MDC 에 넣지 않는다. 둘 다 문서에 남겼다.
i3months
added a commit
to i3months/stackup
that referenced
this pull request
Oct 6, 2026
Team-StackUp#262 로 Core 쪽 추적을 고치고 "AI 서버 로그에는 아직 traceId 가 없다" 를 남은 과제로 적어 뒀는데, 그 이유가 따로 있었다. ai/CLAUDE.md 는 컨슈머 패턴으로 이렇게 안내해 왔다: with trace_context(envelope.trace_id): await resume_analyzer.handle(envelope.payload) **그런데 trace_context 가 존재한 적이 없다.** 문서를 따라 쓰면 ImportError 가 나고, 실제 컨슈머들은 traceId 를 로그에 전혀 싣지 않았다. 오늘만 세 번째다 — infra/backup/README 의 Discord 알림(Team-StackUp#260), Core 의 "동일 traceId 전파"(Team-StackUp#262), 그리고 이것. 문서가 주장하는 동작은 grep 으로 확인해야 한다. ## 구현 observability/trace.py. structlog 기본 프로세서 체인의 첫 번째가 merge_contextvars 인 것을 실측으로 확인하고 그 위에 올렸다: 기본 프로세서: ['merge_contextvars', 'add_log_level', 'StackInfoRenderer', 'set_exc_info', 'TimeStamper', ...] 한 번 묶으면 그 구간의 **모든 로그 줄에 자동으로** 실린다 — 호출부마다 인자로 넘길 필요가 없다. 적용 지점 3곳: consume_with_failure_signal(생성·분석 컨슈머 공통) + voice/tts(직접-발행 모델). 비어 있으면 새로 만든다. 끝나면 반드시 되돌린다 — 워커 태스크가 재사용되면 남은 값이 다음 메시지 로그에 묻는다. ## 테스트 "바인딩했다"가 아니라 **"출력에 나온다"** 를 본다. Core 에서 겪은 함정이 정확히 그거였다 — MDC 는 채우는데 로그 패턴이 참조하지 않아 아무 데도 안 나왔다. trace_id 가 실제 로그 엔트리에 실린다 / 빠져나오면 지워진다 비어 있으면 생성하고 서로 다르다 예외로 빠져나와도 지워진다(컨슈머는 예외를 다시 던져 DLQ 로 보낸다) **동시 메시지 3건이 서로의 traceId 를 오염시키지 않는다** — 추적이 틀린 것은 없는 것보다 나쁘다 AI 전체 422건 통과.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
존재 확인(
PiiMasker·GithubTokenCipher·SSRF 가드·멱등·DLQ·ArchUnit·Testcontainers …)은전부 통과했다. 하지만 "있다"와 "실제로 동작한다"는 다르다. 분산 추적은 배선은 돼 있는데
쓸 수가 없는 상태였고, 끊긴 곳이 세 군데였다.
1. MDC 를 채우는데 로그에 안 나온다
TraceIdFilter가 요청마다 MDC 에 traceId 를 넣는다. 그런데 로그 패턴이 MDC 를 참조하지않았다 —
logback-spring.xml도 없고logging:설정도 없어 Spring Boot 기본 패턴이 쓰였다.운영 로그에서 traceId 가 보이는 줄은 메시지 문자열에 직접 박아 넣은 두 곳뿐이었다:
MDC 를 채우는 코드가 사실상 아무 일도 하지 않고 있었다.
logging.pattern.console에%X{traceId:-no-trace}를 넣었다. traceId 가 없는 흐름(스케줄러스위퍼)은
no-trace로 뜬다 — 빈칸이면 "추적이 끊긴 것"과 "원래 요청이 없는 것"이 구분되지 않는다.JSON 은 넣지 않았다.
docs/observability.md §2.1이 JSON 예시를 싣고 있었지만 그런 설정이존재한 적이 없고, 로그 수집기도 없다. 실제로 읽는 경로는
docker logs라 평문이 낫다.없는 걸 문서가 주장하던 상태를 고치는 게 목적이지, 안 쓰는 걸 만드는 게 목적이 아니다 —
문서를 사실에 맞게 정정했다.
2. 인증 실패에는 traceId 가 항상 null
운영 로그 실물:
@Order가 없어 Spring Boot 가LOWEST_PRECEDENCE로 등록했고, Spring Security 체인은-100이라 보안 체인이 먼저 돈다. 인증 실패는 그 안에서 끝나므로TraceIdFilter에닿지 못한다.
추적 ID 가 가장 필요한 순간(인증 실패·공격 스캔)에 정확히 빠져 있었다.
3. 큐를 건너면 추적이 끊긴다
엔벨로프는 처음부터 traceId 를 실어 왔는데 컨슈머가 MDC 로 되돌리지 않았다. 그래서 콜백
처리 로그에 traceId 가 없고, 이어서 발행하는 메시지는
RabbitMessagePublisher가 새traceId 를 만들어 붙였다 — 그 코드의 주석도 이미 인정하고 있다:
// RabbitListener / EventListener 등에서 MDC 미주입 흐름 — 발행 시점에 새 traceId 생성.docs/observability.md §1의 "한 요청의 모든 후속 처리(REST/Queue/SSE)에 동일 traceId 전파"는 성립하지 않았다.
@RabbitListener5개를TraceContext.runWithTraceId로 감쌌다.finally로 반드시 지운다 — 스레드 풀이 재사용되므로 남기면 다음 메시지 로그에 엉뚱한traceId 가 묻는다.
테스트
TraceContextTest(4)TraceIdFilterOrderTest(1)@Order존재 + Security 기본 순서(-100)보다 앞섬순서 애노테이션은 지워져도 컴파일·테스트가 통과하고 운영에서도 조용하다 — 그래서 고정했다.
백엔드 전체 333건 통과, 0 실패.
배포 후 확인할 것
docker logs stackup-backend한 줄에[3f2a…-9c1b]형태가 붙는지. 인증 실패 줄의traceId=null이 사라지는지.남은 것
ai_request_logs로만 가능하다.userId는 MDC 에 넣지 않는다.둘 다 문서에 남겼다.