Spring Boot에서 HTTP Request & Response Logging 하기

 

개요

기 작성된 코드를 보다가 Interceptor 부분에서 getInputStream()을 통해 데이터를 읽어들인 코드를 발견했다.

 

Interceptor에서 Request를 읽어들여 Map 객체에 저장한뒤 Controller에서 이를 꺼내서 사용하는 방식인 셈이다. 이 방식은 Request Context가 Map 객체에 들어있기 때문에 키를 유추할 수 없을 뿐더러 접근성이 떨어진다고 판단하여 Dto를 활용한 리팩터링 방식을 적용하려 시도했다.

 

그러나 문제가 있었다. Interceptor에서 한번 getInputStream()을 통해서 읽어들인 데이터는 다시 사용할 수 없는 현상이었다. 쉽게 말하면 Interceptor에서 읽었으니 Controller에서는 Dto에 Request 데이터 매핑이 일어나지 않는 상황이라는 점이다.

 

이를 해결할 수 있는 방법을 찾기 위해 조사를 한 결과 크게 3가지 방식을 찾을 수 있었다.

1. Interceptor에 적용하기
2. Filter에서 처리하기
   1. OncePerRequestFilter 로 처리하기
   2. CommonRequestLoggingFilter 사용하기

Request Life Cycle

 

 

Interceptor 에서 처리하기

이 방식은 HandlerInterceptor 인터페이스를 상속받아 처리하는 방식이다. HandlerInterceptor는 3개의 메소드를 구현해야한다.

 

호출되는 시점은 다음과 같다.

• preHandle() : 핸들러가 실행되기 이전
• postHandle() : 핸들러가 실행된 이후
• afterCompletion() : 요청이 모두 완료된 이후

호출되는 메서드의 시점으로 보면 preHandle() 에다가 Request Logging 코드를 삽입하면 적당할 듯 싶다.

결론

비즈니스 로직 수행 전에 Http Request Body에 대해 Logging을 하라면 preHandel()을 사용해야한다. 그러나

preHandle() 메서드에서 Request의 getInputStream()으로 Request 데이터를 읽어버리면 개요에서 언급한 문제가 일어난다.

 

즉, afterCompletion()에서 Request Body를 읽을 수 밖에 없다.

 

이 방식은 우선적으로 고려할 수 있는 부분은 아닌 듯 싶다.

 

Filter에서 처리하기

OncePerRequestFilter로 처리하기

이 방식은 DispatcherServlet 앞 단에 위치한 Filter를 활용한 방식이다. Filter는 Spring Context 밖에 위치하며 대개 공통적으로 처리해야될 부분들에 대해서 Filter를 활용한다고 한다.(CORS, XSS, LOG, 기타)

 

Filter를 활용한 Request 처리 방식은 “OncePerRequestFilter”를 상속받아 사용하는 방법이었다.

OncPerRequestFilter는 한 요청에 대해 한번만 실행하는 필터이다.

import org.springframework.web.filter.OncePerRequestFilter;

@Slf4j
public class LogFilter extends OncePerRequestFilter {

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

        ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);

        // ObjectMapper 생성
        ObjectMapper mapper = new ObjectMapper();

        try {

            // Request Logging
            log.info("[REQUEST-URL] : {}", request.getRequestURL());

            Map<String, String> headerMap = new HashMap<>();
            request.getHeaderNames().asIterator().forEachRemaining(
                headerName -> headerMap.put(headerName, request.getHeader(headerName))
            );

            // JSON 문자열 변환
            log.info("[REQUEST-HEADER] : {}", mapper.writeValueAsString(headerMap));
            log.info("[REQUEST-CONTENT]: {}",
                new String(requestWrapper.getContentAsByteArray(), StandardCharsets.UTF_8));

            filterChain.doFilter(requestWrapper, responseWrapper);

        } finally {
            log.info("response: {}",
                new String(responseWrapper.getContentAsByteArray(), StandardCharsets.UTF_8));
            responseWrapper.copyBodyToResponse();
        }

    }
}

 

위와 같이 Filter를 등록하고 나면 Bean에도 설정이 필요하다고 한다.

package com.practic.demo.config;

import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class WebConfig {

    @Bean
    public FilterRegistrationBean<LogFilter> logFilter() {
        FilterRegistrationBean<LogFilter> filterRegistrationBean = new FilterRegistrationBean<LogFilter>();
        filterRegistrationBean.setFilter(new LogFilter());
        filterRegistrationBean.setOrder(1);
        filterRegistrationBean.addUrlPatterns("/*");
        return filterRegistrationBean;

    }
}

 

이 방식은 선택하지 않았다. 

 

getInputStream()으로 한 번 읽은 데이터를 재사용하기 위해서는 ContentCaching*Wrapper 를 사용해야한다. 그러나 이를 사용하려면 어디선가 Request Data를 한 번 읽는 과정이 필요한데 Filter에서는 위 설정만으로는 그것이 불가능하다는 점 때문이다.

 

위와 같은 코드를 통해 Request Data를 로깅하려면 아래 라인이 실행된 이후에 로그를 찍어야한다.

filterChain.doFilter(requestWrapper, responseWrapper);

 

그러나 그렇게 하면 비즈니스 로직이 종료된 이후에 Request Logging이 남게된다. 이 문제를 해결하기 위해서는 커스텀된 클래스가 필요한데 매번 프로젝트에 로깅 하나 추가하자고 그런 복잡한 일을 해야하는건가라는 생각에 선택하지 않았다.

 

CommonRequestLoggingFilter 처리하기

이 방식은 Spring에서 Request Logging에 필요한 Filter를 이미 구현해놨으니 이를 가져다 적용만 하면 되는 듯 선택하기로 한 방식이다.

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.filter.CommonsRequestLoggingFilter;

@Configuration
public class RequestLoggingFilter {

    @Bean
    public CommonsRequestLoggingFilter commonsRequestLoggingFilter() {
        CommonsRequestLoggingFilter filter = new CommonsRequestLoggingFilter();
        filter.setIncludeClientInfo(true);
        filter.setIncludeQueryString(true); // 쿼리스트링
        filter.setIncludeHeaders(true); // 필요할 때 true
        filter.setIncludePayload(true);  // 페이로드
        filter.setMaxPayloadLength(10000); // 최대 body 길이
        filter.setAfterMessagePrefix("REQUEST DATA : ");
        return filter;
    }
}

위와 같은 코드를 적용한 뒤 application.yml에 해당 옵션을 추가해주자

logging:
    org:
      springframework:
        web:
          filter: DEBUG

 

 

첨부된 이미지는 SpringBoot 테스트 용으로 만든 프로젝트에 CommonsRequetLoggingFilter를 적용한 결과이다. 

 

앞서 언급한 방식에서의 문제점과 같은 현상이 나타나지만 생각보다 이 방식이 간결하고 공수를 많이 들일 필요가 없기에 Logging 적용 시 이 방식을 우선적으로 고려해야겠다.

 

참고하기

ContentCachingRequestWrapper ?

getInputStream()은 1번만 읽을 수 있으니 이미 캐싱 기능이 만들어져 있는 ContentCachingRequestWrapper 클래스를 사용하라는 글들을 많이 읽었다. 그러나 이 방법을 사용해도 원하는 결과를 얻을 수 없었는데 이유는 다음과 같다.

캐시된 요청 내용을 바이트 배열로 반환합니다. 반환되는 배열은 콘텐츠 캐시 제한보다 클 수 없다. 
참고 : 이 메서드에서 반환되는 바이트 배열은 호출되는 시점에 읽혀진 내용의 양을 반영합니다. 

 

즉 어디선가 한 번 읽혀야된다. "@RequestBody" 를 쓴다면 Filter와 DispatcherSevlet 다음 단계인 듯 싶다. (HandlerArgumentResolver <-> HttpMessageConverter)

 

그렇다면 왜 Http Request Body를 getInputStream()으로 읽고 한 번 밖에 못 읽나? 의도가 뭔가 ?

• 이 부분에 대한 답은 찾지 못했다..

 

마치며

SpringBoot에 대한 개발 방식이 익숙하지 않은 상황이기에 이것저것 조사하다보면 “사소한 것 떄문에 이렇게 번잡한 일을 해야한다고?”라는 생각 때문에 간편한 뭔가가 있지 않을까가 계속 생각난다.

 

각 방식에도 그만한 장단점이 있기 마련이겠지만 일단 실용성 위주로 가보는게 좋지 않을까 싶다.