TIL) springboot http requestBody/ResponseBody 찍기

로그백 설정을 하다가, http requestBody와 responseBody가 찍히면 좋을것 같다고 생각해서 찍으려고 했다. 

 

 @preHandle에서 URL이나 Method 로깅하는 식으로 하면 되겠다 하고 HandlerInterceptor를 상속받아 오버라이딩 해서 request 객체의 메소드를 봤지만..!

 

갈곳 잃은 커서

header와 url 그리고 getMethod 등등이 존재하지만 중요한 requestBody객체가 없어 구글링을 해봤다. 

ContentCachingRequestWrapper 을 사용하면 된다! 라는 답을 받고 찾아봤다.

 

 

ContentCachingRequestWrapper 이란?

 

스프링에서는 기본적으로 RequestPacade / ResponsePacade라는 요청을 통해 request/response 서블릿 요청을 처리하는데,  이 Pacade의 요청 그대로는 개발자가 못읽고 RequestBody를 찍으려면, HttpServletRequestWrapper 를 이용해 래핑해야한다고 한다.

친절한 스프링은 이미 래핑된 클래스인 ContentCachingRequestWrapper 가 있으니 사용하면 된다고 한다.

 

그럼 RequestPacade/ResponsePacade이 뭐길래 servlet 요청들을 이렇게 번거롭게 사용하는지에 대해 궁금증이 생겼다. 

 

 

RequestPacade/ResponsePacade이란? 

 

일단 RequestPacade는 HttpServeletRequest의 구현체인걸 찾았다. ResponsePascade 도 마찬가지로 HttpServeletResponse의 구현체다. HttpServelet을 상속받아 이용한 구현체 클래스인걸 알았다. 

이제 이 구현체가 어떻게 동작하는지, 순서는 아래와 같다고 한다. 

 

ResponsePascade 진행 순서

 

1) dispatcherServlet에서 Controller를 호출한다.
2) ResponseEntity의 body의 응답 데이터를 꺼내, 메세지 컨버터가 데이터 스트림으로 변환한다.

• json을 사용할 경우 jackson 라이브러리를 사용하게 될텐데 jackson 라이브러리의 MappingJackson2HttpMessageConverter 클래스는 AbstractGenericHttpMessageConverter를 상속하고 writeInternal() 메서드를 재정의하여(템플릿 메서드 패턴) 객체를 json 포맷으로 직렬화합니다.

4) ResponseFacade 객체 내부의 버퍼(OutputBuffer)에 데이터를 저장한다. 

• ResponseFacade의 OutputBuffer에 접근하여야 body로 응답하는 데이터를 로깅할 수 있는데, 여기에 대한 접근이 불가능합니다.

라고 하는데, 여기서 왜 접근이 불가능 해서 이렇게 힘들게 만들까? 라는 생각에 찾아봤다. 

 

HttpServlet요청을 한번밖에 읽지 못하는 이유

 

HttpServletRequest의 InputStream은 한 번만 읽을 수 있는 이유는 HTTP 프로토콜의 특성 때문이라고 한다. 

InputStream은 선형적인 데이터 흐름을 가지며, 데이터를 읽으면 읽은 위치가 이동하며,

InputStream에서 데이터를 읽게 되면 해당 데이터는 버퍼에서 소비되고, 다시 읽기 위해서는 InputStream을 초기화하고 데이터를 다시 요청해야 한다고 한다. 

 

 

그러면 이제 이유를 알았으니, 방법을 찾아봤다. 

@Component
public class CustomServletWrappingFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                    HttpServletResponse response, FilterChain chain)
            throws ServletException, IOException {

        ContentCachingRequestWrapper wrappingRequest = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper wrappingResponse = new ContentCachingResponseWrapper(response);

        chain.doFilter(wrappingRequest, wrappingResponse);

        wrappingResponse.copyBodyToResponse();
    }
}

 

방법은 의외로 간단했다. 

do.filter로 wrappingRequest와 Response를 저장했다. 그리고  wrappingResponse.copyBodyToResponse()로 실제 response body에다가 값을 넣어주었다. 

하지만 handler가 아닌 filter class를 통해 wrapping class를 재정의한다! 그 이유에 대해서 찾아봤다.

 

 

HandlerInterceptor가 아닌 Filter에서 래핑클래스를 정의해야하는 이유 

 

DispatcherServlet에서 Interceptor를 핸들링하는데,  Interceptor 내에서 wrapper를 만들어서 넘겨주게되면 Interceptor 내에서 사용된 request 객체가 데이터 바인딩 작업을 하러 갈때는 call by value에 따라 이미 사라져서 없어진다.

따라서 DispatcherServlet으로 가기 전인 Servlet Filter에서부터 wrapper 클래스로 전환해주어야 정상동작하게 된다고 한다!  (단, Request 객체 내에서 URL 방식으로 넘어온 parameter들은 별도로 보관하고 처리)

 

쉽게 말하면 필터 는 서블릿에서 제공하는 기능이며, 인터셉터 는 스프링에서 제공하는 기능이라 필터단에서 처리해야한다.

 

@Slf4j
@Component
@RequiredArgsConstructor
public class RequestLoggingInterceptor extends HandlerInterceptorAdapter {

    private final ObjectMapper objectMapper;

     @Override
    public void afterCompletion(
            HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)
            throws Exception {

        final ContentCachingRequestWrapper cachingRequest = (ContentCachingRequestWrapper) request;
        final ContentCachingResponseWrapper cachingResponse = (ContentCachingResponseWrapper) response;

		//post요청 일시 로깅 처리
        if (request.getMethod().equals(HttpMethod.POST)) {

            log.info(
                    "RequestBody : {} / ResponseBody : {}",
                    objectMapper.readTree(cachingRequest.getContentAsByteArray()),
                    objectMapper.readTree(cachingResponse.getContentAsByteArray())
            );
        }
    }
}

 

afterCompletion을 써서 preHandle/postHandle처럼 분기 때만 실행되는 코드가 아닌,

요청에 대해서 반드시 수행되도록 했다.  

 

이렇게 처리하면, POST 요청일때 정상적으로 RequestBody, ResponseBody를 찍을 수 있다! 

 

 

 

참고자료

 

https://meetup.nhncloud.com/posts/44

https://alkhwa-113.tistory.com/entry/TIL-Requset-Wrapping-ContentCachingRequestWrapper-RequestBodyAdviceAdapter-HeaderBody-%EC%9D%98-%EC%B0%A8%EC%9D%B4%EC%99%80-%EC%84%B1%EB%8A%A5%EC%9D%B4%EC%8A%88

https://dlsrb6342.github.io/2019/07/02/Spring-Content-Logging/

https://alkhwa-113.tistory.com/entry/TIL-Requset-Wrapping-ContentCachingRequestWrapper-RequestBodyAdviceAdapter-HeaderBody-%EC%9D%98-%EC%B0%A8%EC%9D%B4%EC%99%80-%EC%84%B1%EB%8A%A5%EC%9D%B4%EC%8A%88