全局记录SpringBoot MVC的请求和响应日志

在线上出现问题需要排查，需要开启整个服务的请求与响应日志，下面简介一下如何开启MVC日志：
注1：本文基于 spring-boot-starter-parent 2.3.4.RELEASE
注2：由于站点一般访问量都比较大，影响性能，生产不建议开启，仅在需要问题排查时，通过actuator接口开启，排查完毕要及时关闭。

---

1、使用logbook组件输出日志

演示代码参考点这里
1.1、添加logbook引用：

<!-- https://github.com/zalando/logbook -->
<dependency>
    <groupId>org.zalando</groupId>
    <artifactId>logbook-spring-boot-starter</artifactId>
    <version>2.3.0</version>
</dependency>

1.2、在application.yml里添加如下配置：

logging:
  level:
    org.zalando.logbook: trace
logbook:
  exclude: # 不记录日志的路径
    - "**.html"
    - "**.htm"
    - "**.js"
    - "**.css"
    - "**.jpg"
    - "**.ico"
    - "/static/**"

1.3、添加如下代码：

@Bean
public HttpLogFormatter httpLogFormatter() {
    // 使用默认的http日志格式
    return new DefaultHttpLogFormatter();
}

OK, 启动项目输出日志如下：

2020-10-21 10:23:55.782 TRACE 19096 --- [nio-8080-exec-3] org.zalando.logbook.Logbook              : Incoming Request: 976f2e27a4f4e536
Remote: 0:0:0:0:0:0:0:1
POST http://localhost:8080/add HTTP/1.1
accept: application/json, text/plain, */*
accept-encoding: gzip, deflate, br
accept-language: zh-CN,zh;q=0.9,en;q=0.8
connection: keep-alive
content-length: 26
content-type: application/json;charset=UTF-8
cookie: JSESSIONID=9ACD6920FCD4B244C2558610862DF8C7;
host: localhost:8080
origin: http://localhost:8080
referer: http://localhost:8080/index.html
sec-fetch-dest: empty
sec-fetch-mode: cors
sec-fetch-site: same-origin
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/86.0.4240.75 Safari/537.36

{"id":123,"name":"beinet"}
2020-10-21 10:23:55.840 TRACE 19096 --- [nio-8080-exec-3] org.zalando.logbook.Logbook              : Outgoing Response: 976f2e27a4f4e536
Duration: 64 ms
HTTP/1.1 200 OK
Connection: keep-alive
Content-Type: application/json
Date: Wed, 21 Oct 2020 02:23:55 GMT
Keep-Alive: timeout=60
Transfer-Encoding: chunked

{"id":123,"name":"Hello, beinet","time":"2020-10-21T10:23:55.829"}

---

2、自定义Filter输出日志

1.1、添加自定义Filter实现代码：

package beinet.cn.web.log;

import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;
import org.springframework.web.util.WebUtils;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.UnsupportedEncodingException;
import java.nio.charset.StandardCharsets;
import java.util.Collection;
import java.util.Enumeration;
import java.util.Objects;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

@Slf4j
@Component
public class ControllerLogFilter extends OncePerRequestFilter {
    static Pattern patternRequest = Pattern.compile("(?i)^/actuator/?|\\.(ico|jpg|png|bmp|txt|xml|html?|js|css)$");

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        if (!logger.isDebugEnabled() || isNotApiRequest(request)) {
            filterChain.doFilter(request, response);
            return;
        }

        long startTime = System.currentTimeMillis();
        if (!(request instanceof ContentCachingRequestWrapper)) {
            // 解决 inputStream 只能读取一次的问题
            request = new ContentCachingRequestWrapper(request);
        }
        if (!(response instanceof ContentCachingResponseWrapper)) {
            // 同样用于解决 响应只能读取一次的问题，注意要在最后调用 responseWrapper.copyBodyToResponse();
            response = new ContentCachingResponseWrapper(response);
        }

        Exception exception = null;
        try {
            filterChain.doFilter(request, response);
        } catch (Exception exp) {
            exception = exp;
            throw exp;
        } finally {
            long latency = System.currentTimeMillis() - startTime;
            doLog(request, response, latency, exception);
            repairResponse(response);
        }
    }

    private boolean isNotApiRequest(HttpServletRequest request) {
        String url = request.getRequestURI(); //request.getRequestURL() 带有域名，所以不用
        Matcher matcher = patternRequest.matcher(url);
        return matcher.find();
    }

    private void doLog(HttpServletRequest request, HttpServletResponse response, long latency, Exception exception) {
        StringBuilder sb = new StringBuilder();
        try {
            getRequestMsg(request, sb);

            sb.append("\n--响应 ")
                    .append(response.getStatus())
                    .append("  耗时 ")
                    .append(latency)
                    .append("ms");

            getResponseMsg(response, sb);

            if (exception != null) {
                sb.append("\n--异常 ")
                        .append(exception.getMessage());
            }
            /* // 直接输出到响应流里
            try (ServletOutputStream stream = response.getOutputStream()) {
                stream.write(sb.toString().getBytes(StandardCharsets.UTF_8));
                stream.flush();
            }
            */

            logger.info(sb.toString());
        } catch (Exception exp) {
            sb.append("\n").append(exp.getMessage());
            logger.error(sb.toString());
        }
    }

    private static void getRequestMsg(HttpServletRequest request, StringBuilder sb) throws IOException {
        String query = request.getQueryString();
        if (!StringUtils.isEmpty(query)) {
            query = "?" + query;
        } else {
            query = "";
        }
        sb.append("\n")
                .append(request.getMethod())
                .append(" ")
                .append(request.getRequestURL())
                .append(query)
                .append("\n--用户IP: ")
                .append(request.getRemoteAddr())
                .append("\n--请求Header:");
        // 读取请求头信息
        Enumeration<String> headerNames = request.getHeaderNames();
        while (headerNames.hasMoreElements()) {
            String header = headerNames.nextElement();
            Enumeration<String> values = request.getHeaders(header);
            while (values.hasMoreElements()) {
                sb.append("\n")
                        .append(header)
                        .append(" : ")
                        .append(values.nextElement()).append("; ");
            }
        }
        // 读取请求体
        String requestBody = readFromStream(request.getInputStream());
        if (!StringUtils.isEmpty(requestBody)) {
            sb.append("\n--请求体:\n")
                    .append(requestBody);
        }
    }

    private static void getResponseMsg(HttpServletResponse response, StringBuilder sb) throws UnsupportedEncodingException {
        sb.append("\n--响应Header: ");
        for (String header : response.getHeaderNames()) {
            Collection<String> values = response.getHeaders(header);//.stream().collect(Collectors.joining("; "));
            for (String value : values) {
                sb.append("\n")
                        .append(header)
                        .append(" : ")
                        .append(value);
            }
        }
        // 读取响应体
        ContentCachingResponseWrapper wrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);
        if (wrapper != null) {
            String responseBody = transferFromByte(wrapper.getContentAsByteArray(), wrapper.getCharacterEncoding());
            if (!StringUtils.isEmpty(responseBody)) {
                sb.append("\n--响应Body:\n")
                        .append(responseBody);
            } else {
                sb.append("\n--无响应Body.");
            }
        }
    }

    private static void repairResponse(HttpServletResponse response) throws IOException {
        ContentCachingResponseWrapper responseWrapper = WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);
        Objects.requireNonNull(responseWrapper).copyBodyToResponse();
    }

    private static String readFromStream(InputStream stream) throws IOException {
        ByteArrayOutputStream result = new ByteArrayOutputStream();
        byte[] buffer = new byte[1024];
        int length;
        while ((length = stream.read(buffer)) != -1) {
            result.write(buffer, 0, length);
        }
        return result.toString(StandardCharsets.UTF_8.name());
        // return new BufferedReader(new InputStreamReader(stream)).lines().collect(Collectors.joining(System.lineSeparator()));
    }

    private static String transferFromByte(byte[] arr, String encoding) throws UnsupportedEncodingException {
        return new String(arr, encoding);
    }
}

OK，启动项目，输出日志参考如下：

GET http://localhost:8080/log?id=1234
--用户IP: 0:0:0:0:0:0:0:1
--请求Header:
host : localhost:8080;
connection : keep-alive;
cache-control : max-age=0;
upgrade-insecure-requests : 1;
user-agent : Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/85.0.4183.121 Safari/537.36 Edg/85.0.564.70;
accept : text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng;q=0.8,application/signed-exchange;v=b3;q=0.9;
    sec-fetch-site : none;
    sec-fetch-mode : navigate;
    sec-fetch-user : ?1;
    sec-fetch-dest : document;
    accept-encoding : gzip, deflate, br;
    accept-language : zh-CN,zh;q=0.9,en;q=0.8,en-GB;q=0.7,en-US;q=0.6,zh-TW;q=0.5,af;q=0.4,mt;q=0.3,cy;q=0.2,fr;q=0.1;
    cookie : JSESSIONID=FA41080F568C632146F7AB80EE342D5F; BD_CK_SAM=1;
--响应 200  耗时 4ms
--响应Header:
    Mike-Trace-Id : nDpT-Hjq5z-t
--响应Body:
    Haha 1234