输出日志中加入traceId 进行链路追踪

环境 springboot 项目

 

定义一个filter

 

 

import lombok.extern.slf4j.Slf4j;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import java.io.IOException;
import java.util.UUID;

@Component
@Slf4j
public class LogTraceFilter implements Filter {
    private final String TRACE_ID = "TRACE_ID";
    @Override
    public void init(FilterConfig filterConfig) throws ServletException {

    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        try{
            String traceId = UUID.randomUUID().toString().replace("-", "");
            MDC.put(TRACE_ID, traceId);
            filterChain.doFilter(servletRequest, servletResponse);
        }catch (Exception e){
            log.error("添加traceId出错，错误信息：",e);
        }finally {
            MDC.remove(TRACE_ID);
        }
    }
    @Override
    public void destroy() {

    }
}

 

 

 

log4j2 日志输出中加入traceId

 

<?xml version="1.0" encoding="UTF-8"?>
<!--Configuration后面的status，这个用于设置log4j2自身内部的信息输出，可以不设置，当设置成trace时，你会看到log4j2内部各种详细输出-->
<!--monitorInterval：Log4j能够自动检测修改配置 文件和重新配置本身，设置间隔秒数-->
<configuration monitorInterval="5" >
    <!--日志级别以及优先级排序: OFF > FATAL > ERROR > WARN > INFO > DEBUG > TRACE > ALL -->

    <!--变量配置-->
    <Properties>
        <!-- 格式化输出：%date表示日期，%thread表示线程名，%X{TRACE_ID}这个是链路追踪的traceId, %-5level：级别从左显示5个字符宽度 %msg：日志消息，%n是换行符-->
        <!-- %logger{36} 表示 Logger 名字最长36个字符 -->
        <property name="LOG_PATTERN" value="%date{HH:mm:ss.SSS} 【%thread】 【%X{TRACE_ID}】 %-5level 【%logger{36}】 - %msg%n"/>
        <!-- 定义日志存储的路径 -->
        <property name="FILE_PATH" value="E:\\logs\\test"/>
        <property name="FILE_NAME" value="springboot-test"/>
    </Properties>

    <appenders>

        <console name="Console" target="SYSTEM_OUT">
            <!--输出日志的格式-->
            <PatternLayout pattern="${LOG_PATTERN}"/>
            <!--控制台只输出level及其以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
        </console>

        <!--文件会打印出所有信息，这个log每次运行程序会自动清空，由append属性决定，适合临时测试用-->
        <File name="Filelog" fileName="${FILE_PATH}/test.log" append="false">
            <PatternLayout pattern="${LOG_PATTERN}"/>
        </File>

        <!-- 这个会打印出所有的info及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="RollingFileInfo" fileName="${FILE_PATH}/info.log"
                     filePattern="${FILE_PATH}/${FILE_NAME}-INFO-%d{yyyy-MM-dd}_%i.log.gz">
            <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="${LOG_PATTERN}"/>
            <Policies>
                <!--interval属性用来指定多久滚动一次，默认是1 hour-->
                <TimeBasedTriggeringPolicy interval="1"/>
                <SizeBasedTriggeringPolicy size="10MB"/>
            </Policies>
            <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
            <DefaultRolloverStrategy max="15"/>
        </RollingFile>

        <!-- 这个会打印出所有的warn及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="RollingFileWarn" fileName="${FILE_PATH}/warn.log"
                     filePattern="${FILE_PATH}/${FILE_NAME}-WARN-%d{yyyy-MM-dd}_%i.log.gz">
            <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="warn" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="${LOG_PATTERN}"/>
            <Policies>
                <!--interval属性用来指定多久滚动一次，默认是1 hour-->
                <TimeBasedTriggeringPolicy interval="1"/>
                <SizeBasedTriggeringPolicy size="10MB"/>
            </Policies>
            <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
            <DefaultRolloverStrategy max="15"/>
        </RollingFile>

        <!-- 这个会打印出所有的error及以下级别的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档-->
        <RollingFile name="RollingFileError" fileName="${FILE_PATH}/error.log"
                     filePattern="${FILE_PATH}/${FILE_NAME}-ERROR-%d{yyyy-MM-dd}_%i.log.gz">
            <!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="${LOG_PATTERN}"/>
            <Policies>
                <!--interval属性用来指定多久滚动一次，默认是1 hour-->
                <TimeBasedTriggeringPolicy interval="1"/>
                <SizeBasedTriggeringPolicy size="10MB"/>
            </Policies>
            <!-- DefaultRolloverStrategy属性如不设置，则默认为最多同一文件夹下7个文件开始覆盖-->
            <DefaultRolloverStrategy max="15"/>
        </RollingFile>

    </appenders>

    <!--Logger节点用来单独指定日志的形式，比如要为指定包下的class指定不同的日志级别等。-->
    <!--然后定义loggers，只有定义了logger并引入的appender，appender才会生效-->
    <loggers>

        <!--过滤掉spring和mybatis的一些无用的DEBUG信息-->
        <logger name="org.mybatis" level="info" additivity="false">
            <AppenderRef ref="Console"/>
        </logger>
        <!--监控系统信息-->
        <!--若是additivity设为false，则 子Logger 只会在自己的appender里输出，而不会在 父Logger 的appender里输出。-->
        <Logger name="org.springframework" level="info" additivity="false">
            <AppenderRef ref="Console"/>
        </Logger>

        <root level="info">
            <appender-ref ref="Console"/>
            <appender-ref ref="Filelog"/>
            <appender-ref ref="RollingFileInfo"/>
            <appender-ref ref="RollingFileWarn"/>
            <appender-ref ref="RollingFileError"/>
        </root>
    </loggers>

</configuration>

 

 

 

请求后看日志

 

18:00:12.730 【http-nio-8080-exec-1】 【d9c6d00bafbb4aefb2502ae97a766f32】 INFO  【com.example.springboottest.test.TestController】 - controller request come in http-nio-8080-exec-1
18:00:12.730 【http-nio-8080-exec-1】 【d9c6d00bafbb4aefb2502ae97a766f32】 INFO  【com.example.springboottest.test.service.impl.TestServiceImpl】 - service request come in http-nio-8080-exec-1
18:00:12.731 【http-nio-8080-exec-1】 【d9c6d00bafbb4aefb2502ae97a766f32】 INFO  【com.example.springboottest.test.service.impl.TestServiceImpl】 - service inner request come in http-nio-8080-exec-1

 

 

输出格式改为JSON 格式

 

可以看到，上边输出的日志格式 非JSON 格式，如果想使用日志输出的格式为 JOSN格式应该怎么办呢？

可以看到上边的log4j2.xml的配置文件 使用的是 PatternLayout ，我们可以改用下边的格式

 

<JsonLayout compact="true" locationInfo="true" complete="false" eventEol="true" pattern="${LOG_PATTERN}" />

 

输出结果

{"instant":{"epochSecond":1601169916,"nanoOfSecond":590000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.TestController","message":"controller request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":159,"threadPriority":5,"source":{"method":"sayHello","file":"TestController.java","line":27,"class":"com.example.springboottest.test.TestController"}}
{"instant":{"epochSecond":1601169916,"nanoOfSecond":591000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.service.impl.TestServiceImpl","message":"service request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":159,"threadPriority":5,"source":{"method":"doTestService","file":"TestServiceImpl.java","line":14,"class":"com.example.springboottest.test.service.impl.TestServiceImpl"}}
{"instant":{"epochSecond":1601169916,"nanoOfSecond":592000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.service.impl.TestServiceImpl","message":"service inner request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":159,"threadPriority":5,"source":{"method":"doTestServiceInner","file":"TestServiceImpl.java","line":20,"class":"com.example.springboottest.test.service.impl.TestServiceImpl"}}

 

可以看到，输出的格式是JSON格式了，但是我们自己定义的 TRACEID 并没有输出。

我们可以修改为如下结果，添加我们自定义的字段

<JsonLayout compact="true" locationInfo="true" complete="false" eventEol="true" pattern="${LOG_PATTERN}">
                <KeyValuePair key="TRACE_ID" value="${ctx:TRACE_ID}"/>
            </JsonLayout>

 

 输出结果，可以看到，已经有了 TRACEID 字段了

 

 

{"instant":{"epochSecond":1601170158,"nanoOfSecond":492000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.TestController","message":"controller request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":158,"threadPriority":5,"source":{"method":"sayHello","file":"TestController.java","line":27,"class":"com.example.springboottest.test.TestController"},"TRACE_ID":"130999f8b5154eecb41e56eca76260b2"}
{"instant":{"epochSecond":1601170158,"nanoOfSecond":493000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.service.impl.TestServiceImpl","message":"service request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":158,"threadPriority":5,"source":{"method":"doTestService","file":"TestServiceImpl.java","line":14,"class":"com.example.springboottest.test.service.impl.TestServiceImpl"},"TRACE_ID":"130999f8b5154eecb41e56eca76260b2"}
{"instant":{"epochSecond":1601170158,"nanoOfSecond":494000000},"thread":"http-nio-8080-exec-2","level":"INFO","loggerName":"com.example.springboottest.test.service.impl.TestServiceImpl","message":"service inner request come in http-nio-8080-exec-2","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":158,"threadPriority":5,"source":{"method":"doTestServiceInner","file":"TestServiceImpl.java","line":20,"class":"com.example.springboottest.test.service.impl.TestServiceImpl"},"TRACE_ID":"130999f8b5154eecb41e56eca76260b2"}