i3months · Sep 28, 2026 · Sep 28, 2026
diff --git a/backend/CLAUDE.md b/backend/CLAUDE.md
@@ -220,8 +220,16 @@ spring.jpa.hibernate.ddl-auto=validate   # Flyway 사용 → validate
 
 ## 14. 로깅
 
-- Logback JSON 포맷 (운영) / human-readable (로컬)
-- MDC에 `traceId`, `userId`
+- **평문 포맷** (`application.yml` 의 `logging.pattern.console`). JSON 아니다 — 로그 수집기가
+  없고 실제로 읽는 경로가 `docker logs` 라서. 문서가 오래 JSON 이라고 적어 뒀는데 그런 설정이
+  존재한 적이 없다(2026-09-28 정정).
+- **MDC `traceId` 는 로그 패턴에 포함된다** (`%X{traceId:-no-trace}`). 2026-09-28 이전에는
+  MDC 만 채우고 패턴이 참조하지 않아 **로그 어디에도 traceId 가 없었다.**
+- `TraceIdFilter` 는 `@Order(HIGHEST_PRECEDENCE)` — 없으면 Spring Security 체인(-100) 뒤로
+  밀려 **인증 실패 로그의 traceId 가 null 이 된다**(운영에서 실제로 그랬다).
+- RabbitMQ 컨슈머 5개는 `TraceContext.runWithTraceId(envelope.traceId(), …)` 로 감싼다 —
+  이게 없으면 큐를 건널 때마다 발행부가 새 traceId 를 만들어 추적이 끊긴다.
+- `userId` 는 아직 MDC 에 넣지 않는다.
 - 민감정보 마스킹 유틸: `common/log/PiiMasker.java` — **자동 적용 아님**(호출부에서만 동작, 현재 호출부 없음). 전역 필터로 꽂으면 트레이스 ID 가 뭉개진다: [`/docs/observability.md §9`](../docs/observability.md)
 - 자세한 정책: [`/docs/observability.md`](../docs/observability.md)
 

diff --git a/backend/src/main/java/com/stackup/stackup/common/trace/TraceContext.java b/backend/src/main/java/com/stackup/stackup/common/trace/TraceContext.java
@@ -21,4 +21,29 @@ public static void setTraceId(String traceId) {
     public static void clear() {
         MDC.remove(MDC_TRACE_ID);
     }
+
+    /**
+     * 비동기 처리(RabbitMQ 컨슈머)를 원 요청의 traceId 아래에서 실행한다.
+     *
+     * <p>엔벨로프는 처음부터 traceId 를 실어 왔지만 <b>컨슈머가 그걸 MDC 로 되돌리지
+     * 않았다.</b> 그래서 콜백 처리 로그는 traceId 없이 남고, 이어서 발행하는 메시지는
+     * {@code RabbitMessagePublisher} 가 <b>새 traceId 를 만들어</b> 붙였다(그 코드의 주석도
+     * "RabbitListener / EventListener 등에서 MDC 미주입 흐름" 이라고 적고 있다).
+     * 결과적으로 큐를 한 번 건널 때마다 추적이 끊겨, "한 요청의 모든 후속 처리에 동일
+     * traceId 전파"(docs/observability.md §1)가 실제로는 성립하지 않았다.
+     *
+     * <p>traceId 가 비어 있으면 새로 만든다 — 없는 것보다 낫고, 적어도 그 처리 한 건은
+     * 묶인다. 끝나면 반드시 지운다(스레드 풀 재사용 시 남은 값이 다음 메시지에 묻는다).
+     */
+    public static void runWithTraceId(String traceId, Runnable work) {
+        String effective = (traceId == null || traceId.isBlank())
+            ? java.util.UUID.randomUUID().toString()
+            : traceId;
+        try {
+            setTraceId(effective);
+            work.run();
+        } finally {
+            clear();
+        }
+    }
 }
diff --git a/backend/src/main/java/com/stackup/stackup/common/trace/TraceIdFilter.java b/backend/src/main/java/com/stackup/stackup/common/trace/TraceIdFilter.java
@@ -6,10 +6,25 @@
 import jakarta.servlet.http.HttpServletResponse;
 import java.io.IOException;
 import java.util.UUID;
+import org.springframework.core.Ordered;
+import org.springframework.core.annotation.Order;
 import org.springframework.stereotype.Component;
 import org.springframework.web.filter.OncePerRequestFilter;
 
+/**
+ * 모든 요청에 traceId 를 붙인다.
+ *
+ * <p><b>순서가 중요하다.</b> {@code @Order} 가 없으면 Spring Boot 는 이 필터를
+ * LOWEST_PRECEDENCE 로 등록하는데, Spring Security 체인은 -100 이라 <b>보안 체인이 먼저
+ * 돈다.</b> 그러면 인증 실패처럼 보안 체인 안에서 끝나는 요청은 이 필터에 닿지 못하고
+ * traceId 가 null 이 된다 — 운영 로그에 실제로 그렇게 찍혀 있었다:
+ *
+ * <pre>Authentication failed. code=AUTH_INVALID_TOKEN, traceId=null, uri=/api/.env</pre>
+ *
+ * 추적 ID 가 가장 필요한 순간(인증 실패·공격 스캔)에 정확히 빠져 있었다.
+ */
 @Component
+@Order(Ordered.HIGHEST_PRECEDENCE)
 public class TraceIdFilter extends OncePerRequestFilter {
 
     @Override

diff --git a/...nd/src/main/java/com/stackup/stackup/document/infrastructure/AnalysisCallbackHandler.java b/...nd/src/main/java/com/stackup/stackup/document/infrastructure/AnalysisCallbackHandler.java
@@ -1,5 +1,6 @@
 package com.stackup.stackup.document.infrastructure;
 
+import com.stackup.stackup.common.trace.TraceContext;
 import com.stackup.stackup.document.application.AnalysisCallbackService;
 import com.stackup.stackup.document.application.dto.AnalysisCallbackEnvelope;
 import lombok.RequiredArgsConstructor;
@@ -19,12 +20,16 @@ public class AnalysisCallbackHandler {
 
     @RabbitListener(queues = "${app.messaging.rabbitmq.queues.names.core-callback-analysis}")
     public void handle(AnalysisCallbackEnvelope envelope) {
-        try {
-            callbackService.apply(envelope);
-        } catch (RuntimeException e) {
-            log.error("callback.analysis processing failed. messageId={}",
-                envelope == null ? null : envelope.messageId(), e);
-            throw e;
-        }
+        TraceContext.runWithTraceId(
+            envelope == null ? null : envelope.traceId(),
+            () -> {
+            try {
+                callbackService.apply(envelope);
+            } catch (RuntimeException e) {
+                log.error("callback.analysis processing failed. messageId={}",
+                    envelope == null ? null : envelope.messageId(), e);
+                throw e;
+            }
+            });
     }
 }
diff --git a/...end/src/main/java/com/stackup/stackup/session/infrastructure/FeedbackCallbackHandler.java b/...end/src/main/java/com/stackup/stackup/session/infrastructure/FeedbackCallbackHandler.java
@@ -1,5 +1,6 @@
 package com.stackup.stackup.session.infrastructure;
 
+import com.stackup.stackup.common.trace.TraceContext;
 import com.stackup.stackup.session.application.FeedbackCallbackService;
 import com.stackup.stackup.session.application.dto.FeedbackCallbackEnvelope;
 import lombok.RequiredArgsConstructor;
@@ -19,12 +20,16 @@ public class FeedbackCallbackHandler {
 
     @RabbitListener(queues = "${app.messaging.rabbitmq.queues.names.core-callback-feedback}")
     public void handle(FeedbackCallbackEnvelope envelope) {
-        try {
-            callbackService.apply(envelope);
-        } catch (RuntimeException e) {
-            log.error("callback.feedback processing failed. messageId={}",
-                envelope == null ? null : envelope.messageId(), e);
-            throw e;
-        }
+        TraceContext.runWithTraceId(
+            envelope == null ? null : envelope.traceId(),
+            () -> {
+            try {
+                callbackService.apply(envelope);
+            } catch (RuntimeException e) {
+                log.error("callback.feedback processing failed. messageId={}",
+                    envelope == null ? null : envelope.messageId(), e);
+                throw e;
+            }
+            });
     }
 }
diff --git a/...nd/src/main/java/com/stackup/stackup/session/infrastructure/QuestionsCallbackHandler.java b/...nd/src/main/java/com/stackup/stackup/session/infrastructure/QuestionsCallbackHandler.java
@@ -1,5 +1,6 @@
 package com.stackup.stackup.session.infrastructure;
 
+import com.stackup.stackup.common.trace.TraceContext;
 import com.stackup.stackup.session.application.QuestionsCallbackService;
 import com.stackup.stackup.session.application.dto.QuestionsCallbackEnvelope;
 import lombok.RequiredArgsConstructor;
@@ -19,12 +20,16 @@ public class QuestionsCallbackHandler {
 
     @RabbitListener(queues = "${app.messaging.rabbitmq.queues.names.core-callback-questions}")
     public void handle(QuestionsCallbackEnvelope envelope) {
-        try {
-            callbackService.apply(envelope);
-        } catch (RuntimeException e) {
-            log.error("callback.questions processing failed. messageId={}",
-                envelope == null ? null : envelope.messageId(), e);
-            throw e;
-        }
+        TraceContext.runWithTraceId(
+            envelope == null ? null : envelope.traceId(),
+            () -> {
+            try {
+                callbackService.apply(envelope);
+            } catch (RuntimeException e) {
+                log.error("callback.questions processing failed. messageId={}",
+                    envelope == null ? null : envelope.messageId(), e);
+                throw e;
+            }
+            });
     }
 }
diff --git a/backend/src/main/java/com/stackup/stackup/session/infrastructure/TtsCallbackHandler.java b/backend/src/main/java/com/stackup/stackup/session/infrastructure/TtsCallbackHandler.java
@@ -1,5 +1,6 @@
 package com.stackup.stackup.session.infrastructure;
 
+import com.stackup.stackup.common.trace.TraceContext;
 import com.stackup.stackup.session.application.TtsCallbackService;
 import com.stackup.stackup.session.application.dto.TtsCallbackEnvelope;
 import lombok.RequiredArgsConstructor;
@@ -18,12 +19,16 @@ public class TtsCallbackHandler {
 
     @RabbitListener(queues = "${app.messaging.rabbitmq.queues.names.core-callback-tts}")
     public void handle(TtsCallbackEnvelope envelope) {
-        try {
-            callbackService.apply(envelope);
-        } catch (RuntimeException e) {
-            log.error("callback.tts processing failed. messageId={}",
-                envelope == null ? null : envelope.messageId(), e);
-            throw e;
-        }
+        TraceContext.runWithTraceId(
+            envelope == null ? null : envelope.traceId(),
+            () -> {
+            try {
+                callbackService.apply(envelope);
+            } catch (RuntimeException e) {
+                log.error("callback.tts processing failed. messageId={}",
+                    envelope == null ? null : envelope.messageId(), e);
+                throw e;
+            }
+            });
     }
 }
diff --git a/backend/src/main/java/com/stackup/stackup/session/infrastructure/VoiceCallbackHandler.java b/backend/src/main/java/com/stackup/stackup/session/infrastructure/VoiceCallbackHandler.java
@@ -1,5 +1,6 @@
 package com.stackup.stackup.session.infrastructure;
 
+import com.stackup.stackup.common.trace.TraceContext;
 import com.stackup.stackup.session.application.VoiceCallbackService;
 import com.stackup.stackup.session.application.dto.VoiceCallbackEnvelope;
 import lombok.RequiredArgsConstructor;
@@ -19,12 +20,16 @@ public class VoiceCallbackHandler {
 
     @RabbitListener(queues = "${app.messaging.rabbitmq.queues.names.core-callback-voice}")
     public void handle(VoiceCallbackEnvelope envelope) {
-        try {
-            callbackService.apply(envelope);
-        } catch (RuntimeException e) {
-            log.error("callback.voice processing failed. messageId={}",
-                envelope == null ? null : envelope.messageId(), e);
-            throw e;
-        }
+        TraceContext.runWithTraceId(
+            envelope == null ? null : envelope.traceId(),
+            () -> {
+            try {
+                callbackService.apply(envelope);
+            } catch (RuntimeException e) {
+                log.error("callback.voice processing failed. messageId={}",
+                    envelope == null ? null : envelope.messageId(), e);
+                throw e;
+            }
+            });
     }
 }
diff --git a/backend/src/main/resources/application.yml b/backend/src/main/resources/application.yml
@@ -26,6 +26,20 @@ spring:
 server:
   port: ${SERVER_PORT:38010}
 
+# traceId 를 **로그 줄에** 싣는다.
+#
+# TraceIdFilter 가 MDC 에 넣고 엔벨로프가 큐 너머로 실어 나르는데도, 지금까지 운영 로그에는
+# traceId 가 없었다 — 로그 패턴이 MDC 를 참조하지 않아서다. SecurityConfig·
+# GlobalExceptionHandler 처럼 **메시지 문자열에 직접 박아 넣은 몇 줄만** 보였고, 나머지는
+# 전부 추적 불가였다. 즉 MDC 를 채우는 코드가 사실상 아무 일도 하지 않고 있었다.
+#
+# JSON 포맷은 쓰지 않는다. docs/observability.md §2.1 이 JSON 을 적어 뒀지만 로그를 모아 가는
+# 수집기가 없고, 실제로 읽는 경로는 `docker logs` 다 — 거기서는 평문이 더 낫다.
+# 수집기를 도입할 때 encoder 를 바꾸면 된다(문서도 그렇게 정정했다).
+logging:
+  pattern:
+    console: "%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX} %5p [%X{traceId:-no-trace}] [%t] %-40.40logger{39} : %m%n%wEx"
+
 management:
   endpoints:
     web:

diff --git a/backend/src/test/java/com/stackup/stackup/common/trace/TraceContextTest.java b/backend/src/test/java/com/stackup/stackup/common/trace/TraceContextTest.java
@@ -0,0 +1,67 @@
+package com.stackup.stackup.common.trace;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+import java.util.ArrayList;
+import java.util.List;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.Test;
+import org.slf4j.MDC;
+
+/**
+ * 엔벨로프는 처음부터 traceId 를 실어 왔지만 컨슈머가 MDC 로 되돌리지 않아,
+ * 큐를 한 번 건널 때마다 추적이 끊겼다(발행 시점에 새 traceId 가 생성됐다).
+ */
+class TraceContextTest {
+
+    @AfterEach
+    void cleanup() {
+        MDC.clear();
+    }
+
+    @Test
+    void runWithTraceId_작업_중에는_MDC에_있고_끝나면_지워진다() {
+        List<String> seen = new ArrayList<>();
+
+        TraceContext.runWithTraceId("trace-from-envelope", () -> seen.add(TraceContext.getTraceId()));
+
+        assertThat(seen).containsExactly("trace-from-envelope");
+        // 스레드 풀이 재사용되므로 남기면 다음 메시지 로그에 엉뚱한 traceId 가 묻는다.
+        assertThat(TraceContext.getTraceId()).isNull();
+    }
+
+    @Test
+    void runWithTraceId_예외가_나도_MDC를_지운다() {
+        try {
+            TraceContext.runWithTraceId("t", () -> {
+                throw new IllegalStateException("boom");
+            });
+        } catch (IllegalStateException expected) {
+            // 컨슈머는 예외를 다시 던져 DLQ 로 보낸다 — 그 경로에서도 정리돼야 한다.
+        }
+
+        assertThat(TraceContext.getTraceId()).isNull();
+    }
+
+    @Test
+    void runWithTraceId_예외를_그대로_전파한다() {
+        // 삼키면 메시지가 ack 되어 DLQ 로 가지 않는다.
+        org.assertj.core.api.Assertions
+            .assertThatThrownBy(() -> TraceContext.runWithTraceId("t", () -> {
+                throw new IllegalStateException("boom");
+            }))
+            .isInstanceOf(IllegalStateException.class);
+    }
+
+    @Test
+    void runWithTraceId_비어있으면_새로_만든다() {
+        List<String> seen = new ArrayList<>();
+
+        TraceContext.runWithTraceId(null, () -> seen.add(TraceContext.getTraceId()));
+        TraceContext.runWithTraceId("  ", () -> seen.add(TraceContext.getTraceId()));
+
+        // 없는 것보다 낫다 — 적어도 그 처리 한 건은 묶인다.
+        assertThat(seen).hasSize(2).doesNotContainNull();
+        assertThat(seen.get(0)).isNotEqualTo(seen.get(1));
+    }
+}
diff --git a/backend/src/test/java/com/stackup/stackup/common/trace/TraceIdFilterOrderTest.java b/backend/src/test/java/com/stackup/stackup/common/trace/TraceIdFilterOrderTest.java
@@ -0,0 +1,35 @@
+package com.stackup.stackup.common.trace;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+import org.junit.jupiter.api.Test;
+import org.springframework.core.Ordered;
+import org.springframework.core.annotation.AnnotationUtils;
+import org.springframework.core.annotation.Order;
+
+/**
+ * 필터 순서가 틀리면 **인증 실패 로그에 traceId 가 없다.**
+ *
+ * <p>@Order 가 없으면 Spring Boot 는 LOWEST_PRECEDENCE 로 등록하는데 Spring Security 체인은
+ * -100 이라 보안 체인이 먼저 돈다. 인증 실패는 보안 체인 안에서 끝나므로 TraceIdFilter 에
+ * 닿지 못한다. 운영 로그에 실제로 그렇게 찍혀 있었다:
+ * {@code Authentication failed. code=AUTH_INVALID_TOKEN, traceId=null, uri=/api/.env}
+ *
+ * <p>추적 ID 가 가장 필요한 순간(인증 실패·공격 스캔)에 정확히 빠져 있었고, 이 순서는
+ * 애노테이션 한 줄이 지워져도 컴파일·테스트가 통과하며 <b>운영에서도 조용하다</b>.
+ */
+class TraceIdFilterOrderTest {
+
+    @Test
+    void 보안_필터체인보다_먼저_돈다() {
+        Order order = AnnotationUtils.findAnnotation(TraceIdFilter.class, Order.class);
+
+        assertThat(order)
+            .as("@Order 가 없으면 Spring Security(-100) 뒤로 밀려 인증 실패에 traceId 가 없다")
+            .isNotNull();
+        assertThat(order.value())
+            .as("Spring Security 기본 필터 순서(-100)보다 앞서야 한다")
+            .isEqualTo(Ordered.HIGHEST_PRECEDENCE)
+            .isLessThan(-100);
+    }
+}