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

• 前言
• 原理
• 实现
  • 过滤器
  • logback.xml
  • 返回体
• 效果日志

前言

在微服务环境中，我们经常使用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