在 Spring Boot 中记录完整的请求体和响应体日志

发表于 分类于 阅读次数： 本文字数： 1.3k 阅读时长 ≈ 5 分钟

完整的请求日志对于 故障排查 和 审计 来说极其重要。通过查看日志，可以检查数据的准确性、参数的传递方式以及服务器返回的数据。

由于 Socket 流不能重读，所以需要一种实现来把读取和写入的数据缓存起来，并且可以多次重复读取缓存的内容。

Spring 提供 2 个可重复读取请求、响应的 Wrapper 工具类：

  • ContentCachingRequestWrapper
  • ContentCachingResponseWrapper

通过类名不难看出，这是典型的装饰者设计模式。它俩的作用就是把读取到的 请求体 和写出的 响应体 都缓存起来，并且提供了访问缓存数据的 API。

创建 RequestLogFilter

创建 RequestLogFilter 继承 HttpFilter，以记录完整的请求和响应日志。

package cn.springdoc.demo.web.filter;

import java.io.IOException;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpFilter;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;

/**
 * 记录请求日志
 */
public class RequestLogFilter extends HttpFilter {

    static final Logger log = LoggerFactory.getLogger(RequestLogFilter.class);

    /**
     *
     */
    private static final long serialVersionUID = 8991118181953196532L;


    @Override
    protected void doFilter(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws IOException, ServletException {

        // Wrapper 封装 Request 和 Response
        ContentCachingRequestWrapper cachingRequest = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper cachingResponse = new ContentCachingResponseWrapper(response);

        // 继续执行请求链
        chain.doFilter(cachingRequest, cachingResponse);

        /**
         * 在请求完成后记录请求、响应日志
         */
        // 请求方法
        String method = request.getMethod();
        // URI
        String uri = request.getRequestURI();
        // 请求体
        byte[] requestContent = cachingRequest.getContentAsByteArray();

        log.info("Request => {} {} {}", method, uri, new String(requestContent));

        // 响应状态
        int status = response.getStatus();
        // 响应体
        byte[] responseContent = cachingResponse.getContentAsByteArray();

        log.info("Response <= {} {}", status, new String(responseContent));

        /**
         * 把缓存的响应数据，响应给客户端
         */
        cachingResponse.copyBodyToResponse();
    }
}

如上，在 doFilter 方法中使用装饰者设计模式，把 HttpServletRequest 和 HttpServletResponse 分别封装为 ContentCachingRequestWrapper 和 ContentCachingResponseWrapper。

继续执行请求链，当从 Request 从读取数据或者是把数据写入到 Response 中时，都会在对应的 Wrapper 中缓存数据。在请求完成时，就可以通过 getContentAsByteArray() 方法从 Wrapper 中读取到缓存的数据，以实现了 “流重读”。

注意，最后调用的 copyBodyToResponse(); 方法很关键，由于往 Response 写入数据时都缓存在 Wrapper 中，所以在最后必须调用此方法把缓存的数据的响应给客户端。

通过这种方式，就可以完完整整地记录到整个请求体和响应体，包括请求头和响应头。

配置 Filter

在 Spring Boot 中有多种方式配置 Filter，本例使用 FilterRegistrationBean Bean 进行注册。

package cn.springdoc.demo.configuration;

import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.Ordered;

import cn.springdoc.demo.web.filter.RequestLogFilter;

@Configuration
public class WebFilterConfiguration {

    @Bean
    public FilterRegistrationBean<RequestLogFilter> requestLogFilter (){
        FilterRegistrationBean<RequestLogFilter> registrationBean = new FilterRegistrationBean<>();
        registrationBean.setFilter(new RequestLogFilter());
        // 拦截 "/api" 开头的请求
        registrationBean.addUrlPatterns("/api/*");
        // 执行顺序最靠前
        registrationBean.setOrder(Ordered.HIGHEST_PRECEDENCE);
        return registrationBean;
    }
}

首先，指定了仅拦截 /api 开头的请求，然后指定 Filter 的执行顺序为最先执行。

建议只拦截业务 API 接口。对于静态文件、文件上传、文件下载等请求来说，把体积较大的请求、响应缓存在内存中可能导致内存溢出，且记录文件内容没有太大意义。

当然，你也可以使用 /* 拦截所有请求，然后在 RequestLogFilter 中进行灵活地判断：

private boolean shouldSkip (HttpServletRequest request) {
    // 跳过文件上传接口
    if (request.getRequestURI().contains("/upload")) {
        return true;
    }
    // 跳过文件下载接口
    if (request.getRequestURI().contains("/download")) {
        return true;
    }
    // 跳过静态资源
    if (request.getRequestURI().contains("/static")) {
        return true;
    }
    return false;
}


@Override
protected void doFilter(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws IOException, ServletException {

    if(shouldSkip(request)) {
        // 不需要记录请求体和响应体
        chain.doFilter(request, response);
    } else {
        // Wrapper 封装 Request 和 Response
        ContentCachingRequestWrapper cachingRequest = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper cachingResponse = new ContentCachingResponseWrapper(response);
        // TODO ...
    }
}

DemoController

创建一个 DemoController 用于测试：

package cn.springdoc.demo.web.controller;

import java.io.IOException;
import java.time.Instant;
import java.util.Map;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.PostMapping;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;


@RestController
@RequestMapping("/api/demo")
public class DemoController {

    static final Logger log = LoggerFactory.getLogger(DemoController.class);

    @PostMapping
    public ResponseEntity<Object> upload (@RequestBody Map<String, Object> payload) throws IOException {

        // 添加服务器当前时间戳后返回
        payload.put("now", Instant.now().toEpochMilli());

        return ResponseEntity.ok(payload);
    }
}

如上，这是一个非常普通的 Controller，它把客户端的 JSON 请求体封装为 Map<String, Object>，然后往这个 Map 中写入服务器的当前时间戳，最后返回这个 Map 给客户端。

测试

启动服务，使用 Postman 对 /api/demo 发起请求，如下：

POST /api/demo HTTP/1.1
Content-Type: application/json
User-Agent: PostmanRuntime/7.29.2
Accept: */*
Cache-Control: no-cache
Postman-Token: ad56c320-1481-441e-ac19-ebc4f32880b6
Host: localhost:8080
Accept-Encoding: gzip, deflate, br
Connection: keep-alive
Content-Length: 60

{"title": "Spring 中文网", "url": "https://springdoc.cn"}

HTTP/1.1 200 OK
Content-Type: application/json;charset=UTF-8
Content-Length: 79
Date: Sat, 30 Dec 2023 04:52:41 GMT
Keep-Alive: timeout=60
Connection: keep-alive

{"title":"Spring 中文网","url":"https://springdoc.cn","now":"1703911961677"}

如你所见，请求和响应都符合预期。再来看看服务端控制台中输出的请求、响应日志：

INFO 16716 --- [nio-8080-exec-3] c.s.demo.web.filter.RequestLogFilter     : Request => POST /api/demo {"title": "Spring 中文网", "url": "https://springdoc.cn"}
INFO 16716 --- [nio-8080-exec-3] c.s.demo.web.filter.RequestLogFilter     : Response <= 200 {"title":"Spring 中文网","url":"https://springdoc.cn","now":"1703911961677"}

一切OK，日志中完完整整地记录了请求体和响应体。

总结

使用 ContentCachingRequestWrapper 和 ContentCachingResponseWrapper 可以完整地记录请求和响应日志，而且对 Controller 来说是透明无感的。弊端也比较明显，这会耗费较多的内存。且因为需要 IO 日志，所以会导致响应时间增加，因此可以考虑异步 IO 日志到 Kafka 或者是其他高性能的日志平台。