logback新认识(二)：logback之MDC日志跟踪、日志自定义效果

上一篇关于logback的文章说明了logback的主要组成部分，其中包括 appender、 encoder、 rollingPolicy、 triggeringPolicy和 filter。这些基本在项目中都很常用的。接下来我们看一下其他的功能点。包括日志的MDC做日志跟踪以及将日志添加自定义颜色，酷炫的显示效果。另外再大概说一下 pattern中的占位符含义。

MDC实现日志跟踪

MDC在做日志跟踪的时候用的比较多。一个系统提供服务，提供给其他系统来调用，当其他系统调用的时候，入参带上一个唯一的请求标识(requestId)，把这个requestId输出到日志中，这样两个系统直接就会形成一个执行链，用requestId串联起来，当出现错误时，可以在调用方查询对应的请求日志，也可以在服务方查询请求日志。定位问题很方便。输出日志的地方很多，不能每次输出都去get拿取requestId，拼接到日志中，很麻烦，也很容易遗漏。这个时候使用MDC配合logback中的pattern就很简单啦。

**实现思路：**首先请求过来，将requestId放到MDC中，然后在pattern中用表达式从MDC中获取到对应的requestId。

了解MDC

在MDC中提供了静态方法put，如同Map的put方法，进入看源码：

static MDCAdapter mdcAdapter;
public static void put(String key, String val) throws IllegalArgumentException {
    if (key == null) {
        throw new IllegalArgumentException("key parameter cannot be null");
    } else if (mdcAdapter == null) {
        throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
    } else {
        mdcAdapter.put(key, val); //调用成员变量mdcAdapter将键值对存储起来
    }
}

然后就是进入到MDCAdapter类中找对应的put方法（MDCAdapter是一个接口，找到实现类LogbackMDCAdapter）：

final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal();//ThreadLocal
public void put(String key, String val) throws IllegalArgumentException {
    if (key == null) {
        throw new IllegalArgumentException("key cannot be null");
    } else {
        Map<String, String> oldMap = (Map)this.copyOnThreadLocal.get();//先从ThreadLocal取Map
        Integer lastOp = this.getAndSetLastOperation(1);
        if (!this.wasLastOpReadOrNull(lastOp) && oldMap != null) {
            oldMap.put(key, val);//Map存在直接存储
        } else {
            //Map不存在，先创建，再存储
            Map<String, String> newMap = this.duplicateAndInsertNewMap(oldMap);
            newMap.put(key, val);
        }
    }
}

源码很简单，就是通过ThreadLocal来维护一个线程共享的Map，然后将键值对放到Map里面。

MDC存值的内部逻辑已经了解，接下来怎么存进去就不是很难了。可以在请求进入的每个方法的第一行，将请求的requestId放到MDC中，但是这样就有点蠢。切面用一下，很简单。下面是实现代码：

/**
 * @Author: Joker
 * @Date: 2018/12/16
 * @Desc: requestId不放在请求的参数中，放在一个统一的位置：请求头
 */
@Component
@Slf4j
@Aspect
public class RequestIdAspectJHandler {
    
    private static final String REQUEST_ID = "requestId";

    @Pointcut("execution(* com.pingan.haofang.iot.*..*Controller.*(..))")
    public void pointcut() {

    }

    @Around("pointcut()")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable{
        HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
        MDC.put(REQUEST_ID,request.getHeader(REQUEST_ID));//将requestId设置到MDC中
        return joinPoint.proceed();
    }
}

这里使用最简单的写法。代码就不多做解释。

在logback配置文件中利用pattern获取requestId

只是表达式写一下就可以了，也是非常简单的下面直接给示例：

<!-- %X{requestId:-defaultrequestId},':-'表示设置默认值，
当获取requestId为空的时候使用defaultrequestId替代，如果不需要默认值直接写成： %X{requestId}-->
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <pattern>[requestId:%X{requestId:-defaultrequestId}] %d %red([%thread]) %5level - %msg%n
    </pattern>
</encoder>

输出的日志格式如下：

[requestId:123] 2018-12-16 12:12:12.123 [main] INFO - this is log info

自定义颜色

在输出不同级别日志的时候，使用不同颜色来做标记，可以让输出的内容可识别性更高。这里就说一种自定义颜色的方式。

自定义颜色处理类

自定义颜色处理类需要继承ForegroundCompositeConverterBase，并指定泛型为ILoggingEvent，泛型类对象会作为getForegroundColorCode方法的默认参数，这里需要使用iLoggingEvent获取一些日志的内部属性。

/**
 * @Author: Joker
 * @Date: 2018/12/13
 * @Desc:
 */
public class CustomLogColor extends ForegroundCompositeConverterBase<ILoggingEvent> {
    @Override
    protected String getForegroundColorCode(ILoggingEvent iLoggingEvent) {
        Level level = iLoggingEvent.getLevel();
        switch (level.toInt()) {
            case Level.INFO_INT:
                return ANSIConstants.GREEN_FG; //INFO级别为绿色
            case Level.WARN_INT:
                return ANSIConstants.YELLOW_FG;//WARN级别为黄色
            default:
                return ANSIConstants.DEFAULT_FG;//默认颜色
        }
    }
}

logback.xml文件配置

配置很简单，直接定义颜色处理类，然后在pattern中使用即可。代码如下：

<!--自定义颜色处理类名称是：custom-->
<conversionRule conversionWord="custom" converterClass="com.itcrud.logback.demo.color.CustomLogColor"/>

<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <!--  %custom(%5level)，用小括号来界定颜色作用的范围，%custom指定使用的处理类 -->
    <pattern>%blue([requestId:%X{requestId}]) %d %red([%thread]) %custom(%5level) - %msg%n
    </pattern>
</encoder>

当然这里除了颜色自定义，也可以使用logback内置的颜色，上面的pattern中有体现，在输出requestId和thread信息的时候分别使用到了%blue和%red。具体提供了多少中颜色，可以去研究研究，这里不做赘述。

pattern的使用

在上面的两个功能点都反复的说到了pattern，说明它很重要也很基础。输出的日志就靠它来帮忙实现各种格式的排版。关于pattern的内容挺多的，这里不多说，如果想研究复杂的，可以到百度上找，相信会有很多。另外文末提供的参考文档中也是有详细的说明，可以作为对照的参考。（logback官方中文版文档的6.2.2节）

logger标签

最后加一个logger标签的说明，以前在项目中没看到有用过，这次在公司新开的项目中有体现，拿出来说一下。

logback.xml格式如下：

<logger name="com.itcrud.logback.UserService" level="info"/>

UserService格式如下：

public class UserService {
    private Logger log = LoggerFactory.getLogger("com.itcrud.logback.UserService");
    
    public String getUserInfo(Integer id){
        //业务代码
        log.info("请求成功！");
        return "";
    }
}

在UserService代码中获取日志对象Logger，这个时候没有设置日志的级别，那就是默认继承root上指定的日志级别。如果这个时候不想去继承root指定的日志级别，就只能自己去指定。就是使用logger标签，在logback.xml配置文件中指定需要使用的日志级别。(这里单看着可能有点懵，因为涉及到日志父级和继承关系，可以先看一下logback官方中文文档的第一章)

很久以前在开发中经常会用到这种方式创建Logger对象，但是现在基本都是注解式开发很简单。使用lombok，然后在类上加上@Slf4j的注解，就大功告成了。至于日志级别，都是直接继承root指定的。有时候用到一些老的框架有可能还真的需要用到logger标签，这也是没有办法的。作为一个了解，知道logger什么时候用，做什么用的即可。