Stream 과 Logging , Interceptor

Logging 과 Stream

• Interceptor 로 Logging 작업을 해놓고 이에 대해 개선 작업을 진행하고 있었다. 이 과정에서 http message 의 body 도 함께 로그에 기록해 좀 더 자세한 정보를 얻을 수 있게 하려했다.
• 그런데 문제가 생겼다. HTTP message 의 body 를 읽으려면 다음과 같이 stream 을 이용해야 했다.

Stream<String> lines = request.getReader().lines();
        
  lines.forEach((s)-> {
      System.out.println("s = " + s);
          }
  );

문제

Spring 에서 Interceptor 의 preHandle 메서드는 DispatcherServlet 이전에 실행된다. 그러면 먼저 logger 를 찍을 때 HTTP message 의 BODY 를 interceptor 에서 읽게된다. 그러면 이후에 controller 에 들어갔을 때, HTTP Message body 를 읽을 수 없다. Stream 의 특성 상 단 한번만 소비될 수 있기 때문이다.

• Error 메시지를 보면, 이미 해당 요청에 대해 getReader() 메서드가 실행되었다는 로그가 나온다.
• 결국 이 body 를 여러번 읽을 수 있게 해야했다.

ContentCachingRequestWrapper 클래스

@Component
public class HttpRequestWrapperFilter implements Filter {

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        ContentCachingRequestWrapper httpRequest = new ContentCachingRequestWrapper((HttpServletRequest) servletRequest);
        filterChain.doFilter(httpRequest , servletResponse);
    }
}

• 위 문제 ( Body 를 여러번 읽을 수 없다 ) 를 해결하기 위해 contentCachingRequestWrapper 클래스를 사용하였다.

해당 클래스는

1. inputStream 과 reader 를 통해 읽힌 content 를 캐싱한다. 이를 통해 body 정보를 다시 읽는것이 가능하다
2. 유의 할 점은 해당 클래스를 사용해서 정보를 읽으려면, 이미 content 가 캐싱된 상태여야 한다. 만약 캐싱되지 않은 상태 (읽힌 상태가 아님) 이면 getContentAsByteArray() 를 통해 content 를 다시 가져올 수 없다.

Logger 에 적용

• 위의 2번 항목을 고려해서 logger 를 설정해야한다. 일단 고려해야하는 것은 controller 에서 한번 stream 을 이용해 해당 content 가 읽힐것이고 그 이후에 getContentAsByteArray() 를 통해 캐싱된 데이터를 가져올 수 있다.
• 현재 interceptor 단에서 로그를 설정해 놓은 상태이다. 그러면 controller 에서 한번 content 가 읽히면 캐싱이 될 것이고 이 정보를 interceptor 의 afterCompletion 단계에서 가져오면 될 듯하다.

public class LoggerInterceptor implements HandlerInterceptor {

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

        ContentCachingRequestWrapper requestInfo = (ContentCachingRequestWrapper) request;
        String requestBody = requestInfo.getContentAsString();

        if(200 <= response.getStatus() && response.getStatus() < 300){
            log.info("url = {} , method = {} , body = {}" , request.getRequestURL() , request.getMethod() , requestBody);
        }else{
            log.error("url = {} , method = {} , status = {} ,  body = {}" , request.getRequestURL() , request.getMethod() , response.getStatus() , requestBody);
        }
    }
}

• requestBody 에서 getContentAsString() 메서드를 통해 캐시된 정보를 가져온다. 그리고 statusCode 에 따라 나눠서 로그를 작성한다.

StatusCode 에 따라 나눠서 작성한 이유

• 현재 ControllerAdvice 를 이용해서 exception 들을 처리하고 있다.
• 그런데 간과 한 점이 dispatcherServlet 에서 exceptionResolver 는 interceptor 의 afterCompletion 이전에 처리된다. 다시 말하면, afterCompletion 의 exception 매개변수까지 해당 exception 이 전파되지 않는다.