Mansur
Mansur

Reputation: 1829

How to log request body before it is processed using CommonsRequestLoggingFilter?

CommonsRequestLoggingFilter is working fine when logging the incoming request bodies. However, it only logs them after the processing is done. So, when I log the response body, it precedes the request body. I would like to know if there's a way to log the request before it is even processed.

Another thing I would like to mention is that CommonsRequestLoggingFilter actually is aware when the request is received, it logs message like Request received at.... However, that log doesn't contain the request body. After the message is processed, it logs almost exact thing with payload in it.

My configuration is the following for the CommonsRequestLoggingFilter. It has nothing special.

@Bean
public CommonsRequestLoggingFilter requestLoggingFilter() {
    CommonsRequestLoggingFilter loggingFilter = new CommonsRequestLoggingFilter();
    loggingFilter.setIncludeClientInfo(true);
    loggingFilter.setIncludeQueryString(true);
    loggingFilter.setIncludePayload(true);
    return loggingFilter;
}

Note. Apparently there's a reason for the behavior mentioned above. It is said that getContentAsByteArray cannot be called until either getInputStream or getReader is called. This method is called inside the logger. I don't know what to do with this. Does it mean there's no way of logging request before?

Upvotes: 2

Views: 7551

Answers (3)

gavenkoa
gavenkoa

Reputation: 48713

IDK how to trigger flushing of request stream. I had to read body after filterChain.doFilter():

public class RequestResponseLogFilter 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);

        try {
            filterChain.doFilter(requestWrapper, responseWrapper);
        } finally {
            // Log request after filter chain completed - so req body stream flushed and non-empty.
            logReq(requestWrapper);

            logRsp(responseWrapper);
        }
    }
}

Upvotes: 0

matthenry87
matthenry87

Reputation: 122

I've been researching this an I've determined that it's probably not best practice to log the request/response bodies.

Starting with Spring Boot 2.0 it's not (and really hasn't officially been) supported.

https://github.com/spring-projects/spring-boot/issues/12953#issuecomment-383830749

Upvotes: 0

user11819144
user11819144

Reputation: 23

You can log both before and after interceptor's execute() method like below.

public class LoggingInterceptor implements ClientHttpRequestInterceptor {

  private final Logger log = LoggerFactory.getLogger(LoggingInterceptor.class);

  @Override
  public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution)
      throws IOException {
    logRequest(request, body);
    ClientHttpResponse response = execution.execute(request, body);
    logResponse(response);
    return response;
  }

  private void logRequest(HttpRequest request, byte[] body) throws IOException {
    if (log.isDebugEnabled()) {
      log.debug("URI         : {}", request.getURI());
      log.debug("Method      : {}", request.getMethod());
      log.debug("Headers     : {}", request.getHeaders());
      log.debug("Request body: {}", new String(body, "UTF-8"));
    }
  }

  private void logResponse(ClientHttpResponse response) throws IOException {
    if (log.isDebugEnabled()) {
      log.debug("Status code  : {}", response.getStatusCode());
      log.debug("Status text  : {}", response.getStatusText());
      log.debug("Headers      : {}", response.getHeaders());
      log.debug("Response body: {}", StreamUtils.copyToString(response.getBody(), Charset.defaultCharset()));
    }
  }
}

Upvotes: 0

Related Questions