Spring Boot：Logback MDC动态映射上下文信息到日志

在SpringBoot应用中使用Logback记录程序日志非常方便，但是随着日志量越来越大，通过查看或筛选日志定位问题也会变得越来越困难。这里提供一种将日志信息关联应用上下文（用户信息）的方式，可看做是对日志进行分组，以进一步提高查看及筛选日志的效率。

Logback框架提供了MDC(Mapped Diagnostic Context)，可使日志实现对上下文的审计，下面记录将用户信息映射到日志中的过程。

1 创建工具类

创建LogbackConfigurator组件类，用于配置日志中的自定义消息（在当前案例中，此类粒度较细，直接处理用户信息，具体可根据实际情况处理需要的上下文，例如权限等其它相关信息）。类完整代码如下：

@Component
public class LogbackConfigurator {
    /**
     * 向logback日志添加用户信息
     *
     * @param userInfo
     */
    public void setUser(String userInfo) {
        MDC.put("userInfo", String.format("[%s]", userInfo));
    }

    /**
     * 从logback日志移除用户信息
     */
    public void clearUser() {
        MDC.remove("userInfo");
    }
}

2 针对请求设置上下文信息

在之前的文章<<Spring Boot：全局日志拦截处理>>中实现了全局日志拦截处理，本案例中将实现对每一个具体的请求审计上下文信息，所以对之前的全局请求拦截类GlobalRequestInterceptor添加相关MDC审计信息，如下图，类改造后完整代码如下：

/**
 * 全局请求拦截器
 */
@Component
public class GlobalRequestInterceptor extends HandlerInterceptorAdapter {
    private Logger logger = LoggerFactory.getLogger(this.getClass());
    private final LogbackConfigurator logbackConfigurator;
    private final SimpleDateFormat simpleDateFormat = new SimpleDateFormat("HH:mm:ss.SSS");

    public GlobalRequestInterceptor(LogbackConfigurator logbackConfigurator) {
        this.logbackConfigurator = logbackConfigurator;
    }

    /**
     * 请求之前被调用
     *
     * @param request
     * @param response
     * @param handler
     * @return
     * @throws Exception
     */
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        String username;
        Authentication authentication = SecurityContextHolder.getContext().getAuthentication();
        //如果用户已登录，获取登录用户信息
        if (authentication.getPrincipal() != null && authentication.getPrincipal() instanceof User) {
            username = ((User) (authentication.getPrincipal())).getUsername();
        } else {
            username = authentication.getName();
        }
        this.logbackConfigurator.setUser(String.format("%s-%s", username, this.simpleDateFormat.format(new Date())));
        logger.info("=====> Request({}) start, params:{}", request.getRequestURI(), JSONObject.toJSONString(request.getParameterMap()));
        return super.preHandle(request, response, handler);
    }

    /**
     * 请求完成之后，如果需要渲染视图，则此操作在渲染视图之前
     *
     * @param request
     * @param response
     * @param handler
     * @param modelAndView
     * @throws Exception
     */
    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
        logger.info("=====> Request({}) end, response status:{}", request.getRequestURI(), response.getStatus());
        this.logbackConfigurator.clearUser();
        super.postHandle(request, response, handler, modelAndView);
    }
}

由于对GlobalRequestInterceptor的改造添加了LogbackConfigurator组件类，所以对应的WebConfig类添加LogbackConfigurator组件类的注入，调整如下：

WebConfig完整代码如下

@Configuration
public class WebConfig implements WebMvcConfigurer {

    private final GlobalRequestInterceptor globalRequestInterceptor;

    public WebConfig(GlobalRequestInterceptor globalRequestInterceptor) {
        this.globalRequestInterceptor = globalRequestInterceptor;
    }

    /**
     * 添加拦截器
     *
     * @param registry
     */
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(this.globalRequestInterceptor);
    }
}

3 调整Logback日志配置

上面步骤已经成功将用户信息映射到了日志上下文中，再在日志配置中稍作配置即可使用。LogbackConfigurator类中将用户信息的key值设置为userInfo，所以日志配置中(当前调整的是开发环境配置logback-dev.xml)可使用userInfo获取用户信息，如下：

<configuration debug="true">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%yellow([%date{yyyy-MM-dd HH:mm:ss.SSS,GMT+8}]) %highlight([%-5level]) %cyan([%thread])
                %boldMagenta(%X{userInfo}) - %msg [%logger{1}] \(%file:%line\) %n
            </pattern>
        </encoder>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

4 最终效果

完成上面步骤后，重启应用程序，分别发送登录和查询Redis两个请求（可点击 这里 查看这两个请求的源码），日志打印如下图：

在用户未登录时，请求中记录的是匿名用户，登录成功之后执行请求则会记录真实的用户信息。用户信息分为两部分：用户名 和 请求发起时间，以查询Redis请求为例，在和此请求所有关联的日志中都会包含[crane-07:22:24.841]这个信息，可以从请求的粒度方便的查看日志。

5 总结

以上是从请求的粒度对日志进行上下文进行映射审计，也可根据实际情况从其他维度（例如多线程同用户）进行审计，提高日志筛选的便捷性。

参考

[1] 日志布局配置
[2] MDC