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需要注意放置的位置，避免由于加载顺序而失效。