Spring에서 request와 response를 JSON format 으로 한번에 로깅하기

 REST API 웹 서버를 개발할 때 모든 Request와 Response를(Header와 Body 전부!) 하나의 JSON Object formate에 로깅하고 싶을 때가 있다. 이번 포스팅에서는 HttpServletRequestWrapper을 활용한 Request body를 처리기법으로 로깅하는 법에 대해 다루겠다. (How to log whole request and response at once?)

 얼핏 생각하면 Request 및 Response를 logging 할 때 aspect를 활용해서 로깅하면 될 것 같다. 그러나 이건 좋은 방법이 아니다. 이유는 크게 두가지인데..

1. Request와 Response를 한번에 로깅할 수 없다.

2. Request의 Stream은 중복해서 읽을 수 없다.

 먼저 첫번째 방법은 딱히 설명이 필요 없을 정도의 간단한 이유이다. 나는 "logger.info()" 를 한번만 써서 로깅을 하고 싶은데 aspect를 쓰면 도저히 방법이 서지 않는다. 이를 극복하기 위해 Custom Filter를 구현하여 거기서 logging 했다. FilterChain.doFilter(); 이후 로깅하면 되기 때문이다.

 한편, Filter에서 로깅처리를 해도 한 번 읽으면 소멸되는 두번째 문제점을 극복할 수 없다. Controller로 Request body가 전달되기 전 로깅을 위해 한번 읽었으므로, Controller에서는 비어있는 Request body를 받게 되는 것이다. (자세한 것은 여기를 참고)

 그러므로 How to log whole request and response at once? 에 대한 답변은...

 CustomFilter를 구현하여 거기서 한큐에 처리하고, Request body는 적절히 복사하여 둘 중 하나로 로깅하고, 나머지 하나는 컨트롤러가 받을 수 있도록 처리하는 것이다. 그럼 이제 예제를 살펴보자. 예제 환경은 Spring Boot 2.1.3 RELEASE, JAVA 11.0.2 이다.

package com.blog.preamtree.filter;

import com.blog.preamtree.component.RequestWrapper;
import com.blog.preamtree.component.ResponseWrapper;
import com.blog.preamtree.util.LoggingUtil;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.filter.OncePerRequestFilter;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Map;

// gradle 의존성 추가하기: compile group:'net.logstash.logback', name:'logstash-logback-encoder', version:'5.1'
import static net.logstash.logback.argument.StructuredArguments.value;

public class LoggingFilter extends OncePerRequestFilter {

    private final Logger logger = LoggerFactory.getLogger(LoggingFilter.class);

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

        final HttpServletRequest request = new RequestWrapper(req);
        final HttpServletResponse response = new ResponseWrapper(res);

        Map<String, Object> requestMap = LoggingUtil.makeLoggingRequestMap(request);

        filterChain.doFilter(request, response);

        Map<String, Object> responseMap = LoggingUtil.makeLoggingResponseMap(response);

        logger.info("", value("req", requestMap), value("res", responseMap));
        ((ResponseWrapper) response).copyBodyToResponse();
    }
}

 CustomFilter는 이런식으로 처리하면 되겠다. RequestWrapper와 ResponseWrapper는 잠시 후에 다룰 것이다. LoggingUtil은 내가 직접 구현한건데 아직 설명을 안했다. 소스코드를 보자.

package com.blog.preamtree.util;

import com.blog.preamtree.component.RequestWrapper;
import com.blog.preamtree.component.ResponseWrapper;
import com.blog.preamtree.exception.PreamtreeException;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Collection;
import java.util.Enumeration;
import java.util.HashMap;
import java.util.Map;

public class LoggingUtil {
    public static Map<String, Object> makeLoggingRequestMap(final HttpServletRequest request) {
        // request info
        Map<String, Object> requestMap = new HashMap<>();
        requestMap.put("url", request.getRequestURL().toString());
        requestMap.put("queryString", request.getQueryString());
        requestMap.put("method", request.getMethod());
        requestMap.put("remoteAddr", request.getRemoteAddr());
        requestMap.put("remoteHost", request.getRemoteHost());
        requestMap.put("remotePort", request.getRemotePort());
        requestMap.put("remoteUser", request.getRemoteUser());
        requestMap.put("encoding", request.getCharacterEncoding());

        // request header
        Map<String, Object> requestHeaderMap = new HashMap<>();
        Enumeration<String> requestHeaderNameList = request.getHeaderNames();
        while(requestHeaderNameList.hasMoreElements()) {
            String headerName = requestHeaderNameList.nextElement();
            requestHeaderMap.put(headerName, request.getHeader(headerName));
        }
        requestMap.put("header", requestHeaderMap);

        // request Body
        try {
            // 이부분 주목!!
            Object requestBody = ((RequestWrapper) request).convertToObject();
            requestMap.put("body", requestBody);
        } catch (IOException iex) {
            throw new PreamtreeException();
        }

        return requestMap;
    }

    public static Map<String, Object> makeLoggingResponseMap(final HttpServletResponse response) throws IOException {
        // response info
        Map<String, Object> responseMap = new HashMap<>();
        responseMap.put("status", response.getStatus());

        // response header
        Map<String, Object> responseHeaderMap = new HashMap<>();
        Collection<String> responseHeaderNameList = response.getHeaderNames();
        responseHeaderNameList.forEach(v -> responseHeaderMap.put(v, response.getHeader(v)));
        responseMap.put("header", responseHeaderMap);

        // response body
        try {
            // 이부분 주목!!
            Object responseBody = ((ResponseWrapper) response).convertToObject();
            responseMap.put("body", responseBody);
        } catch (IOException ioe) {
            throw new PreamtreeException();
        }

        return responseMap;
    }
}

Request와 Response 객체에서 필요한 내용을 뽑아 HashMap에 넣는 모습이다. 이제 I/O Stream의 한계(?)인 "두번 이상 읽기"를 해결하기 Stream의 내용을 복사해서 처리하는 법을 알아보자. 위 소스코드의 40번째 줄을 잘 째려보면 RequestWrapper라는 친구가 보일 것이다.

package com.blog.preamtree.component;

import com.blog.preamtree.exception.PreamtreeException;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.springframework.util.StreamUtils;

import javax.servlet.ReadListener;
import javax.servlet.ServletInputStream;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import java.io.ByteArrayInputStream;
import java.io.IOException;

public class RequestWrapper extends HttpServletRequestWrapper {

    private ObjectMapper objectMapper;

    private byte[] httpRequestBodyByteArray;
    private ByteArrayInputStream bis;

    public RequestWrapper(HttpServletRequest request) {
        super(request);
        this.objectMapper = new ObjectMapper();

        try {
            this.httpRequestBodyByteArray = StreamUtils.copyToByteArray(request.getInputStream());
            this.bis = new ByteArrayInputStream(httpRequestBodyByteArray);
        } catch (IOException e) {
            throw new PreamtreeException();
        }

    }

    @Override
    public ServletInputStream getInputStream() {
        return new ServletInputStream() {
            @Override
            public boolean isFinished() {
                return bis.available() == 0;
            }

            @Override
            public boolean isReady() {
                return true;
            }

            @Override
            public void setReadListener(ReadListener readListener) {
                return;
            }

            @Override
            public int read() {
                return bis.read();
            }
        };
    }

    public Object convertToObject() throws IOException {
        if(httpRequestBodyByteArray.length == 0) return null; // body가 비어있더라도 잘 처리하도록..
        return objectMapper.readValue(httpRequestBodyByteArray, Object.class);
    }
}

 HttpServletRequestWrapper 라는 class를 상속하여 구현했는데.. HttpServletRequestWrapper의 JavaDoc에는 이렇게 쓰여있다.

Provides a convenient implementation of the HttpServletRequest interface that can be subclassed by developers wishing to adapt the request to a Servlet.

This class implements the Wrapper or Decorator pattern. Methods default to calling through to the wrapped request object.

 한마디로 지금 같은 상황에(request, response stream를 조작할 때) 쓰라는 거다. 나는 inputStream 관련 메소드를 override했고 이 객체의 생성자에서 stream을 복사하는 처리를 하고 있다. ResponseWrapper의 경우 딱히 Stream 이슈가 없어서 비슷하게 개발했는데 예제만 보면 될 것 같다.

package com.blog.preamtree.component;

import com.fasterxml.jackson.databind.ObjectMapper;
import org.springframework.web.util.ContentCachingResponseWrapper;

import javax.servlet.http.HttpServletResponse;
import java.io.IOException;

public class ResponseWrapper extends ContentCachingResponseWrapper {
    private ObjectMapper objectMapper;

    public ResponseWrapper(HttpServletResponse response) {
        super(response);
        this.objectMapper = new ObjectMapper();
    }

    public Object convertToObject() throws IOException {
        return objectMapper.readValue(getContentAsByteArray(), Object.class);
    }
}

 이렇게 하면 Request와 Response를 JSON Format으로 한번에 로깅할 수 있다. 다만 이 구현 방식에는 단점이 있는데..

Content-Type: application/json만 가능하다.

 application/x-www-form-urlencoded와 같은 것도 처리하고 싶다면 앞서 소개한 RequestWrapper를 더 상세하게 구현해야 한다. 자세한 것은 설명이 잘 되어있는 링크를 첨부해서 대신한다.

-끝-