Java中最简单的添加日志链路的方式之一

Java项目中添加日志链路功能的设计与实现

---

---

前言

在Java项目的开发过程中，日志记录是不可或缺的一部分。它不仅可以帮助我们追踪程序的执行过程，还可以在出现问题时提供关键的调试信息，特别是当线上出现问题时，详细的日志可以帮助我们更快的定位到问题。然而，随着项目的不断壮大和复杂度的增加，单一的日志记录往往难以满足需求。因此，引入日志链路功能，将不同模块、不同层级的日志信息串联起来，形成完整的执行路径，对于提升项目的可维护性和调试效率具有重要意义。

本文主要是针对单体项目，以单项目为基础例子进行展开讲解，。

---

一、日志链路的概念与作用

日志链路是指将一次完整的业务请求或操作过程中产生的所有日志信息按照时间顺序和逻辑关系串联起来，形成一个完整的日志链。通过日志链路，我们可以清晰地看到业务请求从接收、处理到完成的整个过程，以及其中各个环节的详细执行情况。这对于分析性能瓶颈、定位故障原因以及优化系统性能等方面都具有重要作用。

二、添加日志链路的设计思路

在Java项目中添加日志链路功能，可以从以下几个方面进行设计：

1. 定义一个全局唯一的标识（如UUID）作为日志链路的ID，用于标识一次完整的业务请求或操作。

简单示例代码：

public class TraceIdGenerator {

    private static final AtomicLong counter = new AtomicLong(0);

    /**
     * 生成一个随机的trace_id。
     * 这个trace_id由UUID和递增的计数器组成，确保在单一JVM实例中的唯一性。
     * 如果需要跨多个JVM实例的唯一性，请仅使用UUID部分。
     * 注意，仅仅使用UUID也并不能保证在极端情况下（例如全球范围内的大量并发请求）的绝对唯一性
     *
     * @return 生成的trace_id
     */
    public static String generateTraceId() {
        String uuidPart = UUID.randomUUID().toString().replace("-", ""); // 移除UUID中的横线，使其更简洁
        long counterPart = counter.incrementAndGet(); // 递增计数器

        // 拼接UUID和计数器部分，确保在单一JVM实例中的唯一性
        return uuidPart + "-" + counterPart;
    }

    public static void main(String[] args) {
        // 测试生成几个trace_id
        for (int i = 0; i < 5; i++) {
            System.out.println(generateTraceId());
        }
    }
}

2. 在业务请求的入口处生成该标识，并将其传递给后续的处理环节。此步骤可以统一使用过滤器或者拦截器都可以，正常现在每个项目在进
   入业务流程之前都会有一个解析用户信息的步骤，可以放在同一个步骤上。传递这个标识可以通过自定义日志记录器或使用现有的日志框架（如SLF4J、Logback等）的MDC（Mapped Diagnostic Context）功能来实现。

代码示例：MDC存放的逻辑你可以理解成map类型（底层是ThreadLocal），存放的数据是key、value形式。BaseConstants.TRACE_ID是定义的一个key，TraceIdGenerator.generateTraceId()是生成的链路id，放在MDC之后在线程的上下文就可以直接使用MDC.get(BaseConstants.TRACE_ID)去获取链路id。

public class LogFilter extends OncePerRequestFilter {

    private final Logger logger = LoggerFactory.getLogger(LogFilter.class);

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        filter(request,response, filterChain);
    }

    private void filter(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws IOException, ServletException {
        request.setCharacterEncoding(StandardCharsets.UTF_8.name());
        try {
            //将threadId和traceId放入mdc   BaseConstants.TRACE_ID = "TRACE_ID"
            MDC.put(BaseConstants.TRACE_ID, TraceIdGenerator.generateTraceId());
            MDC.put(BaseConstants.MDC_THREAD_ID, String.valueOf(Thread.currentThread().getId()));

            //在响应头中设置traceId
            response.setHeader(BaseConstants.TRACE_ID,MDC.get(BaseConstants.TRACE_ID));

            logger.debug("=== begin request processing ===");
            RequestWrapper requestWrapper = new RequestWrapper(request);
            chain.doFilter(requestWrapper, response);

        } finally {
           
            logger.debug("=== finish request processing ===");
            
            //移除 threadId和traceId
            MDC.remove(BaseConstants.TRACE_ID);
            MDC.remove(BaseConstants.MDC_THREAD_ID);

        }
    }
//过滤器需要注册，且需要配置相关的规则
@Configuration
public class WebConfig {

    @Bean
    public FilterRegistrationBean<LogFilter> platformFilter() {
        FilterRegistrationBean<LogFilter> filterRegBean = new FilterRegistrationBean<>();
        //设置过滤器
        filterRegBean.setFilter(new LogFilter());
        //设置过滤路径：所有请求路径
        filterRegBean.addUrlPatterns("/*");
        //设置过滤顺序：数字越小，会在越前面过滤
        filterRegBean.setOrder(-9999);

        return filterRegBean;
    }
}

3. 在各个处理环节中，将日志链路的ID作为日志记录的一部分，确保所有与该请求相关的日志都能被正确关联。这里其实就是配置日志文件的输出格式，带上日志链路id即可。可以看到配置的输出中有TRACE_ID，这是因为在第二个步骤中，存放在MDC中的日志链路id的key是TRACE_ID。

logging.file.name=log-demo1.log
logging.level.root=info
logging.level.com.jzs.log=debug
logging.level.com.jzs.log.console=debug
logging.pattern.console=[%d{MM-dd HH:mm:ss.SSS}][%thread][%level][LOG-DEMO1] %cyan([%logger{50}.%F:%L]):[%X{TRACE_ID}] %msg%n
logging.pattern.file=[%d{MM-dd HH:mm:ss.SSS}][%thread][%level][LOG-DEMO1] %cyan([%logger{50}.%F:%L]):[%X{TRACE_ID}] %msg%n

4. 最后，我们需要一种机制来收集具有相同日志链路ID的日志信息，并按照时间顺序和逻辑关系进行排序和展示。这可以通过日志收集系统（如ELK Stack、ClickHouse+可视化界面等）来实现。这些系统通常支持按照特定字段（如本例中的traceId）对日志进行过滤和排序，从而方便地展示完整的日志链路。

三、如何支持多线程下的日志打印也附加上日志链路id

主要就在于重写类方法上，涉及的是Runnable和Callable这两个接口，下面给出示例和使用方式。

1. 示例1：实现Runnable接口，无返回值

public abstract class MyRunnable implements Runnable {

    private final Logger log = LoggerFactory.getLogger(MyRunnable.class);

    private String traceId;

    public MyRunnable() {
        traceId = MDC.get(BaseConstants.TRACE_ID);
    }

    public MyRunnable(String traceId) {
        this.traceId = traceId;
    }

    @Override
    public void run() {
        try {
            MDC.put(BaseConstants.TRACE_ID, traceId);
            log.info("MyRunnable::run");
            doRun();
        } finally {
            MDC.remove(BaseConstants.TRACE_ID);
        }
    }

    public abstract void doRun();

}

2. 示例2：实现Callable接口，有返回值

public abstract class MyCallable implements Callable {

    private final Logger log = LoggerFactory.getLogger(MyCallable.class);

    private String traceId;

    public MyCallable() {
        traceId = MDC.get(BaseConstants.TRACE_ID);
    }

    public MyCallable(String traceId) {
        this.traceId = traceId;
    }

    @Override
    public Object call() throws Exception {
        try {
            MDC.put(BaseConstants.TRACE_ID, traceId);
            log.info("TraceCallable::call");
            return doCall();
        } finally {
            MDC.remove(BaseConstants.TRACE_ID);
        }
    }

    public abstract Object doCall();

}

3.使用示例

@GetMapping("/test")
public Object test() throws Exception {

    ExecutorService executorService = Executors.newSingleThreadExecutor();

    log.info("进入test");

    new Thread(()->{
        //预期无打印traceId
        log.info("Thread::start");
    }).start();

    new Thread(new MyRunnable() {
        @Override
        public void doRun() {
        }
    }).start();

    new Thread(new MyRunnable() {
        @Override
        public void doRun() {
            log.info("MyRunnable::doRun::2");
        }
    }).start();

    executorService.submit(new MyRunnable() {
        @Override
        public void doRun() {
            log.info("MyRunnable::doRun::3");
        }
    });

    Future future = executorService.submit(new MyCallable() {
        @Override
        public Object doCall() {
            log.info("MyCallable::doCall");
            return "11111";
        }
    });

    log.info("MyCallable::call::{}",future.get());

/*
    //没有通过子线程去创建会导致traceId丢失
    new MyRunnable(){

        @Override
        public void doRun() {
            log.info("MyRunnable::doRun::");
        }
    }.run();
    String s = MDC.get(BaseConstants.TRACE_ID);
    MyCallable myCallable = new MyCallable() {
        @Override
        public Object doCall() {
            log.info("MyCallable::doCall");
            return "11111";
        }
    };
    myCallable.call();
*/
    return ""+ MDC.get(BaseConstants.TRACE_ID);
}

打印如下：

---

总结

通过以上步骤，我们可以在Java项目中实现日志链路功能，提升项目的可维护性和调试效率。然而，日志链路只是日志管理的一个方面，我们还需要关注日志的级别控制、格式化、异步处理等方面，以构建一个完善的日志管理体系。当前的只是一个很简单的例子，从基础到深层次，慢慢的熟悉才能一步步的成长。

基于单体项目的日志链路，其实分布式也是可以套用的。像常见的调用下游系统或者分布式项目中的其他项目的业务接口，只需要在请求业务接口之前，将traceId放在请求头中或者是一个约定俗成的对象字段中，那么下游接口就可以获取到这个链路id并做处理，这样子当发现问题时，需要下游帮忙排查时只需要提供这个链路id，就可以更快的进行请求和错误定位。当然，分布式链路追踪肯定不止这么简单，但是原理都是一样的，只是功能更加完善，使用也比较方便。