使用 Log4j 的 NDC/MDC 改进日志

1、问题产生

通常软件系统都会由简单到复杂，功能少的，简单的软件系统用用通常的日志输出也就可以解决问题了，可是这种软件系统真正能用的也太少了，实际场景中每每是软件么越作越复杂，越作越臃肿，且不说软件系统设计好坏，总归这是一个软件系统所要经历的，那么在系统中用日志的方式添加追踪点，帮助解决问题就成了比较经常使用的方法。而对于网站系统，一般除了知道这个日志是在哪一个跟踪点产生的，还须要知道是由谁（每每是哪一个用户，哪一个 IP 等）产生的，这时就会想到往日志里塞入这类信息，但并非每段代码都那么容易获取到用户的信息，特别是那些分层比较多，比较内层的方法，将一个对象穿透到应用的各个部分，想一想都有点很差办。那么用户相关的信息每个请求都是有办法获取到的，那有没有办法不侵入系统的内部而实现获取这些信息呢？原来 Log4j 早就为咱们准备好了。

2、了解 NDC/MDC

关于 NDC/MDC 的详细介绍能够看这里：在 Web 应用中增长用户跟踪功能

简而言之：NDC是一种在同一个线程内将信息保存起来，提供日志输出时使用。MDC 与 NDC 相比，信息以 Map 方式保存，支付多个健值对。

使用方式上，NDC 经过在 PatternLayout 增长 %x 获取信息，而 MDC 经过 %X{key} 获取对应 key 的信息。 注意下,MDC 是大写 X，我在后面的试验开始时使用的小写的，结果没法正确输出

3、试着写一个

思路：经过 filter 将 session 中保存的用户信息放入 MDC，经过调整 log4j.properties 输出须要的信息。

//定义 Filter
package net.caiban.pc.erp.filter;

import net.caiban.pc.erp.config.AppConst;
import net.caiban.pc.erp.domain.SessionUser;
//import org.apache.log4j.MDC;  //这里没有选择用 Log4j 的 MDC，而是换成了 slf4j
import org.slf4j.MDC;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;


/**
 * @author mays (mays@caiban.net)
 *
 * created on 2016-5-8
 */
public class Log4jMDCFilter implements Filter {

   @Override
   public void destroy() {
   }

   @Override
   public void doFilter(ServletRequest rq, ServletResponse rp,
         FilterChain chain) throws IOException, ServletException {
      HttpServletRequest request= (HttpServletRequest) rq;
      HttpServletResponse response = (HttpServletResponse) rp;

        try {
            putMDC(request, response); //保存信息
            chain.doFilter(request, response);
        }finally {
            clearMDC(request); //记得 clear 相关信息，不然会致使内存溢出
        }
        return ;
   }

   @Override
   public void init(FilterConfig config) throws ServletException {
   }

    public void putMDC(HttpServletRequest request, HttpServletResponse response){
        MDC.put("remoteAddr", request.getRemoteAddr());
        MDC.put("remoteHost", request.getRemoteHost());
        SessionUser user = (SessionUser) request.getSession().getAttribute(AppConst.SESSION_KEY);
        if(user!=null){
            MDC.put("uid", String.valueOf(user.getUid()));
            MDC.put("cid", String.valueOf(user.getCid()));
            MDC.put("account", user.getAccount());
        }
    }

    public void clearMDC(HttpServletRequest request){
        MDC.clear();
    }
}

log4j 配置

#############default level and appender####################
log4j.rootCategory=info,stdout

###################appender stdout##########################
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.Threshold = debug
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] (%F:%L) - %m %X{uid} %X{remoteAddr}%n

关于的配置：

%X{uid} %X{remoteAddr}

随后随便找个位置打印一句日志，效果以下：

ERROR [http-nio-8080-exec-8] (ApiController.java:193) - log4j test MDC 6 127.0.0.1

大体的方法就这么些了，但实际应用中这么写仍是不够的，下面看下能够作的改进

4、能够继续改进的地方

1. 丰富信息：网站或软件系统应根据本身的须要获取请求中能够被拿到的任何信息，并将其放入 MDC，例如URI,Referer等

2. 能够在 MDC 中将请求的时间截放入，同时能够利用过虑器统计请求耗时，最终将耗时信息提供给日志，以便输出

3. 日志输出应从新组织下，输出日志到合适的位置，而不是像我示例那样直接在 console 中输出

另外有几点要注意：

1. 千万记得 finally 要清除 MDC 中保存的信息

2. 我在示例中未使用 Log4j 的 MDC，而是换成了 slf4j 的 MDC，功能没什么差异，可是 slf4j 能够直接使用 MDC.clear()，而 Log4j 的 MDC 须要一个个 remove 放入的 key。另外 slf4j 只有 MDC，没有 NDC。关于 slf4j MDC 的使用，还能够看下这篇文章（虽然文章排版实在有点乱）：Slf4j MDC 使用和 基于 Logback 的实现分析