在分布式系统或者较为复杂的系统中,我们希望可以看到一个客户请求的处理过程所涉及到的所有子系统\模块的处理日志。
由于slf4j/log4j基本是日志记录的标准组件,所以slf4j/log4j成为了我的重点研究对象。
slf4j/log4j支持MDC,可以实现同一请求的日志追踪功能。
基本思路是:
实现自定义Filter,在接受到http请求时,计算eventID并存储在MDC中。如果涉及分布式多系统,那么向其他子系统发送请求时,需要携带此eventID。
源代码:https://github.com/athinboy/studyjava.git
其中:
response.setHeader("eventsign", eventsign);很有用,返回的response中,将有httpheader:eventsign:000010x1489108079237 log4j日志格式配置为:
log4j.appender.stdout.layout.ConversionPattern=%d %logger-%5p - %X{eventid} - %m%n
在web.xml中配置自定义filter:
1 <!--start log4jfilter--> 2 <filter> 3 <filter-name>log4jfilter</filter-name> 4 <filter-class>org.fgq.study.log4j.Log4jFilter</filter-class> 5 <init-param> 6 <param-name>sign</param-name> 7 <param-value>000010x</param-value> 8 </init-param> 9 </filter> 10 <filter-mapping> 11 <filter-name>log4jfilter</filter-name> 12 <url-pattern>/*</url-pattern> 13 </filter-mapping> 14 <!--end log4jfilter-->
web.xml配置
doFilterInternal方法:
1 protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException { 2 3 String eventsign; 4 5 if (request.getHeader("eventsign") == null || request.getHeader("eventsign").length() == 0) { 6 eventsign = this.sign + String.valueOf(new Date().getTime()); //计算eventID 7 8 logger.error("set eventid:" + eventsign); 9 } else { 10 eventsign = request.getHeader("eventsign");//从请求端获取eventsign 11 logger.error("get eventid from request:" + eventsign); 12 13 } 14 15 MDC.put("eventid", eventsign); 16 response.setHeader("eventsign", eventsign); 17 filterChain.doFilter(request, response); 18 19 20 }
Log4jFilter-doFilterInternal
测试结果:
1、
Request URL:http://localhost:8084/spmvc/index.html
Request Method:GET
Status Code:304 Not Modified
Remote Address:[::1]:8084
Response Headers
Date:Fri, 10 Mar 2017 03:20:01 GMT
ETag:W/"660-1489115626000"
eventsign:000010x1489116001756
服务器端日志:
2017-03-10 11:20:01,756 org.fgq.study.log4j.Log4jFilter.doFilterInternal(Log4jFilter.java:59)ogger-ERROR - - set eventid:000010x1489116001756
2、
Request URL:http://localhost:8084/spmvc/mv/mvc/time?id=1
Request Method:GET
Status Code:200 OK
Remote Address:[::1]:8084
Response Headers
Content-Language:zh-CN
Content-Type:text/html;charset=utf-8
Date:Fri, 10 Mar 2017 03:21:02 GMT
Server:Apache-Coyote/1.1
Transfer-Encoding:chunked
Request Headers
Accept:*/*
Accept-Encoding:gzip, deflate, sdch, br
Accept-Language:zh-CN,zh;q=0.8
Connection:keep-alive
Cookie:eryewrhuewr
eventsign:eventsignOfQequest
服务器端日志:
2017-03-10 11:21:02,378 org.fgq.study.log4j.Log4jFilter.doFilterInternal(Log4jFilter.java:62)ogger-ERROR - - get eventid from request:eventsignOfQequest
2017-03-10 11:21:02,555 org.fgq.study.controller.TimeController.ShowTime(TimeController.java:34)ogger- WARN - 000010xeventsignOfQequest - get eventid:eventsignOfQequest, send request to other sub system ,and with the eventid!
返回内容:the eventsign is : eventsignOfQequest
参考: https://logback.qos.ch/manual/mdc.html