logback下日誌輸出前處理操作——以日誌脫敏為例

使用lockback

目前Java Spring服務在列印日誌時一般使用slf4j和logback這種組合，其基本原理圖如下

具體的：大多數會先定義一個loackback-dev.xml檔案，而後使用<appender>標籤定義輸出格式

<appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}</file>
        <!--滾動策略，基於時間策略 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyyMMddHH}</fileNamePattern>
            <maxHistory>168</maxHistory>
        </rollingPolicy>
        <!-- 日誌的格式化 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>[%level][%d{yyyy-MM-dd'T'HH:mm:ss.SSSZ}][%logger:%L][%thread]||traceid=%X{traceId}||spanid=%X{spanId}||hintCode=%X{hintCode}||hintContent=%X{hintContent}||uri=%X{uri}||caller=%X{caller}||ip=%X{ip}||proc_time=%X{proc_time}||%msg%n</pattern>
            <charset>utf8</charset>
        </encoder>
</appender>

如果使用了Lombok提供的@slf4j註解來輸入日誌，它會自動生成一個名為 log 的日誌物件，用於在程式中輸出日誌資訊。

具體使用時會在應用中

log.info("this is a testing log!")；

在使用這條語句到列印出日誌到指定位置，總共會經過六個步驟（ 官方文件地址，中譯版地址）

第一步：獲取過濾器鏈

如果存在，則 TurboFilter 過濾器會被呼叫，Turbo 過濾器會設定一個上下文的閥值，或者根據每一條相關的日誌請求資訊，例如：Marker, Level， Logger， 訊息，Throwable 來過濾某些事件。如果過濾器鏈的響應是 FilterReply.DENY，那麼這條日誌請求將會被丟棄。如果是 FilterReply.NEUTRAL，則會繼續執行下一步，例如：第二步。如果響應是 FilterRerply.ACCEPT，則會直接跳到第三步。

第二步：應用基本選擇規則

在這步，logback 會比較有效級別與日誌請求的級別，如果日誌請求被禁止，那麼 logback 將會丟棄調這條日誌請求，並不會再做進一步的處理，否則的話，則進行下一步的處理。

第三步：建立一個 LoggingEvent 物件

如果日誌請求透過了之前的過濾器，logback 將會建立一個 ch.qos.logback.classic.LoggingEvent 物件，這個物件包含了日誌請求所有相關的引數，請求的 logger，日誌請求的級別，日誌資訊，與日誌一同傳遞的異常資訊，當前時間，當前執行緒，以及當前類的各種資訊和 MDC。MDC 將會在後續章節進行討論。

第四步：呼叫 appender

在建立了 LoggingEvent 物件之後，logback 會呼叫所有可用 appender 的 doAppend() 方法。這些 appender 繼承自 logger 上下文。

所有的 appender 都繼承了 AppenderBase 這個抽象類，並實現了 doAppend() 這個方法，該方法是執行緒安全的。AppenderBase 的 doAppend() 也會呼叫附加到 appender 上的自定義過濾器。自定義過濾器能動態的動態的新增到 appender 上，在過濾器章節會詳細討論。

第五步：格式化輸出

被呼叫的 Appender 負責格式化 Logging Event。但是，有些 Appender 將格式化 Logging Event 的任務委託給一個 Layout。Layout 將 LoggingEvent 例項格式化為一個字串並返回。但需要注意的是，某些 Appender（例如 SocketAppender） 並不會把 Logging Event 轉化為一個字串，而是進行序列化。因此，它們沒有並且也不需要 Layout。

第六步：傳送 LoggingEvent

當日志事件被完全格式化之後將會透過每個 appender 傳送到具體的目的地。

下面是執行上面六個步驟的UML圖

我們不難發現，Layout類操作時，會返回一個String型別變數，這個就是我們指定的info方法裡的字串，預設情況下logback直接返回，具體的處理類如下

public class MessageConverter extends ClassicConverter {
    public String convert(ILoggingEvent event) {
        return event.getFormattedMessage();
    }
}

其並沒有做什麼操作，所以可以從這裡入手繼承抽象類ClassicConverter,重寫convert方法

重寫ClassicConverter類

public class DesensitizedMessageConverter extends ClassicConverter {
    public static final int LOG_MAX_LENGTH = 10000;
    
    public String desensitization(String content) {
        // 這裡是真正進行操作的方法，此處是日誌脫敏，具體實現可以自己定義
        content = RegexUtils.desensitization(content);
      
        return content;
    }
    @Override
    public String convert(ILoggingEvent iLoggingEvent) {
        String source = iLoggingEvent.getFormattedMessage();
        try {
            // 日誌超長處理
            if (source.length() > LOG_MAX_LENGTH) {
                source = StringUtils.substring(source, 0, LOG_MAX_LENGTH) + "<<<";
            }
            return desensitization(source);
        } catch (Exception e) {
            log.error("DesensitizedMessageConverter convert error", e);
        }

        return source;
    }
}

需要注意的是，儘管logback的日誌輸出是非同步的，這裡也做了一下日誌截斷操作，避免由於日誌過長，脫敏（或者其他操作）長耗時，造成效能問題，因為這個非同步操作是透過一個BlockingQueue<E> blockingQueue；來執行日誌時間的輸出，預設情況下超過佇列80%容量是，會丟棄info級別以下的日誌。

使用與生效

重寫了轉換類後，還需要使其生效，將自定義的轉換類配置到logback配置檔案中，位置在<configuration>標籤下

<configuration>
    <!-- 自定義的日誌轉換類  -->
    <conversionRule conversionWord="dmsg" converterClass="com.xxx.xxx.xxxx.log.DesensitizedMessageConverter"/>
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}</file>
        <!--滾動策略，基於時間策略 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyyMMddHH}</fileNamePattern>
            <maxHistory>168</maxHistory>
        </rollingPolicy>
        <!-- 日誌的格式化 -->
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>[%level][%d{yyyy-MM-dd'T'HH:mm:ss.SSSZ}][%logger:%L][%thread]||traceid=%X{traceId}||spanid=%X{spanId}||hintCode=%X{hintCode}||hintContent=%X{hintContent}||uri=%X{uri}||caller=%X{caller}||ip=%X{ip}||proc_time=%X{proc_time}||%dmsg%n</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>
</configuration>

其中conversionWord="dmsg" 是自定義的佔位符，輸出日誌時在<pattern>標籤下使用%dmsg來生效，需要注意的一點是conversionRule需要注意放置的位置，避免由於載入順序而失效。