서블릿 async 재디스패치에서 preHandle이 두 번 돌고 응답 객체가 바뀌는 이유

컨트롤러가 Mono를 반환하면 DispatcherServlet.doDispatch()가 한 요청에 두 번 실행된다. 그래서 HandlerInterceptor.preHandle()도 두 번 돈다. 나는 이걸 모르고 요청 ID를 인터셉터에서 발급하는 코드를 봤다가, 같은 요청의 로그 두 줄이 서로 다른 ID를 갖는 현상을 추적하게 됐다. 두 번째 실행에서는 인터셉터가 받는 응답 객체도 달라진다. 필터에서 감싼 응답 래퍼를 인터셉터에서 instanceof로 확인하던 코드가 그래서 동작하지 않았다.

이 글은 네 질문에 답한다.

• DispatcherType은 무엇이고 왜 있는가
• Mono를 반환했을 뿐인데 왜 디스패치가 두 번 도는가
• 그 전제를 모르고 짠 코드는 어디서 깨지는가
• 재디스패치에서 인터셉터가 받는 응답 객체는 왜 필터가 넘긴 것과 다른가

요청 파이프라인에서 Filter, Interceptor, AOP를 어디에 둘지가 먼저 궁금하면 Filter, Interceptor, AOP를 먼저 읽으면 좋다. 이 글은 그중 Interceptor가 몇 번 실행되고 어떤 응답 객체를 받는지를 다룬다.

확인에 쓴 버전은 Spring Framework 6.1.8, Spring Boot 3.3.0, Tomcat 10.1.24, Jakarta Servlet 6.0이다. 아래 인용한 소스 줄번호는 모두 그 버전 기준이고, 실행 결과는 직접 돌려서 얻었다.

톰캣이 서블릿을 호출하고, 서블릿이 컨트롤러로 연결한다

평소에는 @RestController와 @GetMapping만 작성해도 HTTP 요청을 받을 수 있다. 하지만 컨트롤러가 직접 네트워크 연결을 받고 HTTP 메시지를 읽는 것은 아니다. 그 앞에서 톰캣과 Spring MVC가 요청을 Java 메서드 호출로 연결한다.

서블릿은 요청을 받아 응답을 만드는 Java 컴포넌트다. Servlet API의 service(request, response)가 요청 처리 진입점이다. HTTP용 기본 클래스인 HttpServlet은 HTTP 메서드에 따라 doGet(), doPost() 등으로 연결한다.

서블릿 컨테이너는 서블릿을 실행하고 관리하는 환경이다. 서블릿의 생성과 초기화, URL 매핑, 요청·응답 객체 제공과 service() 호출을 담당한다. 톰캣이 이 역할을 한다. 여기서 컨테이너는 Docker 컨테이너를 뜻하지 않는다. Spring의 Bean을 관리하는 Spring 컨테이너와도 역할이 다르다. 이 구분은 Jakarta Servlet 6.0 명세의 개요를 기준으로 한다.

Spring MVC에서는 Spring이 제공하는 DispatcherServlet이 서블릿 역할을 맡는다. 이 서블릿이 요청에 맞는 컨트롤러 메서드를 찾아 실행하도록 연결한다. 우리가 작성한 @RestController 자체가 서블릿인 것은 아니다. Spring 공식 문서도 이 구조를 DispatcherServlet을 중심으로 한 요청 처리로 설명한다.

이 글의 내장 톰캣 기반 Spring Boot 애플리케이션에서 GET /orders를 받는 흐름은 다음과 같다.

1. 톰캣이 네트워크로 HTTP 요청을 받는다.
2. 톰캣은 HttpServletRequest와 HttpServletResponse를 제공하고, URL에 매핑된 서블릿과 적용할 필터를 찾는다.
3. 필터 체인을 거쳐 DispatcherServlet.service()가 호출된다.
4. DispatcherServlet 내부의 doDispatch()에서 인터셉터와 컨트롤러 호출이 이어진다.
5. 컨트롤러 반환값을 Spring MVC가 응답 본문으로 쓰고, 톰캣이 클라이언트로 전송한다.

톰캣의 서블릿 URL 매핑과 Spring MVC의 @GetMapping은 서로 다른 단계다. 톰캣은 어느 서블릿에 넘길지 정하고, DispatcherServlet은 어느 컨트롤러 메서드로 연결할지 정한다. Spring Boot가 내장 톰캣 구동과 서블릿 등록을 자동으로 처리해 주므로, 컨트롤러만 작성할 때는 앞 단계가 잘 드러나지 않는다.

한 HTTP 요청 안에서도 서블릿을 다시 호출할 수 있다

서블릿 호출이 끝나는 시점과 HTTP 요청 처리가 끝나는 시점이 항상 같지는 않다. 처리 중 다른 서버 내부 자원에 작업을 넘기거나, 비동기 결과를 기다렸다가 처리를 이어갈 수도 있다. 이처럼 컨테이너가 요청을 처리할 자원으로 넘기는 동작을 디스패치라고 부른다.

예를 들어 서블릿에서 인증을 확인한 뒤 RequestDispatcher.forward()로 JSP에 화면 생성을 맡길 수 있다. JSP도 컨테이너에서는 서블릿으로 변환되어 실행된다. 브라우저가 HTTP 요청을 새로 보내는 대신, 컨테이너가 진행 중인 요청과 응답을 대상에 넘긴다. 반면 sendRedirect()는 클라이언트에 새 주소로 요청하도록 응답하므로, 클라이언트가 따라가면 별도의 HTTP 요청이 생긴다. 이 차이는 Servlet 명세의 요청 디스패치에 따른다.

이 글에서 다루는 비동기 처리도 요청을 이어가는 경우다. 첫 번째 DispatcherServlet 호출에서는 비동기 처리를 시작하고 반환한다. 나중에 결과가 준비되면 Spring이 AsyncContext.dispatch()를 호출하고, 톰캣이 같은 요청으로 DispatcherServlet을 다시 호출한다. 클라이언트는 요청을 한 번 보냈지만, 서버 안에서는 서블릿에 두 번 진입하는 것이다. 자세한 실행 순서는 뒤의 「Mono를 반환하면 흐름이 둘로 나뉜다」 절에서 다룬다.

DispatcherType은 서블릿에 진입한 유형을 나타낸다

서블릿 컨테이너는 하나의 요청을 서블릿에 여러 번 넘길 수 있다. DispatcherType은 지금 진입이 최초 요청인지, forward인지, 비동기 재디스패치인지를 나타내는 enum이다. 여기서 말하는 유형은 요청 URL이나 HTTP 메서드와 별개다.

ASYNC는 컨테이너가 결과의 완성을 판정했다는 뜻은 아니다. 이 글의 Spring MVC 흐름에서는 결과가 준비되면 Spring이 dispatch()를 호출하기 때문에, 결과 확정 뒤에 ASYNC 진입이 생긴다.

여기서 중요한 건 다시 들어올 때도 같은 요청을 이어서 쓴다는 점이다. 컨테이너가 요청 객체를 한 겹 감싸서 넘길 수는 있어도 request attribute는 그대로 남는다. forward한 서블릿에서 request.getAttribute()로 앞 서블릿이 넣어 둔 값을 읽을 수 있는 것과 같은 이유다. 응답 객체는 사정이 다른데, 그 내용은 뒤의 「재디스패치에서는 응답 객체가 한 겹 더 감싸진다」 절에서 다룬다.

DispatcherType이 enum으로 노출된 이유는 필터 매핑 단위가 이것이기 때문이다. web.xml의 <dispatcher>나 FilterRegistrationBean.setDispatcherTypes()로 "이 필터는 어느 경로의 진입에서 돌 것인가"를 지정한다. Spring Boot의 기본값은 이렇게 정해진다.

// AbstractFilterRegistrationBean.determineDispatcherTypes() — Spring Boot 3.3.0
if (this.dispatcherTypes == null) {
    if (... && filter instanceof OncePerRequestFilter) {
        return EnumSet.allOf(DispatcherType.class);
    }
    else {
        return EnumSet.of(DispatcherType.REQUEST);
    }
}

Filter를 직접 구현하면 REQUEST에만 등록되고, OncePerRequestFilter를 상속하면 전 경로에 등록된다. 다만 후자도 실제로는 async 진입에서 본문을 건너뛴다.

// OncePerRequestFilter.doFilter() 안
if (isAsyncDispatch(request) && shouldNotFilterAsyncDispatch()) { ... }
 
// 그리고 기본값은
protected boolean shouldNotFilterAsyncDispatch() {
    return true;
}

즉 필터는 기본 설정에서 async 재진입 때 실행되지 않는다. 인터셉터는 재진입 때도 다시 실행된다. 이 차이가 뒤에서 preHandle 중복 실행과 응답 래퍼 문제로 이어진다.

동기 요청은 service()가 한 번 돈다

먼저 평범한 요청을 보자.

톰캣이 스레드를 하나 잡아 service()를 호출하고, DispatcherServlet.doDispatch()가 핸들러를 찾고 인터셉터를 실행하고 컨트롤러를 부른다. 반환값으로 응답을 쓰고 스레드를 반납한다. 요청 하나에 service() 한 번, doDispatch() 한 번이다.

DispatcherType은 REQUEST 하나만 등장하고 끝난다.

Mono를 반환하면 흐름이 둘로 나뉜다

컨트롤러가 Mono를 반환하는 순간 사정이 달라진다. 반환 시점에는 아직 결과가 없다. 모델 서버 응답을 기다려야 한다면 몇 초 뒤에 나온다.

Spring MVC는 이런 반환값을 결과를 나중에 주겠다는 약속으로 받아들인다. Callable, DeferredResult, CompletableFuture, 그리고 Mono와 Flux가 모두 여기에 해당한다. Mono는 내부에서 DeferredResult로 감싸진다.

이때 Spring은 request.startAsync()를 호출한다. 그러면 두 가지가 벌어진다.

• service()가 응답을 닫지 않은 채 그냥 리턴한다. 소켓은 열려 있고 요청은 보류 상태로 남는다.
• 톰캣 스레드는 풀로 돌아가 다른 요청을 받는다.

그리고 나중에 결과가 확정되면 Spring이 컨테이너에게 요청을 되돌려 준다.

// WebAsyncManager:393
this.asyncWebRequest.dispatch();
 
// StandardServletAsyncWebRequest:169
this.asyncContext.dispatch();

AsyncContext.dispatch()가 하는 일이 이 글의 핵심이다. 이 호출은 결과를 알려 주는 통지가 아니다.

dispatch()는 이 요청을 서블릿 파이프라인에서 처음부터 다시 처리해 달라는 요청이다.

컨테이너는 스레드를 새로 잡아 service()를 다시 호출한다. 이번 진입의 DispatcherType이 ASYNC다. 그래서 doDispatch()도 다시 돈다.

forward와 같은 계열로 이해하면 쉽다. forward하면 같은 요청으로 서블릿이 한 번 더 실행되는데, async 재디스패치도 똑같이 같은 요청으로 다시 실행된다. 구분은 DispatcherType 값뿐이다.

doDispatch는 DispatcherType을 보지 않는다

여기까지가 요청이 다시 들어오는 이유다. 다시 들어왔을 때 인터셉터가 또 실행되는 이유는 doDispatch() 코드에 있다.

// DispatcherServlet.java:1049 부터, 요지만 발췌
protected void doDispatch(HttpServletRequest request, HttpServletResponse response) throws Exception {
    WebAsyncManager asyncManager = WebAsyncUtils.getAsyncManager(request);
    ...
    mappedHandler = getHandler(processedRequest);          // 1065
    HandlerAdapter ha = getHandlerAdapter(mappedHandler.getHandler());
 
    if (!mappedHandler.applyPreHandle(processedRequest, response)) {   // 1084
        return;
    }
 
    mv = ha.handle(processedRequest, response, mappedHandler.getHandler());
 
    if (asyncManager.isConcurrentHandlingStarted()) {      // 1091
        return;
    }
 
    applyDefaultViewName(processedRequest, mv);
    mappedHandler.applyPostHandle(processedRequest, response, mv);
    ...
}

읽을 점이 셋이다.

• DispatcherType을 확인하는 분기가 없다. doDispatch()는 자기가 몇 번째 진입인지 모른다. 호출되면 처음부터 다 한다.
• 그래서 1084줄의 applyPreHandle()이 무조건 다시 실행된다. 등록된 인터셉터를 전부 순회해 preHandle()을 부르는 게 이 메서드가 하는 일이다.
• 1091줄에서 async가 시작됐으면 return한다. 그래서 첫 진입에서는 applyPostHandle()이 실행되지 않는다.

postHandle과 afterCompletion은 첫 진입에서 실행되지 않고 대신 다른 콜백으로 대체된다.

// doDispatch 의 finally, DispatcherServlet.java:1116
if (asyncManager.isConcurrentHandlingStarted()) {
    // Instead of postHandle and afterCompletion
    if (mappedHandler != null) {
        mappedHandler.applyAfterConcurrentHandlingStarted(processedRequest, response);
    }
}

여기서 불리는 건 AsyncHandlerInterceptor.afterConcurrentHandlingStarted()다. HandlerInterceptor만 구현했다면 이 인터페이스가 없으니 아무 일도 일어나지 않는다. 결과적으로 첫 진입에서는 preHandle만 돌고 끝난다.

정리하면 한 요청에서 인터셉터 콜백은 이렇게 나뉜다.

그런데 컨트롤러는 다시 불리지 않는다

doDispatch()가 통째로 다시 도는데 컨트롤러 메서드까지 두 번 불리면 큰일이다. 그건 막혀 있다. 막는 위치가 핸들러 어댑터 안이다.

// RequestMappingHandlerAdapter.invokeHandlerMethod() — 913줄 부근
if (asyncManager.hasConcurrentResult()) {
    Object result = asyncManager.getConcurrentResult();
    ...
    asyncManager.clearConcurrentResult();
    invocableMethod = invocableMethod.wrapConcurrentResult(result);
}
 
invocableMethod.invokeAndHandle(webRequest, mavContainer);

재진입 시점에는 WebAsyncManager에 결과가 이미 들어 있다. 그러면 컨트롤러 메서드 대신 그 결과를 돌려주기만 하는 핸들러로 교체한다. 이후 invokeAndHandle()은 결과 변환과 응답 쓰기만 수행한다.

이 비대칭이 이 구조에서 가장 헷갈리는 지점이다.

• doDispatch — 두 번 돈다
• applyPreHandle — 두 번 돈다
• 컨트롤러 메서드 — 한 번만 돈다

직접 세어 본 결과

소스만 읽고 넘어가면 기억에 남지 않을 것 같아 호출 횟수를 직접 세어 봤다. MockMvc로 Mono를 반환하는 컨트롤러를 호출하고, 인터셉터의 preHandle이 몇 번 불리는지와 그때의 DispatcherType을 찍었다.

MockMvc mvc = MockMvcBuilders.standaloneSetup(new ProbeController())
                             .addInterceptors(probe)
                             .build();
 
MvcResult result = mvc.perform(get("/probe")).andReturn();
// 여기서 result.getRequest().isAsyncStarted() == true
 
mvc.perform(asyncDispatch(result)).andReturn();

MockMvcRequestBuilders.asyncDispatch()라는 API가 있다는 사실이 디스패치가 두 번이라는 근거다. 테스트에서 두 번째 디스패치를 직접 실행해야 한다는 뜻이다.

출력은 이랬다.

=== 1차: 클라이언트 요청 ===
[preHandle] dispatcherType=REQUEST  새로 만든 UUID=ef9608be-f00d-44ef-b635-5d6c5de07bb6
[controller] 호출됨
asyncStarted = true
 
=== 2차: AsyncContext.dispatch() 로 다시 태움 ===
[preHandle] dispatcherType=ASYNC    새로 만든 UUID=747ae62a-a6c3-47aa-858f-60bd17ca40f9
[afterCompletion] dispatcherType=ASYNC
 
preHandle 총 호출 횟수 = 2

preHandle은 두 번, 컨트롤러는 한 번, afterCompletion은 ASYNC에서만 실행됐다. 앞에서 소스로 읽은 그대로다.

한 가지 한계는 밝혀 둔다. MockMvc는 두 디스패치를 같은 스레드에서 순차 실행한다. 그래서 이 실험이 보여주는 건 디스패치가 두 번 돈다는 사실까지다. 실제 톰캣에서는 재디스패치가 보통 다른 스레드에서 일어나는데, 그건 이 테스트로 증명되지 않는다. 스레드가 바뀌는 것은 뒤의 응답 객체 실험에서 실제 톰캣으로 확인했다.

전체 흐름

spring-boot-starter-web과 webflux를 같이 넣었을 때 뜨는 스택

여기서 한 가지를 짚어야 한다. Mono를 반환한다고 WebFlux 애플리케이션이 되는 게 아니다.

두 스타터가 함께 있으면 Spring Boot는 서블릿 스택으로 뜬다. WebFlux는 WebClient를 쓰려고 넣은 의존성일 뿐이고, 톰캣과 Spring MVC가 요청을 처리한다.

이걸 헷갈리면 문제를 완전히 다른 곳에서 찾게 된다. 나는 "WebFlux니까 reactor 컨텍스트 전파가 깨졌겠지"라고 짐작하다가 시간을 썼는데, 애초에 서블릿 스택이었다.

내가 쓰는 판별 기준은 이렇다.

• 예외 핸들러가 HttpServletRequest를 파라미터로 받는가 → 서블릿
• 설정 클래스가 WebMvcConfigurer인가 WebFluxConfigurer인가
• 인터셉터가 HandlerInterceptor인가 WebFilter인가
• spring.mvc.async.request-timeout 설정이 실제로 적용되는가 → 서블릿 async를 쓰고 있다는 뜻

한 요청 안에서 세 구간이 이어진다는 점을 알고 있어야 한다.

이 전제를 모르고 짠 코드가 깨지는 유형

preHandle이 두 번 돈다는 걸 모르면, 인터셉터에 넣은 코드가 오류 없이 두 번 실행된다. 깨지는 유형은 크게 셋이다.

• 부수효과가 두 번 일어난다 — 이력 저장, 카운터 증가, 외부 호출을 preHandle에 넣으면 중복 실행된다.
• 값이 두 번 만들어진다 — ID 발급, 타임스탬프 기록처럼 매 호출이 새 값을 만드는 코드가 첫 값을 덮어쓴다.
• 인증이 두 번 검사된다 — 대개 무해하지만, 토큰 사용 횟수를 세거나 일회용 nonce를 소비하는 방식이면 두 번째 검사에서 실패한다.

그래서 Spring MVC에서 async를 쓰는 프로젝트의 인터셉터에는 이 방어가 관용적으로 들어간다.

@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
    if (DispatcherType.REQUEST != request.getDispatcherType()) {
        return true;
    }
    // 최초 진입에서만 할 일
    return true;
}

요청 ID가 둘로 나뉜 사례

내가 이 동작을 조사하게 된 계기는 운영 로그였다. 이미지 분석 요청을 모델 서버로 넘기는 API 서버에서, 같은 요청이 남긴 에러 로그 두 줄이 서로 다른 요청 ID를 갖고 있었다.

로그가 두 줄인 이유는 찍는 지점이 두 군데였기 때문이다.

• 외부 호출 공통 sender — 다운스트림 응답이 에러 상태면 응답 자체를 남긴다
• 전역 예외 핸들러 — 그 실패가 예외로 올라오면 다시 남긴다

앞의 것은 reactor 스레드에서, 뒤의 것은 재디스패치된 컨테이너 스레드에서 찍힌다. 그런데 요청 ID를 발급하는 코드가 인터셉터의 preHandle에 이렇게 들어 있었다.

String requestId = sanitizeRequestId(request.getHeader("X-Request-Id"));
MDC.put(REQUEST_ID, requestId != null ? requestId : UUID.randomUUID().toString());

헤더가 없으면 UUID.randomUUID()로 채운다. 그리고 이 코드는 DispatcherType을 보지 않는다. 재디스패치에서 preHandle이 다시 돌면서 새 UUID를 만들어 MDC에 덮어쓴다.

DispatcherType을 보지 않는 건 실수가 아니었다. 2023년 커밋 메시지에 의도가 남아 있었다. afterCompletion에서 감사 로그를 전송하는데, 그 호출이 재디스패치 스레드에서 일어나므로 그 스레드의 MDC도 채워져 있어야 했다. 같은 저장소의 다른 인터셉터 8개는 모두 DispatcherType.REQUEST 가드를 갖고 있었고, 이 하나만 의도적으로 빼 둔 상태였다.

문제는 다시 채운다를 새로 만든다로 구현한 것이었다. 원래 값을 이어받아야 했다.

여기서 인과를 한 번 잘못 짚었던 것도 적어 둔다. 나는 처음에 "스레드가 바뀌어 MDC가 비었고 그래서 새로 만들어졌다"고 생각했다. 그런데 MockMvc는 단일 스레드로 도는데도 UUID가 두 개 나왔다. 위 실험 출력이 그것이다. MDC.put()이 기존 값 유무를 보지 않고 덮어쓰기 때문에, 스레드가 같아도 ID가 달라진다. 스레드 전환은 재실행이 필요해진 이유이지 ID가 달라진 원인이 아니었다.

운영에서 드러난 대가

한 주 에러 로그를 분류하다 이 현상을 만났다. 로그 387건 중 288건이 같은 실패를 두 번 찍은 것이었고, 실제 사건은 243건이었다.

요청 ID로 두 로그를 연결할 수 없으니 다른 방법으로 짝을 맞춰야 했다. 두 로그 집합을 pod와 분 단위로 묶어 개수를 비교했고, 48개 버킷이 전부 일치해서 겨우 1:1 짝임을 확정했다. requestId 한 필드로 GROUP BY 하면 끝날 일이었다.

더 큰 문제는 추적이 끊긴다는 점이다. 공통 sender는 첫 번째 ID를 X-Request-Id 헤더로 모델 서버에 넘기고 있었다. 모델 서버 로그에는 첫 번째 ID가 남는데 우리 에러 로그에는 두 번째 ID가 남는다. 고객 문의를 받고 에러 로그에서 출발하면 모델 서버 로그로 넘어갈 방법이 없다.

고친 방향

두 디스패치가 공유하는 것은 request attribute다. 여기에 담으면 스레드가 바뀌어도 값이 이어진다.

private String resolveRequestId(HttpServletRequest request) {
 
    if (request.getAttribute(REQUEST_ID_ATTRIBUTE) instanceof String cached) {
        return cached;
    }
 
    String requestId = sanitizeRequestId(request.getHeader("X-Request-Id"));
 
    if (requestId == null) {
        requestId = UUID.randomUUID().toString();
    }
 
    request.setAttribute(REQUEST_ID_ATTRIBUTE, requestId);
 
    return requestId;
}

DispatcherType 가드를 넣는 방식은 쓰지 않았다. 그러면 재디스패치 스레드의 MDC가 비어 감사 로그의 요청 ID가 null이 되고, 2023년에 내린 결정을 되돌리는 셈이 된다. 가드가 아니라 값을 기억하는 것이 맞는 해법이었다.

attribute 키를 MDC 키와 분리한 것도 의도가 있다. "requestId"는 흔한 이름이라 다른 라이브러리가 같은 이름의 attribute를 쓸 여지가 있어서, 클래스명을 접두어로 붙였다.

재디스패치에서는 응답 객체가 한 겹 더 감싸진다

요청 ID 문제는 request attribute로 풀렸다. 요청 쪽은 디스패치를 넘어 값이 이어지기 때문이다. 응답에는 그런 수단이 없고, 객체도 그대로 넘어오지 않는다. 재디스패치에서 인터셉터가 받는 응답은 필터가 넘긴 객체가 아니라, Spring이 그 객체를 한 번 더 감싼 래퍼다.

이 절의 실행 결과는 Spring Boot 3.3.0에 내장된 톰캣 10.1.24를 실제 포트로 띄워 얻었다. 같은 구성을 MockMvc로 돌려도 래퍼가 겹치는 순서는 같았다.

응답을 감싸는 위치

아래는 Spring Framework 6.1.8 소스에서 읽은 것이다. 핸들러 어댑터는 디스패치마다 async 요청 객체를 새로 만들고, 그 생성자가 응답을 감싼다.

// RequestMappingHandlerAdapter.invokeHandlerMethod():880
AsyncWebRequest asyncWebRequest = WebAsyncUtils.createAsyncWebRequest(request, response);
 
// StandardServletAsyncWebRequest 생성자:90
super(request, new LifecycleHttpServletResponse(response));
 
// StandardServletAsyncWebRequest.startAsync():158
this.asyncContext = getRequest().startAsync(getRequest(), getResponse());

LifecycleHttpServletResponse는 StandardServletAsyncWebRequest 안에 선언된 private static final 클래스이고 HttpServletResponseWrapper를 상속한다. async 요청이 끝났거나 컨테이너가 오류를 알린 뒤에는 응답 스트림에 쓰지 못하게 막는 역할이다. 응답 스트림을 감싸 수명이 끝난 뒤의 사용을 막는다는 방침은 Spring 이슈 #32340에 적혀 있고, 그 이슈의 마일스톤은 6.1.5다. 소스의 javadoc에는 @since 5.3.33으로 적혀 있다.

158행이 중요하다. startAsync()에 감싼 응답을 넘긴다. 서블릿 명세에서 AsyncContext.dispatch()는 startAsync()에 넘긴 요청과 응답으로 서블릿을 다시 호출한다. 그래서 ASYNC 디스패치의 DispatcherServlet은 필터가 넘긴 응답이 아니라 LifecycleHttpServletResponse를 받는다.

여기에 글 앞부분에서 본 필터 등록 기본값이 겹친다. Filter를 직접 구현한 필터는 REQUEST에만 등록되므로, 재디스패치에서는 필터가 실행되지 않고 응답을 다시 감싸지도 않는다.

지점별로 받는 응답

응답 본문을 복사하는 래퍼로 응답을 감싸는 필터를 두고, 각 지점이 받는 응답의 래퍼 체인을 출력했다. 아래 표는 그 출력이다. ResponseFacade는 톰캣이 넘기는 원본 응답이다.

본문을 쓰는 쪽에 LifecycleHttpServletResponse가 두 겹인 이유는 핸들러 어댑터가 ASYNC 디스패치에서도 880행을 다시 실행하기 때문이다. afterCompletion은 doDispatch()가 받은 응답을 그대로 받으므로 그보다 한 겹 안쪽이다.

같은 실험에서 요청 쪽도 확인했다. 톰캣은 ASYNC 디스패치에서 요청을 ApplicationHttpRequest로 한 번 감싸서 넘겼고, 그 안쪽은 첫 진입과 같은 RequestFacade였다. 첫 진입에서 넣은 attribute는 재디스패치에서 그대로 읽혔다. 요청과 응답 모두 가장 바깥 객체는 디스패치마다 달라질 수 있다. 요청은 attribute로 값을 이어받고, 응답은 래퍼 체인을 안쪽으로 풀어서 찾아야 한다.

재디스패치가 다른 스레드에서 실행되는 것도 여기서 확인됐다. 첫 진입은 http-nio-auto-1-exec-2, 재디스패치는 http-nio-auto-1-exec-3에서 실행됐다.

instanceof 검사가 false가 되는 요청

이 구조에서 실제로 겪은 문제는 감사 로그였다. 응답 본문을 감사 로그에 남기려고 필터에서 응답을 본문 복사 래퍼로 감쌌고, 감사 인터셉터의 afterCompletion이 그 래퍼에서 본문을 꺼냈다. 아래 코드는 그 구조를 실험용으로 다시 쓴 것이고, 클래스 이름은 실험에서 붙인 이름이다.

// 필터
chain.doFilter(request, new BodyCopyResponseWrapper((HttpServletResponse) response));
 
// 인터셉터의 afterCompletion
String body = "";
if (response instanceof BodyCopyResponseWrapper wrapper) {
    body = wrapper.copiedBody();
}

컨트롤러가 Mono를 반환하는 API에서는 afterCompletion이 ASYNC 디스패치에서 실행된다. 그때 받는 응답의 가장 바깥은 LifecycleHttpServletResponse라서 instanceof가 false다. 예외는 나지 않고 본문만 빈 문자열로 기록된다.

요청 종류별 실행 결과는 이랬다.

async가 시작되기 전에 끝난 요청은 REQUEST 디스패치에서 afterCompletion까지 실행되므로 필터가 넘긴 래퍼를 그대로 받는다. 그래서 일부 요청에서는 본문이 정상으로 남는다. 거절된 요청과 예외 핸들러가 처리한 요청의 본문은 기록되고 정상 처리된 요청의 본문만 비어 있어서, 기능이 통째로 동작하지 않는 것처럼 보이지 않았다. 응답 자체는 정상이고 오류 로그도 없어 한동안 알아채지 못했다.

예외를 아무도 처리하지 않아 톰캣의 ERROR 디스패치로 넘어간 경우도 돌려 봤다. ERROR 디스패치의 afterCompletion은 래퍼가 없는 ResponseFacade를 받았다. 필터가 ERROR에 등록돼 있지 않기 때문이다. 이 경우 오류 응답 본문은 복사 래퍼를 거치지 않으므로 어떤 방법으로도 꺼낼 수 없다.

래퍼 체인에서 찾는 방법

instanceof 대신 WebUtils.getNativeResponse()를 쓰면 된다.

BodyCopyResponseWrapper wrapper = WebUtils.getNativeResponse(response, BodyCopyResponseWrapper.class);
String body = (wrapper != null) ? wrapper.copiedBody() : "";

이 메서드는 응답이 원하는 타입이면 그대로 돌려주고, 아니면 ServletResponseWrapper.getResponse()를 따라 안쪽으로 들어가며 찾는다. 끝까지 없으면 null이다.

// WebUtils.getNativeResponse():481
if (requiredType.isInstance(response)) {
    return (T) response;
}
else if (response instanceof ServletResponseWrapper wrapper) {
    return getNativeResponse(wrapper.getResponse(), requiredType);
}

실험에서 이 방법은 위 표의 네 요청 모두에서 래퍼를 찾았고, Mono 반환 요청에서도 mono-body를 꺼냈다. Spring도 같은 방식을 쓴다. ShallowEtagHeaderFilter는 자기가 감싼 ConditionalContentCachingResponseWrapper를 getNativeResponse()로 다시 찾는다. 이 클래스는 ContentCachingResponseWrapper를 상속한다.

같은 프로젝트의 이력 저장 인터셉터는 이 문제를 리플렉션으로 우회하고 있었다. response.getOutputStream()이 돌려주는 LifecycleServletOutputStream에서 delegate 필드를 꺼내 안쪽 스트림에 접근하는 방식이다. 두 방법을 비교하면 이렇다.

표의 ASYNC와 REQUEST 행은 실행으로 확인했다. 첫 행은 소스에서 읽은 것이다. 마지막 행의 리플렉션 쪽은 코드 구조에서 추론한 것이고 실행하지 않았다.

리플렉션 우회는 Spring이 필드 이름을 바꾸면 깨진다. 그리고 한 인터셉터만 고쳐져 있었다는 점이 더 큰 문제였다. 같은 원인에 대한 우회가 이력 저장 인터셉터에만 들어가 있었고, 감사 인터셉터는 instanceof 검사를 그대로 갖고 있었다.

필터를 ASYNC에도 등록한 경우

필터를 REQUEST와 ASYNC 양쪽에 등록하면 instanceof가 다시 true가 된다. 실행해 보니 ASYNC 디스패치에서 필터가 한 번 더 실행됐고, afterCompletion이 받은 체인은 이랬다.

복사 래퍼(2) → LifecycleHttpServletResponse → 복사 래퍼(1) → ResponseFacade

바깥 래퍼에서 mono-body가 꺼내졌다. 다만 한 요청에 복사 래퍼가 둘이 된다. 본문이 바깥 래퍼를 지나 안쪽 래퍼로 내려가므로 같은 본문이 두 번 복사될 것으로 보인다. 안쪽 래퍼의 복사본은 직접 출력해 확인하지 않았다. instanceof를 살리려고 필터 등록을 바꾸는 것보다 getNativeResponse()로 찾는 편이 낫다.

가져갈 판단 기준

내가 이 일에서 남긴 체크리스트는 넷이다.

• 인터셉터에 코드를 넣을 때 "이게 두 번 실행돼도 괜찮은가"를 먼저 묻는다. 컨트롤러가 Mono나 DeferredResult를 반환하는 프로젝트라면 두 번 실행이 기본이다.
• 디스패치를 넘겨야 할 값은 ThreadLocal이 아니라 request attribute에 둔다. 스레드는 바뀌지만 request attribute는 이어진다. 반대로 스레드 안에서만 유효한 값은 MDC에 둔다.
• DispatcherType 가드를 붙이기 전에 "재실행이 왜 필요했는가"를 확인한다. 가드가 다른 기능의 전제를 깨뜨릴 수 있다. 이번 경우 가드는 감사 로그를 깨뜨렸고, 필요한 건 값의 멱등성이었다.
• 필터에서 감싼 응답을 인터셉터에서 꺼낼 때는 instanceof가 아니라 WebUtils.getNativeResponse()로 찾는다. 필터가 감싼 래퍼는 재디스패치에서도 체인 안쪽에 남아 있지만, 가장 바깥에는 Spring의 래퍼가 온다.

이 구조를 피하는 편이 나은 경우

Spring MVC에서 Mono를 반환하는 구성 자체가 나쁜 건 아니다. 외부 호출이 오래 걸릴 때 컨테이너 스레드를 붙잡지 않는 이점이 분명히 있다. 다만 다음 상황이면 다시 생각해볼 만하다.

• 가상 스레드를 이미 켰다면 이점이 크게 줄어든다. 스레드 하나를 쓰는 비용이 작아지므로 블로킹으로 기다려도 손해가 작다. 대신 이중 디스패치라는 복잡도는 그대로 남는다. 가상 스레드 자체는 Virtual Thread와 Project Loom에 정리해 뒀다.
• 인터셉터에 부수효과가 많은 레거시라면 이중 실행 전제를 모든 인터셉터에 다시 검토해야 한다. 하나만 놓쳐도 오류 없이 두 번 실행된다.
• 처음부터 리액티브로 갈 수 있다면 진짜 WebFlux로 가는 편이 낫다. 서블릿 async 재디스패치라는 층이 아예 없어진다.

반대로 이 구성을 유지할 이유도 분명하다. 서블릿 생태계의 필터, 인터셉터, HttpServletRequest 기반 도구를 그대로 쓸 수 있다.

지금 보면

이 문제의 본질은 코드가 틀린 게 아니라 전제가 문서화되지 않은 것이었다. "preHandle은 한 요청에 한 번 돈다"는 암묵적 전제 위에서 짠 코드였고, 그 전제는 Mono를 반환하기 시작한 순간 깨졌다. 그런데 깨진 시점에 아무 신호도 나지 않았다.

기존 테스트도 이 전제를 검증하지 않았다. 요청 ID 관련 테스트가 헤더 채택, UUID 대체, 문자열 정리, MDC 정리까지 검증하고 있었는데 디스패치를 두 번 실행하는 경우가 없었다. 단위 테스트가 실행 횟수 전제를 검증하지 않으면, 프레임워크가 몇 번 부르는지는 테스트 밖의 일이 된다.

로그를 남기는 코드는 잘못돼도 오류가 드러나지 않는다는 것도 배운 점이다. 요청 ID가 달라져도 응답은 정상이고 알람도 안 울린다. 운영 로그를 사람이 직접 분류하다 발견했다. 관측 수단 자체를 관측하는 장치는 따로 두지 않았다는 게 회고 지점이다.

관련 문서

• Filter, Interceptor, AOP — 횡단 관심사를 어느 계층에 둘지 결정하는 기준
• MDC — MDC의 스레드 지역성과 분산 추적 구조
• Virtual Thread와 Project Loom — 가상 스레드가 async 모델의 이점을 어떻게 바꾸는가

참고 자료

• Jakarta Servlet 6.0 Specification — Asynchronous Processing
• Jakarta Servlet API — AsyncContext.dispatch()
• Spring Framework Reference — Asynchronous Requests
• Spring Framework Reference — Handler Interceptors
• Spring Framework 이슈 #32340 — Better protect against concurrent error handling for async requests
• Spring Framework 6.1.8 소스 — DispatcherServlet, HandlerExecutionChain, RequestMappingHandlerAdapter, WebAsyncManager, OncePerRequestFilter, StandardServletAsyncWebRequest, WebUtils, ShallowEtagHeaderFilter