统一请求日志输出2.0

还记得前面我们通过AOP切面类实现的统一请求响应日志输出方案嘛，经过后面interceptor、filter实践发现，未放行的请求日志信息并没有记录，很显然，AOP没有充当第一道防线！本节我们就此功能，升级改造为2.0版本。开干！

实现思路

现在我们已经意识到统一日志记录存在的漏洞，这对生产环境排查问题所造成的困扰是致命的打击。为此我们必须把请求日志记录放在请求发起后的第一个检查卡口。很显然，我们将用filter来实现，直接将request中的信息输出。但这里有一个坑：request.getInputStream()方法获取请求体内容后，流就输出结束，无法再调用第二次。也就是说，如果我们在filter中通过读取流写入请求日志后，在映射到controller方法，由spring web模块进行请求体到@requestBody注解的DTO对象的转换时，会报错，究其原因，罪魁祸首就是request.getInputStream()已经没有内容返回了。

要解决这个问题，spring web模块提供了一个ContentCachingRequestWrapper类，采用了装饰器模式，这里我贴出部分源码：

对原始的HttpServletRequest进行了包装，我们在调用其getInputStream()方法时，其实内部调用的是原始request的相应方法获取输入流，其内部也是对流进行了一层包装，说到底最终操作的还是原始请求的流对象。它的使用场景归结为四个字：先斩后奏，当我们调用一次其getInputStream()方法后，就可以通过调用其getContentAsByteArray()方法得到缓存的内容。同样的问题还是没解决，我们的日志记录场景并不是“先斩后奏”的形式，关于“先斩后奏”形式的请求体日志输出可以参考这篇教程：在SpringBoot中缓存HTTP请求响应体(实现请求响应日志的记录)

现在我们必须换一种实现方式，思路不变，还是使用装饰器模式，只不过在内部，我们不会再对原始request获取的流对象进行装饰，而是基于已经读取的字节数组来新创建一个ByteArrayInputStream类型的流对象，对其装饰。

定义包装器类

按照前面的思路，我们定义如下包装器类：

package com.xiaojuan.boot.common.web.util;

import ...

public class CachedHttpServletRequestWrapper extends HttpServletRequestWrapper {

    private byte[] cachedByteArray;

    @SneakyThrows
    public CachedHttpServletRequestWrapper(HttpServletRequest request) {
        super(request);
        InputStream in = request.getInputStream();
        this.cachedByteArray = StreamUtils.copyToByteArray(in);
    }

    @Override
    public ServletInputStream getInputStream() {
        return new CachedServletInputStream(this.cachedByteArray);
    }

    @Override
    public BufferedReader getReader() {
        ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(this.cachedByteArray);
        return new BufferedReader(new InputStreamReader(byteArrayInputStream));
    }
}

代码说明

这里我们的包装类从HttpServletRequestWrapper继承，重写了必要的getInputStream()和getReader()方法。

在构造器中，我们就进行流的读取和拷贝，并将结果缓存到cachedByteArray中，这样，未来再调用包装器对象的getInputStream()或getReader()方法时，将缓存的内容包装返回即可。

package com.xiaojuan.boot.common.web.util;

import ...

@Slf4j
public class CachedServletInputStream extends ServletInputStream {

    private InputStream cachedInputStream;

    public CachedServletInputStream(byte[] cachedByteArray) {
        this.cachedInputStream = new ByteArrayInputStream(cachedByteArray);
    }

    @Override
    public boolean isFinished() {
        try {
            return cachedInputStream.available() == 0;
        } catch (IOException ex) {
            log.error(ex.getMessage());
        }
        return false;
    }

    @Override
    public boolean isReady() {
        return true;
    }

    @Override
    public void setReadListener(ReadListener readListener) {
        throw new UnsupportedOperationException();
    }

    @Override
    public int read() throws IOException {
        return cachedInputStream.read();
    }
}

代码说明

这里我们采用了委托的设计思想，基于已读取得字节数组的缓存数据来构建一个内部的ByteArrayInputStream对象，在调用流的isFinished()或者read()方法时，实际上委托了给了依赖的对象来完成相同的操作的。

请求日志过滤器

package com.xiaojuan.boot.web.filter;

import ...

@Slf4j
public class RequestLogFilter extends OncePerRequestFilter {

    @Resource
    private ObjectMapper objectMapper;

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        log.info("====================================================================================================");
        log.info("========== {}: {}", request.getMethod(), request.getRequestURL());
        logParams(request);

        CachedHttpServletRequestWrapper requestWrapper = new CachedHttpServletRequestWrapper(request);
        logRequestBody(requestWrapper);

        filterChain.doFilter(requestWrapper, response);
    }

    private void logParams(HttpServletRequest request) {
        ...
    }

    @SneakyThrows
    private void logRequestBody(CachedHttpServletRequestWrapper request) {

        if (StringUtils.equals(request.getContentType(), MediaType.APPLICATION_JSON_VALUE)) {
            log.info("========== body: {}", objectMapper.readTree(request.getInputStream()));
        }
    }
}

代码说明

在所有请求到达后续的filter和interceptor并最终由映射到的controller处理前，先被RequestLogFilter拦截到，进行请求日志的输出，然后放行。在输出请求体内容时，我们对其进行包装，调用了new CachedHttpServletRequestWrapper(request)后，已经进行了request的流读取操作，然后进行了缓存，后续我们再在logRequestBody(request)中操作了包装对象的getInputStream()，其实就是从缓存中获取，并用objectMapper.readTree(inputStream)读取输出到日志，该方法可以去掉请求体中的空格、换行符等，以最紧凑的字符串形式输出。

注意，这里我们在logRequestBody(request)中的逻辑处理，只考虑请求的内容类型为application/json的形式，其他形式的请求体，当然有必要可以另外扩展输出。

不要忘了对其进行配置，这里我们过滤所有的请求地址，假设我们不考虑为我们的spring boot应用提供额外的静态资源服务，否则我们还得排除一些资源请求路径的模式。还要配置filter的执行顺序，确保在basicAuthFilter之前执行。

package com.xiaojuan.boot.web;

import ...

@Configuration
public class WebConfig implements WebMvcConfigurer {

    ...

    @Bean
    public RequestLogFilter requestLogFilter() {
        return new RequestLogFilter();
    }

    @Bean
    public FilterRegistrationBean basicAuthFilterBean(){
        ...
        bean.setOrder(2);
        return bean;
    }

    @Bean
    public FilterRegistrationBean requestLogFilterBean() {
        FilterRegistrationBean bean = new FilterRegistrationBean();
        bean.setFilter(requestLogFilter());
        bean.setName("requestLogFilter");
        bean.addUrlPatterns("/*"); // 这里不考虑spring boot应用提供静态资源访问功能
        bean.setOrder(1);
        return bean;
    }
}

测试

最后我们调整下先前的TestController的post方法，让它接受post请求体内容：

package com.xiaojuan.boot.web.controller;

import ...

@Slf4j
@RestController
public class TestController implements TestAPI {
    ...

    @Override
    public void post(JSONObject obj) {
        log.info("post 入参：{}", obj);
        ...
    }

    ...
}

这里我们还要引入一个json相关的依赖：

dependencies {
    ...
    implementation 'com.alibaba:fastjson:1.2.75'
}

web单元测试：

package com.xiaojuan.boot.web.controller;

import ...

public class TestControllerTest extends WebTestBase {

    ...

    @Test
    public void testPostWithRequestBody() {
        JSONObject data = new JSONObject();
        data.put("username", "zhangsan");
        postObject("/test/post", new TypeReference() {}, data, null);
    }

}

运行单元测试看到控制台的日志输出，ok！

这样，我们的请求日志的输出总算是完善了，不会再丢失了，只不过我们只关心json请求体的日志输出，在现在的方案上扩展其他形式也不难了，可以交给小伙伴们自己完成，大家加油！

参考资料：Spring – Log Incoming Requests