通過slf4j/log4j的MDC/NDC 實現日志追蹤

     在分布式系統或者較為復雜的系統中，我們希望可以看到一個客戶請求的處理過程所涉及到的所有子系統\模塊的處理日志。

     由於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:

    <!--start  log4jfilter-->
    <filter>
        <filter-name>log4jfilter</filter-name>
        <filter-class>org.fgq.study.log4j.Log4jFilter</filter-class>
        <init-param>
            <param-name>sign</param-name>
            <param-value>000010x</param-value>
        </init-param>
     </filter>
    <filter-mapping>
        <filter-name>log4jfilter</filter-name>
        <url-pattern>/*</url-pattern>
    </filter-mapping>  
    <!--end  log4jfilter-->

 

 

doFilterInternal方法：

    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {

        String eventsign;

        if (request.getHeader("eventsign") == null || request.getHeader("eventsign").length() == 0) {
            eventsign = this.sign + String.valueOf(new Date().getTime()); //計算eventID

            logger.error("set eventid:" + eventsign);
        } else {
            eventsign = request.getHeader("eventsign");//從請求端獲取eventsign
            logger.error("get eventid from request:" + eventsign);

        }

        MDC.put("eventid",  eventsign);
        response.setHeader("eventsign", eventsign);
        filterChain.doFilter(request, response);


    }

 

 

 

 

測試結果：

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