Java 和 Spring Web 项目请求日志打印(4种实现)

SpringMVC之DispatcherServlet（一）
Java过滤器—Filter用法简介
 Spring 拦截器和过滤器的区别？

前言

今天，一个同事问道，怎么给我们的 Spring Web 服务打印请求日志？他主要困惑的地方是，我们的服务提供了Restful风格的API，请求方法/请求参数格式多样化，不知道如果处理比较好。

听到这个问题，我一时想起了大学写的几个用例，本想翻一下发给他，发现都是只有代码没有想过描述。算了算了，补一个文档吧，故有此篇。

统一日志打印，一般想到的是用面向切面的方式实现。常见的实现方式有，过滤器 Filter、拦截器 Intercprot、增强 DispatcherServlet、Spring Aop。

对于，过滤器、拦截器、Servlet 执行顺序如下图：

示例项目仓库

过滤器 Filter

Filter译为过滤器。由于 Servlet 规范是开放的，借助于公众与开源社区的力量， Servlet 规范越来越科学，功能也越来越强大。 2000 年， Sun 公司在 Servlet2.3 规范中添加了 Filter 功能，并在 Servlet2.4 中对 Filter 进行了细节上的补充。
当客户端向服务器端发送一个请求时，如果有对应的过滤器进行拦截，过滤器可以改变请求的内容、或者重新设置请求协议的相关信息等，然后再将请求发送给服务器端的Servlet进行处理。当Servlet对客户端做出响应时，过滤器同样可以进行拦截，将响应内容进行修改或者重新设置后，再响应给客户端浏览器。在上述过程中，客户端与服务器端并不需要知道过滤器的存在。

在一个Web应用程序中，可以部署多个过滤器进行拦截，这些过滤器组成了一个过滤器链（设计模式：责任链模式的应用）。过滤器链中的每个过滤器负责特定的操作和任务，客户端的请求在这些过滤器之间传递，直到服务器端的Servlet。具体执行流程如下：

所以，对于请求处理来说，过滤器是一个天然的切面。

@Slf4j
@Component
@WebFilter(filterName = "logFilter", urlPatterns = "/*")
public class LogFilter implements Filter {


    @Override
    public void init(FilterConfig filterConfig) {

    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper((HttpServletRequest) request);
        ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper((HttpServletResponse) response);
        RequestLogInfo requestLogInfo = HttpLoggingUtil.initByHttpServletRequest(requestWrapper);
        chain.doFilter(requestWrapper, responseWrapper);
        HttpLoggingUtil.updateByHttpServletResponse(requestLogInfo, requestWrapper, responseWrapper);
        log.info(JSON.toJSONString(requestLogInfo));
    }

    @Override
    public void destroy() {

    }
}

拦截器 Intercprot

过滤器和拦截器底层实现方式大不相同，过滤器是基于函数回调的，拦截器则是基于Java的反射机制（动态代理）实现的。

过滤器实现的是 javax.servlet.Filter 接口，而这个接口是在 Servlet 规范中定义的，也就是说过滤器 Filter 的使用要依赖于 Tomcat 等容器，导致它只能在 web 程序中使用。而拦截器(Interceptor) 它是一个 Spring 组件，并由 Spring 容器管理，并不依赖 Tomcat 等容器，是可以单独使用的。不仅能应用在 web 程序中，也可以用于Application、Swing 等程序中。

过滤器Filter是在请求进入容器后，但在进入servlet之前进行预处理，请求结束是在servlet处理完以后。拦截器 Interceptor 是在请求进入servlet后，在进入Controller之前进行预处理的，Controller 中渲染了对应的视图之后请求结束。

过滤器几乎可以对所有进入容器的请求起作用，而拦截器只会对Controller中请求或访问static目录下的资源请求起作用。

@Slf4j
@Component
public class LogInterceptor extends HandlerInterceptorAdapter {

    private final ThreadLocal<Long> startTimeThreadLocal = new ThreadLocal<>();
    @Override
    public boolean preHandle(HttpServletRequest request,
                             HttpServletResponse response, Object handler) {
        startTimeThreadLocal.set(System.currentTimeMillis());
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request,
                           HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        super.postHandle(request, response, handler, modelAndView);
        ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);
        RequestLogInfo requestLogInfo = HttpLoggingUtil.initByHttpServletRequest(requestWrapper);
        requestLogInfo.setCosTimeMillis(startTimeThreadLocal.get());
        HttpLoggingUtil.updateByHttpServletResponse(requestLogInfo, requestWrapper, responseWrapper);
        log.info(JSON.toJSONString(requestLogInfo));
    }

    @Override
    public void afterCompletion(HttpServletRequest request,
                                HttpServletResponse response, Object handler, Exception ex) throws Exception {
        super.afterCompletion(request, response, handler, ex);
        startTimeThreadLocal.remove();
    }
}

增强 DispatcherServlet

DispatcherServlet 继承自 HttpServlet ，通过使用 Servlet API 对 HTTP 请求进行响应。其工作大致分为两个部分：一是初始化部分，由 init() 启动，经 initServletBean() ，通过 initWebApplicationContext() 最终调用 DispatcherServlet 的 initStrategies 方法，在该方法里对诸如 handlerMapping，ViewResolver 等进行初始化；另一个是对 HTTP 请求进行响应的部分，作为一个 Servlet，Web 容器会调用其 doGet()，doPost 等方法，经过 FrameworkServlet 的processRequest() 简单处理后会调用 DispatcherServlet 的doService() 方法，该方法会调用 doDispatch()，doDispatch 是实现 MVC 模式的主要部分，流程图如下

所以，利用他的特点，我们可以修饰 DispatcherServlet ，给其增加统一日志打印能力。

@Slf4j
@Component(value = DispatcherServletAutoConfiguration.DEFAULT_DISPATCHER_SERVLET_BEAN_NAME)
public class LoggableDispatcherServlet extends DispatcherServlet {

    @Override
    protected void doDispatch(HttpServletRequest request, HttpServletResponse response) throws Exception {
        ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);
        RequestLogInfo requestLogInfo = HttpLoggingUtil.initByHttpServletRequest(requestWrapper);
        try {
            super.doDispatch(requestWrapper, responseWrapper);
        } finally {
            HttpLoggingUtil.updateByHttpServletResponse(requestLogInfo, requestWrapper, responseWrapper);
            log.info(JSON.toJSONString(requestLogInfo));
        }
    }
}

Spring Aop 切面编程

动态代理的实现，给切点做增强，可以用环绕通知@Around，也可以用前置通知@Before+后置通知@AfterReturning，完成日志打印功能。

@Slf4j
@Aspect
@Component
public class WebLogAspect {

    private final ThreadLocal<RequestLogInfo> requestInfoThreadLocal = new ThreadLocal<>();

    @Pointcut("execution(public * com.eden.springbootwebdemo.controller..*.*(..))")
    public void webLog() {

    }

    @Before(value = "webLog()")
    public void doBefore(JoinPoint point) {
        Long startTime = System.currentTimeMillis();
        ServletRequestAttributes attributes =
                (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        RequestLogInfo requestLogInfo = new RequestLogInfo();
        requestLogInfo.setCosTimeMillis(startTime);
        requestLogInfo.setRemoteAddr(request.getRemoteAddr());
        requestLogInfo.setRequestUri(request.getRequestURL().toString());
        requestLogInfo.setMethod(point.getSignature().getDeclaringTypeName() + "." + point.getSignature().getName());
        requestLogInfo.setRequest(Arrays.toString(point.getArgs()));
        requestInfoThreadLocal.set(requestLogInfo);
    }

    @AfterReturning(value = "webLog()", returning = "ret")
    public void doAferReturning(Object ret) {
        RequestLogInfo requestLogInfo = requestInfoThreadLocal.get();
        requestLogInfo.setCosTimeMillis(System.currentTimeMillis() - requestLogInfo.getCosTimeMillis());
        requestLogInfo.setResponse(ret);
        log.info(JSON.toJSONString(requestLogInfo));
        requestInfoThreadLocal.remove();
    }

}

本文其他工具类

RequestLogInfo

@Setter
@Getter
@ToString
@NoArgsConstructor
@AllArgsConstructor
public class RequestLogInfo {

    /**
     * 请求资源
     */
    private String requestUri;

    /**
     * 调用者地址
     */
    private String remoteAddr;

    /**
     * 请求头
     */
    private Object requestHeaders;

    /**
     * 被调方法
     */
    private String method;

    /**
     * 请求参数
     */
    private Object request;

    /**
     * 响应状态
     */
    private Integer status;

    /**
     * 响应头
     */
    private Object responseHeaders;

    /**
     * 响应数据
     */
    private Object response;

    /**
     * 接口耗时
     */
    private Long cosTimeMillis;

}

HttpLoggingUtil.class

public class HttpLoggingUtil {

    public static RequestLogInfo initByHttpServletRequest(ContentCachingRequestWrapper requestWrapper) {
        RequestLogInfo requestLogInfo = new RequestLogInfo();
        requestLogInfo.setCosTimeMillis(System.currentTimeMillis());
        requestLogInfo.setRequestUri(requestWrapper.getRequestURI());
        requestLogInfo.setRemoteAddr(requestWrapper.getRemoteAddr());
        requestLogInfo.setRequestHeaders(getRequestHeaders(requestWrapper));
        return requestLogInfo;
    }

    public static void updateByHttpServletResponse(RequestLogInfo requestLogInfo, ContentCachingRequestWrapper requestWrapper, ContentCachingResponseWrapper responseWrapper) throws IOException {
        String method = requestWrapper.getMethod();
        requestLogInfo.setMethod(method);
        if (method.equals(RequestMethod.GET.name())) {
            requestLogInfo.setRequest(requestWrapper.getParameterMap());
        } else {
            requestLogInfo.setResponse(new String(requestWrapper.getContentAsByteArray()));
        }
        requestLogInfo.setStatus(responseWrapper.getStatus());
        requestLogInfo.setResponse(new String(responseWrapper.getContentAsByteArray()));
        responseWrapper.copyBodyToResponse();
        requestLogInfo.setResponseHeaders(getResponsetHeaders(responseWrapper));
        requestLogInfo.setCosTimeMillis(System.currentTimeMillis() - requestLogInfo.getCosTimeMillis());
    }

    private static Map<String, Object> getResponsetHeaders(ContentCachingResponseWrapper response) {
        Map<String, Object> headers = new HashMap<>(16);
        Collection<String> headerNames = response.getHeaderNames();
        for (String headerName : headerNames) {
            headers.put(headerName, response.getHeader(headerName));
        }
        return headers;
    }

    private static Map<String, Object> getRequestHeaders(HttpServletRequest request) {
        Map<String, Object> headers = new HashMap<>(16);
        Enumeration<String> headerNames = request.getHeaderNames();
        while (headerNames.hasMoreElements()) {
            String headerName = headerNames.nextElement();
            headers.put(headerName, request.getHeader(headerName));
        }
        return headers;
    }
}