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

Leave a Reply

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