Spring Web filter for logging request and response

RequestAndResponseLoggingFilter.java

/*
Copyright 2017 Hidetake Iwata

Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at

    http://www.apache.org/licenses/LICENSE-2.0

Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/

import lombok.extern.slf4j.Slf4j;
import lombok.val;
import org.springframework.http.HttpStatus;
import org.springframework.http.MediaType;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.util.Arrays;
import java.util.Collections;
import java.util.List;
import java.util.stream.Stream;

/**
 * Spring Web filter for logging request and response.
 *
 * @author Hidetake Iwata
 * @see org.springframework.web.filter.AbstractRequestLoggingFilter
 * @see ContentCachingRequestWrapper
 * @see ContentCachingResponseWrapper
 */
@Slf4j
public class RequestAndResponseLoggingFilter extends OncePerRequestFilter {
    private static final List<MediaType> VISIBLE_TYPES = Arrays.asList(
        MediaType.valueOf("text/*"),
        MediaType.APPLICATION_FORM_URLENCODED,
        MediaType.APPLICATION_JSON,
        MediaType.APPLICATION_XML,
        MediaType.valueOf("application/*+json"),
        MediaType.valueOf("application/*+xml"),
        MediaType.MULTIPART_FORM_DATA
    );

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        if (isAsyncDispatch(request)) {
            filterChain.doFilter(request, response);
        } else {
            doFilterWrapped(wrapRequest(request), wrapResponse(response), filterChain);
        }
    }

    protected void doFilterWrapped(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response, FilterChain filterChain) throws ServletException, IOException {
        try {
            beforeRequest(request, response);
            filterChain.doFilter(request, response);
        }
        finally {
            afterRequest(request, response);
            response.copyBodyToResponse();
        }
    }

    protected void beforeRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) {
        if (log.isInfoEnabled()) {
            logRequestHeader(request, request.getRemoteAddr() + "|>");
        }
    }

    protected void afterRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) {
        if (log.isInfoEnabled()) {
            logRequestBody(request, request.getRemoteAddr() + "|>");
            logResponse(response, request.getRemoteAddr() + "|<");
        }
    }

    private static void logRequestHeader(ContentCachingRequestWrapper request, String prefix) {
        val queryString = request.getQueryString();
        if (queryString == null) {
            log.info("{} {} {}", prefix, request.getMethod(), request.getRequestURI());
        } else {
            log.info("{} {} {}?{}", prefix, request.getMethod(), request.getRequestURI(), queryString);
        }
        Collections.list(request.getHeaderNames()).forEach(headerName ->
            Collections.list(request.getHeaders(headerName)).forEach(headerValue ->
                log.info("{} {}: {}", prefix, headerName, headerValue)));
        log.info("{}", prefix);
    }

    private static void logRequestBody(ContentCachingRequestWrapper request, String prefix) {
        val content = request.getContentAsByteArray();
        if (content.length > 0) {
            logContent(content, request.getContentType(), request.getCharacterEncoding(), prefix);
        }
    }

    private static void logResponse(ContentCachingResponseWrapper response, String prefix) {
        val status = response.getStatus();
        log.info("{} {} {}", prefix, status, HttpStatus.valueOf(status).getReasonPhrase());
        response.getHeaderNames().forEach(headerName ->
            response.getHeaders(headerName).forEach(headerValue ->
                log.info("{} {}: {}", prefix, headerName, headerValue)));
        log.info("{}", prefix);
        val content = response.getContentAsByteArray();
        if (content.length > 0) {
            logContent(content, response.getContentType(), response.getCharacterEncoding(), prefix);
        }
    }

    private static void logContent(byte[] content, String contentType, String contentEncoding, String prefix) {
        val mediaType = MediaType.valueOf(contentType);
        val visible = VISIBLE_TYPES.stream().anyMatch(visibleType -> visibleType.includes(mediaType));
        if (visible) {
            try {
                val contentString = new String(content, contentEncoding);
                Stream.of(contentString.split("\r\n|\r|\n")).forEach(line -> log.info("{} {}", prefix, line));
            } catch (UnsupportedEncodingException e) {
                log.info("{} [{} bytes content]", prefix, content.length);
            }
        } else {
            log.info("{} [{} bytes content]", prefix, content.length);
        }
    }

    private static ContentCachingRequestWrapper wrapRequest(HttpServletRequest request) {
        if (request instanceof ContentCachingRequestWrapper) {
            return (ContentCachingRequestWrapper) request;
        } else {
            return new ContentCachingRequestWrapper(request);
        }
    }

    private static ContentCachingResponseWrapper wrapResponse(HttpServletResponse response) {
        if (response instanceof ContentCachingResponseWrapper) {
            return (ContentCachingResponseWrapper) response;
        } else {
            return new ContentCachingResponseWrapper(response);
        }
    }
}

spring.log

2017-11-03 13:33:18.777  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> POST /users?v=1
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> User-Agent: curl/7.54.0
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> Host: localhost:8080
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> Accept: */*
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> Content-Length: 24
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> Content-Type: application/json
2017-11-03 13:33:18.778  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|>
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|> {"id": 1, "name": "Foo"}
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< 200 OK
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< Content-Length: 49
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< Date: Fri, 03 Nov 2017 04:33:18 GMT
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< Content-Type: application/json
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|<
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< {
2017-11-03 13:33:18.784  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|<   "id": 1,
2017-11-03 13:33:18.785  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|<   "name": "Foo",
2017-11-03 13:33:18.785  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|<   "active": true
2017-11-03 13:33:18.785  INFO 17287 --- [tp1860754643-33] RequestAndResponseLoggingFilter  : 0:0:0:0:0:0:0:1|< }

what i need to do if i need to write request/response into a file and with session ID for each request, can you please help me in this? thank you

I am using spring boot Rest Microservices in my project, I need to log request and response with session ID, Date and time .

After I used this code, the log work successfully. However, the http did not get the response in the postman. Do you know the reason?

The reason is you can read the Request or Response body only once and you already did in StubLoggingFilter. So response is not visible in Postman.

Any chance you could specify a license for this code?

Hi!

If I try to log the request body in beforeRequest method, then It does not do anything. Do you know why?

Thanks!

@int128 - Just asking again if it would be possible for you to add some license to this code (I can't reuse it otherwise).

Completely understand if you don't want to - I won't bug you about it again after this :)

Response Headers isn't logged, any suggestions?

@Ramesh1249

public class XXFilter implements Filter {

@Override
public void init(FilterConfig filterConfig) throws ServletException {

}

@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain filterChain) throws IOException, ServletException {
    HttpServletResponse httpServletResponse = (HttpServletResponse) response;

    httpServletResponse.setHeader("RequestId", "1234455"); --> UUID random, you can use.
    filterChain.doFilter(request, response);
}

@Override
public void destroy() {

}

}

any idea why when I return org.springframework.http.ResponseEntity in controller

response invalid?

ref: https://stackoverflow.com/questions/39935190/contentcachingresponsewrapper-produces-empty-response

This filter will cause an issue if the original filter is already a ContentCachingResponseWrapper. It will clear the cached content by invoking copyToResponse, which makes the filter who wraps the response with ContentCachingResponseWrapper loses the cached content in it.

Two solutions to avoid this issue:

1. Always wrap the response with ContentCachingResponseWrapper even if it is already a ContentCachingResponseWrapper.
2. If the original response is ContentCachingResponseWrapper, don't copyToResponse`, read the cached response without clear it.

This filter will cause an issue if the original filter is already a ContentCachingResponseWrapper. It will clear the cached content by invoking copyToResponse, which makes the filter who wraps the response with ContentCachingResponseWrapper loses the cached content in it.

Two solutions to avoid this issue:

1. Always wrap the response with ContentCachingResponseWrapper even if it is already a ContentCachingResponseWrapper.
2. If the original response is ContentCachingResponseWrapper, don't copyToResponse`, read the cached response without clear it.

Could you please share a version of the code with the changes you are talking about?

Since it is using a ContentCachingRequestWrapper, doesn't this only work for POST and application/x-www-form-urlencoded requests?

This approach works fine for requests (with body) and success responses (with body). In case of error (400, 404 and Others), the response body comes blank. Any idea to solve using OncePerRequestFilter?

I followed the same code in my rest api project but I get the following error - "org.springframework.http.InvalidMediaTypeException: Invalid mime type "null": 'mimeType' must not be empty.
I am getting Http 500 error while testing in Postman. Please help me.

Since it is using a ContentCachingRequestWrapper, doesn't this only work for POST and application/x-www-form-urlencoded requests?

yes

I am not getting response headers any idea why

@lavanya2290 check whether u r sending headers; in case u r sending headers kindy shared the code snippet.

@tejas07
can u check in https://github.com/lavanya2290/request-response-log.git

How can I use this filter before the permission evaluator.. I do not find any way. trying since days. Handlers do execute before, bad is they have a limitation which this filter can do. Any ideas?

Fixed the garbled characters probrem on json format.
See this fork https://github.com/LinfinyJapan/RequestAndResponseLoggingFilter

Hi!

If I try to log the request body in beforeRequest method, then It does not do anything. Do you know why?

Thanks!

Becuase @component annotation is missing