Fork me on GitHub

Programming, Internet & more

Log request body with Spring Boot

Recently, one of my spring boot applications was running into a severe internal server error. I’ve tried to debug the issue but had a really hard time because I had no clue what the actual JSON payload of the problematic HTTP request was. The HTTP headers were not much of a help because the issue really was dependent on the quite large JSON body.

To make it even worse, it was not possible to just log the RequestBody in my RestController because spring boot was not even able to deserialize the JSON payload!

To capture the problematic request, I’ve had rather simple requirements: Just log the whole JSON payload in an HTTP request everytime an internal server error occurs.

After some time of searching on the net, I’ve realized that it’s not easy to find a simple and good solution without introducing a ton of external libraries.

Solution – A filter to log the JSON request payload

I’ve written my own solution which is based on the tracing actuator from spring boot. Unfortunately, spring boots tracing filter does not allow to log the body of HTTP requests. Furthermore, the tracing filter will log ALL requests, which is not what I wanted.

My solution is a custom logging filter which will write the body of the request in case of an internal server error to the standard logger. So, it’s up to the logger where to put these data. Additionally, it will only print the request body in case of an error, which will keep the log clean most of the time.

The filter is placed near the very end of the filter chain to make sure all other filters in the chain (which might change/enrich the request) are already passed. It is also worth noting that you cannot just naively read the body of a request. That’s because the body is realized as an InputStream which gets consumed on the first read. Instead, it is necessary to wrap the body and copy the content of the stream while reading. Therefore, it is only possible to access the body content AFTER the actual processing of the request was done.

import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.security.Principal;
import java.util.LinkedHashMap;
import java.util.Map;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.boot.autoconfigure.web.ErrorAttributes;
import org.springframework.core.Ordered;
import org.springframework.http.HttpStatus;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.ServletRequestAttributes;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.WebUtils;

/**
* A filter which logs web requests that lead to an error in the system.
*
*/

@Component
public class LogRequestFilter extends OncePerRequestFilter implements Ordered {

    private final Log logger = LogFactory.getLog(getClass());

    // put filter at the end of all other filters to make sure we are processing after all others
    private int order = Ordered.LOWEST_PRECEDENCE - 8;
    private ErrorAttributes errorAttributes;

    @Override
    public int getOrder() {
        return order;
    }

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
        throws ServletException, IOException {
        ContentCachingRequestWrapper wrappedRequest = new ContentCachingRequestWrapper(request);

        int status = HttpStatus.INTERNAL_SERVER_ERROR.value();

        // pass through filter chain to do the actual request handling
        filterChain.doFilter(wrappedRequest, response);
        status = response.getStatus();

        // only log request if there was an error
        if (status == HttpStatus.INTERNAL_SERVER_ERROR.value()) {
            Map<String, Object> trace = getTrace(wrappedRequest, status);

            // body can only be read after the actual request handling was done!
            getBody(wrappedRequest, trace);
            logTrace(wrappedRequest, trace);
        }
    }

    private void getBody(ContentCachingRequestWrapper request, Map<String, Object> trace) {
        // wrap request to make sure we can read the body of the request (otherwise it will be consumed by the actual
        // request handler)
        ContentCachingRequestWrapper wrapper = WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
        if (wrapper != null) {
            byte[] buf = wrapper.getContentAsByteArray();
            if (buf.length > 0) {
                String payload;
                try {
                    payload = new String(buf, 0, buf.length, wrapper.getCharacterEncoding());
                }
                catch (UnsupportedEncodingException ex) {
                    payload = "[unknown]";
                }

                trace.put("body", payload);
            }
        }
    }

    private void logTrace(HttpServletRequest request, Map<String, Object> trace) {
        Object method = trace.get("method");
        Object path = trace.get("path");
        Object statusCode = trace.get("statusCode");

        logger.info(String.format("%s %s produced an error status code '%s'. Trace: '%s'", method, path, statusCode,
        trace));
    }

    protected Map<String, Object> getTrace(HttpServletRequest request, int status) {
        Throwable exception = (Throwable) request.getAttribute("javax.servlet.error.exception");

        Principal principal = request.getUserPrincipal();

        Map<String, Object> trace = new LinkedHashMap<String, Object>();
        trace.put("method", request.getMethod());
        trace.put("path", request.getRequestURI());
        trace.put("principal", principal.getName());
        trace.put("query", request.getQueryString());
        trace.put("statusCode", status);

        if (exception != null && this.errorAttributes != null) {
            trace.put("error", this.errorAttributes
                .getErrorAttributes(new ServletRequestAttributes(request), true));
        }

        return trace;
    }

}
Category: spring-boot

12 Comments

  • Arne Stone says:

    Kudos Christian ! Thank you very much for posting this article. I have wasted this whole day looking for a obvious spring boot property /method to do just this, unfortunately like you know, there isn’t an easy ready to use property.

    Thanks once again!!

  • Milan says:

    Very good article. Solved my problem of logging incoming request.

  • Shashikanth Channagiri says:

    Thank you really, this helped

  • Reza says:

    How should add this to the filter chain?

  • tibor.szalai.work@gmail.com says:

    Thank you for your post. Do you know any solution for log the body before doFilter? Thank you

    • Yes. Try implement your wrapper instead of ContentCachingRequestWrapper – I didn’t check it out in the source code, but there is something wrong with this wrapper.
      For example:
      public class RequestWrapper extends HttpServletRequestWrapper {

      private byte[] body;

      public RequestWrapper(HttpServletRequest request) {
      super(request);
      try {
      body = IOUtils.toByteArray(request.getInputStream());
      } catch (IOException ex) {
      body = new byte[0];
      }
      }

      @Override
      public ServletInputStream getInputStream() throws IOException {
      return new ServletInputStream() {
      @Override
      public boolean isFinished() {
      return false;
      }

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

      @Override
      public void setReadListener(ReadListener readListener) {

      }

      ByteArrayInputStream bais = new ByteArrayInputStream(body);

      @Override
      public int read() throws IOException {
      return bais.read();
      }

      };
      }

      }

  • Gurunath Solanki says:

    This is the best and the only solution that worked for me. Keep it up !!
    Works like charm !!
    I customized above mentioned code to log both request and response body for each request.

  • granadacoder says:

    If I use your code “as is”, it works fine.

    If I comment out
    if (status == HttpStatus.INTERNAL_SERVER_ERROR.value()) {

    (where you check status = 500)

    I get an error.

    Can you help?

  • granadacoder says:

    I figured it out:

    You may want to put a null check around the principal

    if (null != principal) {
    trace.put(“principal”, principal.getName());
    }

    My principal was null.

  • Swastik says:

    Hi,
    I was trying to read the request body before submitting. In this process after reading the request body, controller giving error “Required request body is missing”.
    How to achieve this kind of requirement.
    Appreciate your help on the same.

    Thanks
    Swastik

  • Aos Enkimaru says:

    Nice! I allowed my self to copy paste it.
    Needed only one small change:
    line 111: .getErrorAttributes(new ServletWebRequest(request), true));
    and the relevant imports:
    import org.springframework.boot.web.servlet.error.ErrorAttributes;
    import org.springframework.web.context.request.ServletWebRequest;

    This is relevant for

  • Chris says:

    Nice Blog you have here! You should keep the good work up 🙂

1 Trackback

Leave a Reply

Your email address will not be published. Required fields are marked *