从零搭建开发脚手架 使用MDC实现日志链路跟踪

前言

在微服务环境中，我们经常使用Skywalking、CAT等去实现整体请求链路的追踪，但是这个整体运维成本高，架构复杂，我们来使用MDC通过Log来实现一个轻量级的会话事务跟踪功能。

原理

MDC org.sl4j.MDC其实内部就是ThreadLocal，MDC提供了put/get/clear等几个核心接口，用于操作ThreadLocal中的数据；ThreadLocal中的K-V，可以在logback.xml中声明，最终将会打印在日志中。

// java代码
MDC.put("userId","laker");  

// logback.xml
%X{userId}

例如：

<property name="pattern" value="%d{HH:mm:ss.SSS} [%thread] %-5level [%X{userId}] %logger{20} - %msg%n"/>

实现

整体流程如下：

• 用户登录系统，我们日志中记录userId:laker。
• 用户发起请求，一个请求中可能实际产生多个http请求，这里可以前端生成一个requestId
• 在返回体中，返回requestId。
• 研发运维人员，可以根据 userId和requestId去日志中捞请求链路。

过滤器

@Order(value = Ordered.HIGHEST_PRECEDENCE + 100)
@Component
@WebFilter(filterName = "MDCFilter", urlPatterns = "/*")
public class MDCFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest httpServletRequest, HttpServletResponse httpServletResponse, FilterChain filterChain) throws ServletException, IOException {
        try {
            MDC.put("userId", "laker");
            MDC.put("requestId", IdUtil.fastUUID());
        } catch (Exception e) {
            //
        }

        try {
            filterChain.doFilter(httpServletRequest, httpServletResponse);
        } finally {
            MDC.clear();
        }
    }
}

logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOG_HOME" value="logs"/>
    <property name="encoding" value="UTF-8"/>

    <appender name="DEFAULT" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_HOME}/test.log</file>
        <Append>true</Append>
        <prudent>false</prudent>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{50} %line - %m%n</pattern>
        </encoder>
        <!-- 按天回滚 daily -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--归档日志文件名-->
            <FileNamePattern>${LOG_HOME}/test.log.%d{yyyy-MM-dd}</FileNamePattern>
            <!-- 最多保存15天历史文件 -->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
    </appender>

    <!-- 日志输出格式 -->
    <property name="log.pattern"
              value="%d{HH:mm:ss.SSS} [%thread] %-5level [%X{userId}|%X{requestId}] %logger{20} - [%method,%line] - %msg%n"/>

    <!-- 控制台输出 -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${log.pattern}</pattern>
        </encoder>
    </appender>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{50} %line - %m%n</pattern>
        </encoder>
    </appender>

    <logger name="com.test.demo" level="DEBUG">
        <appender-ref ref="DEFAULT"/>
    </logger>
    <!-- 日志输出级别 -->
    <root level="INFO">
        <appender-ref ref="DEFAULT"/>
        <appender-ref ref="console"/>
    </root>
</configuration>

返回体

public class Response<T> {
    @ApiModelProperty(notes = "响应码，非200 即为异常", example = "200")
    private final int code;
    @ApiModelProperty(notes = "响应消息", example = "提交成功")
    private final String msg;
    @ApiModelProperty(notes = "响应数据")
    private final T data;
    @ApiModelProperty(notes = "请求id")
    private final String requestId;

    public Response(int code, String msg, T data) {
        this.code = code;
        this.msg = msg;
        this.data = data;
        this.requestId = MDC.get("requestId");
    }

效果日志

响应

{
	code: 200,
	msg: "",
	requestId: "74a269a8-3cb4-417e-853c-b968b77cce23"
}

日志

18:37:15.997 [http-nio-8080-exec-1] INFO  [laker|90717490-5ef4-4e46-bc2c-605952fc3803] c.l.m.c.InfoController - [v2Map,17] - null
18:37:38.980 [http-nio-8080-exec-2] INFO  [laker|82bde351-f86e-466f-97a0-c857a0c4c1c9] c.l.m.c.InfoController - [v2Map,17] - null
18:37:39.992 [http-nio-8080-exec-3] INFO  [laker|74a269a8-3cb4-417e-853c-b968b77cce23] c.l.m.c.InfoController - [v2Map,17] - null