How to track http request responses for Spring MVC

Certain business requirements require tracking access to our http service, that is, logging the requests and responses. The basic logging dimension contains request parameters (path query parameters, request body), request path (uri), request method (method), request headers (headers), and response status, response headers, and even contains sensitive response bodies, etc. Today summarizes several methods, you can choose as needed.

How request tracking is implemented

Gateway

Many gateway facilities have httptrace capabilities that help us centrally log request traffic. orange, Kong, Apache Apisix, and other Nginx-based gateways have this capability, and even Nginx itself provides the ability to log httptrace logs.

The advantage is that httptrace logs can be managed centrally, free of development; the disadvantage is the high technical requirements and the need for supporting distribution, storage and query facilities.

Spring Boot Actuator

In Spring Boot, simple tracking is actually provided. You just need to integrate.

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>

enable /actuator/httptrace：

management:
  endpoints:
    web:
      exposure:
        include: 'httptrace'

You can get the most recent Http request information through http://server:port/actuator/httptrace

However, in the latest versions it may be necessary to explicitly declare how this trace information is stored, i.e. by implementing the HttpTraceRepository interface and injecting Spring IoC.

For example in memory and limited to the last 100 entries (not recommended for production use).

@Bean
public HttpTraceRepository httpTraceRepository(){
    return new InMemoryHttpTraceRepository();
}

The trace log is presented in json format.

There are not many dimensions recorded, but of course you can try if it is enough.

The advantage is that it is simple to integrate and virtually eliminates development; the disadvantage is that there are few dimensions to record and a facility needs to be built to buffer the consumption of this log information.

CommonsRequestLoggingFilter

The Spring Web module also provides a filter CommonsRequestLoggingFilter that logs the details of the request. It is also relatively simple to configure.

@Bean
CommonsRequestLoggingFilter  loggingFilter(){
    CommonsRequestLoggingFilter loggingFilter = new CommonsRequestLoggingFilter();
    // Logging Client IP Information
    loggingFilter.setIncludeClientInfo(true);
    // Record request header
    loggingFilter.setIncludeHeaders(true);
    // If the request header is logged, you can specify which records are logged and which are not
    // loggingFilter.setHeaderPredicate();
    // Log the request body, especially the body parameter of the POST request
    loggingFilter.setIncludePayload(true);
    // Size limit of request body Default 50
    loggingFilter.setMaxPayloadLength(10000);
    //Record query parameters in the request path 
    loggingFilter.setIncludeQueryString(true);
    return loggingFilter;
}

And the debug logging for CommonsRequestLoggingFilter must be turned on.

logging:
  level:
    org:
      springframework:
        web:
          filter:
            CommonsRequestLoggingFilter: debug

A request outputs the log twice, once before the first pass through the filter; and once after completing the filter chain.

Here is one more sentence can actually be converted to output json format.

The advantages are flexible configuration and comprehensive dimensionality of request tracking, while the disadvantage is that only requests but not responses are logged.

ResponseBodyAdvice

The Spring Boot unified return body can actually be logged, so you need to implement it yourself. This is based on the CommonsRequestLoggingFilter method of parsing requests. The response body can also be obtained, but the response header and state are not clear because the life cycle is not clear, so it is not clear whether it is appropriate to obtain here, but it is an idea.

/**
 * @author felord.cn
 * @since 1.0.8.RELEASE
 */
@Slf4j
@RestControllerAdvice(basePackages = {"cn.felord.logging"})
public class RestBodyAdvice implements ResponseBodyAdvice<Object> {
    private static final int DEFAULT_MAX_PAYLOAD_LENGTH = 10000;
    public static final String REQUEST_MESSAGE_PREFIX = "Request [";
    public static final String REQUEST_MESSAGE_SUFFIX = "]";
    private ObjectMapper objectMapper = new ObjectMapper();

    @Override
    public boolean supports(MethodParameter returnType, Class<? extends HttpMessageConverter<?>> converterType) {
        return true;
    }

    @SneakyThrows
    @Override
    public Object beforeBodyWrite(Object body,
                                  MethodParameter returnType,
                                  MediaType selectedContentType,
                                  Class<? extends HttpMessageConverter<?>> selectedConverterType,
                                  ServerHttpRequest request,
                                  ServerHttpResponse response) {

        ServletServerHttpRequest servletServerHttpRequest = (ServletServerHttpRequest) request;

        log.debug(createRequestMessage(servletServerHttpRequest.getServletRequest(), REQUEST_MESSAGE_PREFIX, REQUEST_MESSAGE_SUFFIX));
        Rest<Object> objectRest;
        if (body == null) {
            objectRest = RestBody.okData(Collections.emptyMap());
        } else if (Rest.class.isAssignableFrom(body.getClass())) {
            objectRest = (Rest<Object>) body;
        }
        else if (checkPrimitive(body)) {
            return RestBody.okData(Collections.singletonMap("result", body));
        }else {
            objectRest = RestBody.okData(body);
        }
        log.debug("Response Body ["+ objectMapper.writeValueAsString(objectRest) +"]");
        return objectRest;
    }


    private boolean checkPrimitive(Object body) {
        Class<?> clazz = body.getClass();
        return clazz.isPrimitive()
                || clazz.isArray()
                || Collection.class.isAssignableFrom(clazz)
                || body instanceof Number
                || body instanceof Boolean
                || body instanceof Character
                || body instanceof String;
    }


    protected String createRequestMessage(HttpServletRequest request, String prefix, String suffix) {
        StringBuilder msg = new StringBuilder();
        msg.append(prefix);
        msg.append(request.getMethod()).append(" ");
        msg.append(request.getRequestURI());


        String queryString = request.getQueryString();
        if (queryString != null) {
            msg.append('?').append(queryString);
        }


        String client = request.getRemoteAddr();
        if (StringUtils.hasLength(client)) {
            msg.append(", client=").append(client);
        }
        HttpSession session = request.getSession(false);
        if (session != null) {
            msg.append(", session=").append(session.getId());
        }
        String user = request.getRemoteUser();
        if (user != null) {
            msg.append(", user=").append(user);
        }

        HttpHeaders headers = new ServletServerHttpRequest(request).getHeaders();
        msg.append(", headers=").append(headers);

        String payload = getMessagePayload(request);
        if (payload != null) {
            msg.append(", payload=").append(payload);
        }

        msg.append(suffix);
        return msg.toString();
    }

    protected String getMessagePayload(HttpServletRequest request) {
        ContentCachingRequestWrapper wrapper =
                WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
        if (wrapper != null) {
            byte[] buf = wrapper.getContentAsByteArray();
            if (buf.length > 0) {
                int length = Math.min(buf.length, DEFAULT_MAX_PAYLOAD_LENGTH);
                try {
                    return new String(buf, 0, length, wrapper.getCharacterEncoding());
                } catch (UnsupportedEncodingException ex) {
                    return "[unknown]";
                }
            }
        }
        return null;
    }
}

Don’t forget to configure the logging level of ResponseBodyAdvice to be DEBUG.

logstash-logback-encoder

This is logstash’s logback encoder that structures the output of httptrace as json.

<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>6.6</version>
</dependency>

Add a ConsoleAppender as LogstashEncoder in the logback configuration

<configuration>
    <appender name="jsonConsoleAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
    </appender>
    <root level=" INFO">
        <appender-ref ref="jsonConsoleAppender"/>
    </root>
</configuration>

Then implement a Filter for parsing as well:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;

/**
 * @author felord.cn
 * @since 1.0.8.RELEASE
 */
@Order(1)
@Component
public class MDCFilter implements Filter {

    private final Logger LOGGER = LoggerFactory.getLogger(MDCFilter.class);
    private final String X_REQUEST_ID = "X-Request-ID";

    @Override
    public void doFilter(ServletRequest request,
                         ServletResponse response,
                         FilterChain chain) throws IOException, ServletException {
        HttpServletRequest req = (HttpServletRequest) request;
        HttpServletResponse res = (HttpServletResponse) response;
        try {
            addXRequestId(req);
            LOGGER.info("path: {}, method: {}, query {}",
                    req.getRequestURI(), req.getMethod(), req.getQueryString());
            res.setHeader(X_REQUEST_ID, MDC.get(X_REQUEST_ID));
            chain.doFilter(request, response);
        } finally {
            LOGGER.info("statusCode {}, path: {}, method: {}, query {}",
                    res.getStatus(), req.getRequestURI(), req.getMethod(), req.getQueryString());
            MDC.clear();
        }
    }

    private void addXRequestId(HttpServletRequest request) {
        String xRequestId = request.getHeader(X_REQUEST_ID);
        if (xRequestId == null) {
            MDC.put(X_REQUEST_ID, UUID.randomUUID().toString());
        } else {
            MDC.put(X_REQUEST_ID, xRequestId);
        }
    }

}

The parsing approach here could actually be a bit more refined.

Not only can the interface request log be recorded, but it can also be structured as json.

{"@timestamp":"2021-08-10T23:48:51.322+08:00","@version":"1","message":"statusCode 200, path: /log/get, method: GET, query foo=xxx&bar=ooo","logger_name":"cn.felord.logging.MDCFilter","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"X-Request-ID":"7c0db56c-b1f2-4d85-ad9a-7ead67660f96"}

Summary

Today introduced a number of records tracking interface request response method, relatively simple, if your project to do a large may need to use the link tracking.

Reference https://my.oschina.net/10000000000/blog/5182314

Table of Contents