詳解Java如何在CompletableFuture中實(shí)現(xiàn)日志記錄

更新時(shí)間：2023年04月20日 08:28:54 作者：會(huì)飛的蛋蛋面

這篇文章主要為大家詳細(xì)介紹了一種slf4j自帶的MDC類，來(lái)記錄完整的請(qǐng)求日志，和在CompletableFuture異步線程中如何保留鏈路id，需要的可以參考一下

平時(shí)寫(xiě)項(xiàng)目的時(shí)候，java之父叫我們多打日志，我們通常使用traceId和requestId來(lái)保存完整請(qǐng)求的鏈路日志，例如市面上的skywalking、zipkin等都能實(shí)現(xiàn)此功能。

下面介紹一種slf4j自帶的MDC類，來(lái)記錄完整的請(qǐng)求日志，和在CompletableFuture異步線程中如何保留鏈路id

1.首先利用aop為所有請(qǐng)求入口添加requestId。

@Aspect
@Component
public class LoggingAspect {

    /**
     * AOP注解的Controller類方法必須為 public 或 protect ，千萬(wàn)不能用private！?。。。。。。》駝t會(huì)@Autowired注入的service會(huì)報(bào)空指針異常。
     * 私有方法和字段不屬于Spring上下文中的bean屬性。
     */
    @Around("@annotation(org.springframework.web.bind.annotation.GetMapping) || " +
            "@annotation(org.springframework.web.bind.annotation.PostMapping) || " +
            "@annotation(org.springframework.web.bind.annotation.PutMapping) || " +
            "@annotation(org.springframework.web.bind.annotation.DeleteMapping)")
    public Object logAround(ProceedingJoinPoint joinPoint) throws Throwable {
        // 在logback-spring.xml里對(duì)應(yīng)%X{requestId}
        MDC.put("requestId", UUID.randomUUID().toString().substring(0, 13));  // Add request ID to MDC
        try {
            return joinPoint.proceed(); // Execute method
        } finally {
            MDC.remove("requestId");  // Remove request ID from MDC
        }
    }
}

2.定義一下 logback-spring.xml ，引入 requestId 來(lái)進(jìn)行鏈路記錄，關(guān)鍵代碼是 %X{requestId}

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- 控制臺(tái)日志格式 -->
    <property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %X{requestId} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <!-- 控制臺(tái)日志格式 依賴的渲染類 -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
    <conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
    <conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
    <!-- 輸出到控制臺(tái) -->
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
                <level>debug</level>
            </filter>
            <!-- 配置日志輸出格式 -->
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <!-- 使用的字符集 -->
            <charset>UTF-8</charset>
        </encoder>
    </appender>


    <!-- 定義輸出的路徑，獲取application.yml的source的值 -->
    <springProperty scope="context" name="LOG_FILE_PATH" source="logging.file-location" default="/var/log/myapp"/>
    <!-- 2.輸出到文件 -->
    <!-- 2.1 level為 DEBUG 日志，時(shí)間滾動(dòng)輸出  -->
    <appender name="DEBUG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE_PATH}/debug.log</file> <!-- 文件路徑 -->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{requestId} [%thread] %-5level %logger{50} - %msg%n</pattern><!-- 日志文檔輸出格式 -->
            <charset>UTF-8</charset>
        </encoder>
        <!-- 日志記錄器的滾動(dòng)策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天新開(kāi)一個(gè)文件 -->
            <fileNamePattern>${LOG_FILE_PATH}/debug-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!-- 每天100m新開(kāi)一個(gè)文件 -->
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!-- 日志文檔保留天數(shù) -->
            <maxHistory>15</maxHistory>
            <!-- 用來(lái)指定日志文件的上限大小，例如設(shè)置為1GB的話，那么到了這個(gè)值，就會(huì)刪除舊的日志。 -->
            <totalSizeCap>1GB</totalSizeCap>
        </rollingPolicy>
        <!-- 此日志文檔只記錄debug級(jí)別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>debug</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.2 level為 INFO 日志，時(shí)間滾動(dòng)輸出  -->
    <appender name="INFO_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE_PATH}/info.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{requestId} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE_PATH}/info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文檔只記錄info級(jí)別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.3 level為 WARN 日志，時(shí)間滾動(dòng)輸出  -->
    <appender name="WARN_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE_PATH}/warn.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{requestId} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset> <!-- 此處設(shè)置字符集 -->
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE_PATH}/warn-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文檔只記錄warn級(jí)別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>warn</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 2.4 level為 ERROR 日志，時(shí)間滾動(dòng)輸出  -->
    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE_PATH}/error.log</file>
        <!--日志文檔輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %X{requestId} [%thread] %-5level %logger{50} - %msg%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE_PATH}/error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文檔只記錄ERROR級(jí)別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 使用異步，一個(gè)AsyncAppender只能添加一個(gè)appender-ref -->
    <appender name="ASYNC_DEBUG_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="DEBUG_FILE"/>
    </appender>
    <appender name="ASYNC_INFO_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="INFO_FILE"/>
    </appender>
    <appender name="ASYNC_WARN_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="WARN_FILE"/>
    </appender>
    <appender name="ASYNC_ERROR_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="ERROR_FILE"/>
    </appender>

    <!-- 開(kāi)啟上面的appender -->
    <root level="info">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="ASYNC_DEBUG_FILE" />
        <appender-ref ref="ASYNC_INFO_FILE" />
        <appender-ref ref="ASYNC_WARN_FILE" />
        <appender-ref ref="ASYNC_ERROR_FILE" />
    </root>


</configuration>

2.定義一個(gè)`復(fù)雜`業(yè)務(wù)流程，來(lái)看看日志的實(shí)力

private final ExecutorService executorService = Executors.newFixedThreadPool(4);

@GetMapping("saveUser")
    public String saveUser() {
    log.info("進(jìn)入了saveUser");
    // 異步
    CompletableFuture.runAsync(()-> b(), executorService);
    log.info("退出了saveUser");
    return "Ok";
}

private void b() {
    log.info("進(jìn)入了b");
}

日志如下，可以看到異步線程的requestId丟失了，21dbaad3-3158 這個(gè)就是requestId，這種情況下我們需要自定義線程類來(lái)保存MDC的上下文

2023-04-19 11:51:59.309 21dbaad3-3158 INFO 23044 --- [p-nio-80-exec-1] c.h.m.api.CompletableFutureApi : 進(jìn)入了saveUser
2023-04-19 11:51:59.312 21dbaad3-3158 INFO 23044 --- [p-nio-80-exec-1] c.h.m.api.CompletableFutureApi : 退出了saveUser
2023-04-19 11:51:59.312 INFO 23044 --- [pool-1-thread-1] c.h.m.api.CompletableFutureApi : 進(jìn)入了b

3.定義線程實(shí)現(xiàn)類，并且在構(gòu)造函數(shù)中存儲(chǔ)MDC的上下文

public static class MdcTaskWrapper implements Runnable {
    private final Runnable task;
    private final Map<String, String> contextMap;

    public MdcTaskWrapper(Runnable task) {
        this.task = task;
        this.contextMap = MDC.getCopyOfContextMap();
    }

    @Override
    public void run() {
        if (contextMap != null) {
            MDC.setContextMap(contextMap);
        }
        try {
            task.run();
        } finally {
            MDC.clear();
        }
    }
}

4.接下來(lái)再改寫(xiě)一下runAsync的使用方式，我們用MdcTaskWrapper來(lái)進(jìn)行線程操作，這個(gè)線程類是包含mdc上下文的

@GetMapping("saveUser")
public String saveUser() {
    log.info("進(jìn)入了saveUser");
    // 異步
    CompletableFuture.runAsync(this::b, command -> executorService.execute(new MdcTaskWrapper(command)));
    log.info("退出了saveUser");
    return "Ok";
}

private void b() {
    log.info("進(jìn)入了b");
}

可以看到，requestId：4ab037ab-92cb，異步線程能夠拿到MDC的上下文，并且成功記錄鏈路日志

2023-04-19 11:58:27.581 4ab037ab-92cb INFO 6816 --- [p-nio-80-exec-5] c.h.m.api.CompletableFutureApi : 進(jìn)入了saveUser
2023-04-19 11:58:27.582 4ab037ab-92cb INFO 6816 --- [p-nio-80-exec-5] c.h.m.api.CompletableFutureApi : 退出了saveUser
2023-04-19 11:58:27.582 4ab037ab-92cb INFO 6816 --- [pool-1-thread-1] c.h.m.api.CompletableFutureApi

以上就是詳解Java如何在CompletableFuture中實(shí)現(xiàn)日志記錄的詳細(xì)內(nèi)容，更多關(guān)于Java CompletableFuture日志記錄的資料請(qǐng)關(guān)注腳本之家其它相關(guān)文章！

您可能感興趣的文章: