你好,我是看山。
一个系统上线,肯定会或多或少的存在异常情况。为了更快更好的排雷,记录请求参数和响应结果是非常必要的。所以,Nginx 和 Tomcat 之类的 web 服务器,都提供了访问日志,可以帮助我们记录一些请求信息。
本文是在我们的应用中,定义一个Filter来实现记录请求参数和响应结果的功能。
有一定经验的都知道,如果我们在Filter中读取了HttpServletRequest或者HttpServletResponse的流,就没有办法再次读取了,这样就会造成请求异常。所以,我们需要借助 Spring 提供的ContentCachingRequestWrapper和ContentCachingRequestWrapper实现数据流的重复读取。
定义 Filter
通常来说,我们自定义的Filter是实现Filter接口,然后写一些逻辑,但是既然是在 Spring 中,那就借助 Spring 的一些特性。在我们的实现中,要继承OncePerRequestFilter实现我们的自定义实现。
从类名上推断,OncePerRequestFilter是每次请求只执行一次,但是,难道Filter在一次请求中还会执行多次吗?Spring 官方也是给出定义这个类的原因:
Filter base class that aims to guarantee a single execution per request dispatch, on any servlet container. It provides a doFilterInternal(javax.servlet.http.HttpServletRequest, javax.servlet.http.HttpServletResponse, javax.servlet.FilterChain) method with HttpServletRequest and HttpServletResponse arguments.
As of Servlet 3.0, a filter may be invoked as part of a REQUEST or ASYNC dispatches that occur in separate threads. A filter can be configured in web.xml whether it should be involved in async dispatches. However, in some cases servlet containers assume different default configuration. Therefore sub-classes can override the method shouldNotFilterAsyncDispatch() to declare statically if they should indeed be invoked, once, during both types of dispatches in order to provide thread initialization, logging, security, and so on. This mechanism complements and does not replace the need to configure a filter in web.xml with dispatcher types.
Subclasses may use isAsyncDispatch(HttpServletRequest) to determine when a filter is invoked as part of an async dispatch, and use isAsyncStarted(HttpServletRequest) to determine when the request has been placed in async mode and therefore the current dispatch won’t be the last one for the given request.
Yet another dispatch type that also occurs in its own thread is ERROR. Subclasses can override shouldNotFilterErrorDispatch() if they wish to declare statically if they should be invoked once during error dispatches.
也就是说,Spring 是为了兼容不同的 Web 容器,所以定义了只会执行一次的OncePerRequestFilter。
接下来开始定义我们的Filter类:
public class AccessLogFilter extends OncePerRequestFilter { //... 这里有一些必要的属性 @Override protected void doFilterInternal(final HttpServletRequest request, final HttpServletResponse response, final FilterChain filterChain) throws ServletException, IOException { // 如果是被排除的 uri,不记录 access_log if (matchExclude(request.getRequestURI())) { filterChain.doFilter(request, response); return; } final String requestMethod = request.getMethod(); final boolean shouldWrapMethod = StringUtils.equalsIgnoreCase(requestMethod, HttpMethod.PUT.name()) || StringUtils.equalsIgnoreCase(requestMethod, HttpMethod.POST.name()); final boolean isFirstRequest = !isAsyncDispatch(request); final boolean shouldWrapRequest = isFirstRequest && !(request instanceof ContentCachingRequestWrapper) && shouldWrapMethod; final HttpServletRequest requestToUse = shouldWrapRequest ? new ContentCachingRequestWrapper(request) : request; final boolean shouldWrapResponse = !(response instanceof ContentCachingResponseWrapper) && shouldWrapMethod; final HttpServletResponse responseToUse = shouldWrapResponse ? new ContentCachingResponseWrapper(response) : response; final long startTime = System.currentTimeMillis(); Throwable t = null; try { filterChain.doFilter(requestToUse, responseToUse); } catch (Exception e) { t = e; throw e; } finally { doSaveAccessLog(requestToUse, responseToUse, System.currentTimeMillis() - startTime, t); } } // ... 这里是一些必要的方法
这段代码就是整个逻辑的核心所在,其他的内容从源码中找到。
分析
这个代码中,整体的逻辑没有特别复杂的地方,只需要注意几个关键点就可以了。
默认的HttpServletRequest和HttpServletResponse中的流被读取一次之后,再次读取会失败,所以要使用ContentCachingRequestWrapper和ContentCachingResponseWrapper进行包装,实现重复读取。
既然我们可以自定义Filter,那我们依赖的组件中也可能会自定义Filter,更有可能已经对请求和响应对象进行过封装,所以,一定要先进行一步判断。也就是request instanceof ContentCachingRequestWrapper和response instanceof ContentCachingResponseWrapper。
只要注意了这两点,剩下的都是这个逻辑的细化实现。
运行
接下来我们就运行一遍,看看结果。先定义几种不同的请求:普通 get 请求、普通 post 请求、上传文件、下载文件,这四个接口几乎可以覆盖绝大部分场景。(因为都是比较简单的写法,源码就不赘述了,可以从文末的源码中找到)
先启动项目,然后借助 IDEA 的 http 请求工具:
###普通 get 请求 GET http://localhost:8080/index/get?name=howard ###普通 post 请求 POST http://localhost:8080/index/post Content-Type: application/json {"name":"howard"} ###上传文件 POST http://localhost:8080/index/upload Content-Type: multipart/form-data; boundary=WebAppBoundary --WebAppBoundary Content-Disposition: form-data; name="file"; filename="history.txt" Content-Type: multipart/form-data </Users/liuxh/history.txt --WebAppBoundary-- ###下载文件 GET http://localhost:8080/index/download
再看看打印的日志:
2021-04-29 19:44:57.495 INFO 83448 --- [nio-8080-exec-1] c.h.d.s.filter.AccessLogFilter : time=44ms,ip=127.0.0.1,uri=/index/get,headers=[host:localhost:8080,connection:Keep-Alive,user-agent:Apache-HttpClient/4.5.12 (Java/11.0.7),accept-encoding:gzip,deflate],status=200,requestContentType=null,responseContentType=text/plain;charset=UTF-8,params=name=howard,request=,response= 2021-04-29 19:44:57.551 INFO 83448 --- [nio-8080-exec-2] c.h.d.s.filter.AccessLogFilter : time=36ms,ip=127.0.0.1,uri=/index/post,headers=[content-type:application/json,content-length:17,host:localhost:8080,connection:Keep-Alive,user-agent:Apache-HttpClient/4.5.12 (Java/11.0.7),accept-encoding:gzip,deflate],status=200,requestContentType=application/json,responseContentType=application/json,params=,request={"name":"howard"},response={"name":"howard","timestamp":"1619696697540"} 2021-04-29 19:44:57.585 INFO 83448 --- [nio-8080-exec-3] c.h.d.s.filter.AccessLogFilter : time=20ms,ip=127.0.0.1,uri=/index/upload,headers=[content-type:multipart/form-data; boundary=WebAppBoundary,content-length:232,host:localhost:8080,connection:Keep-Alive,user-agent:Apache-HttpClient/4.5.12 (Java/11.0.7),accept-encoding:gzip,deflate],status=200,requestContentType=multipart/form-data; boundary=WebAppBoundary,responseContentType=application/json,params=,request=,response={"contentLength":"0","contentType":"multipart/form-data"} 2021-04-29 19:44:57.626 INFO 83448 --- [nio-8080-exec-4] c.h.d.s.filter.AccessLogFilter : time=27ms,ip=127.0.0.1,uri=/index/download,headers=[host:localhost:8080,connection:Keep-Alive,user-agent:Apache-HttpClient/4.5.12 (Java/11.0.7),accept-encoding:gzip,deflate],status=200,requestContentType=null,responseContentType=application/octet-stream;charset=utf-8,params=,request=,response=
文末总结
自定义Filter是比较简单的,只要能够注意几个关键点就可以了。不过后续还有扩展的空间,比如:
定义排除的请求 uri,可以借助AntPathMatcher实现 ant 风格的定义
将请求日志单独存放,可以借助 logback 或者 log4j2 等框架的的日志配置实现,这样能更加方便的查找日志
与调用链技术结合,在请求日志中增加调用链的 TraceId 等,可以快速定位待查询的请求日志
源码
附上源码:https://github.com/howardliu-cn/effective-spring/tree/main/spring-filter
推荐阅读
SpringBoot 实战:一招实现结果的优雅响应
SpringBoot 实战:如何优雅的处理异常
SpringBoot 实战:通过 BeanPostProcessor 动态注入 ID 生成器
SpringBoot 实战:自定义 Filter 优雅获取请求参数和响应结果