一起进阶一起拿高工资！Java开发进阶-log4j2日志脱敏原理

大家好，我是tin，这是我的第5篇原创文章

本文讲述在考虑对业务系统代码入侵最小的情况下实现日志脱敏的方案原理。文章很长，包括了日志脱敏起由、编码实现、log4j2.xml文件加载原理、log4j2的插件机制等，最后还抖出注解编译处理器AbstractProcessor，实现编译期动态生成代码！有点像捡到宝，毕竟以前没关注过注解编译处理器，先上一个目录：

• 一、为什么做日志脱敏

• 二、log4j2日志脱敏编码实现

• 三、源码探索log4j2日志脱敏实现原理
  1、什么是slf4j？
  2、log4j2又是什么？
  3、slf4j和log4j2是如何完成绑定的？
  4、log4j.xml配置文件是如何加载的？
  5、我们定义log4j2的Plugin插件又是如何加载注册的？
  6、AbstractProcessor注解处理器

• 四、朋友请留步

一、为什么做日志脱敏

日志打印非常常见且重要，这毋庸置疑，但有这样一种情况：我们打印的日志包含了用户的隐私信息，比如做登录支付的打印用户账号和密码，做金融的打印用户的卡号等，这些日志先不说放在磁盘上管理不当可能造成用户隐私泄露，再者就算是合规检查，它也是不过关的，必须要做处理整治。

我们打日志是怎么打的？先上一个图(日志中打印我的用户名和账号)，看看我们自己就是这么用的：

没做特殊处理，不出意外，日志输出是这样的：

image

卡号打印出来了，随后这行日志就安详地躺在我们服务器磁盘上。
[图片上传失败...(image-bdaa9d-1611469924727)]

二、log4j2日志脱敏编码实现

如何借助日志框架实现对账号打码脱敏，而不入侵业务代码？废话不多说，先看看我已实现的效果：

image

本文基于slf4j+log4j2实现，我们代码日志输出处没有任何改动，打打印出来的日志对卡号做了打码脱敏。

本文实现日志打码脱敏的方案涉及开发的地方有两个：

一是实现log4j2的RewritePolicy接口，重写logEvent；

二是修改log4j2.xml文件。

看看我写的RewritePolicy实现类：

image

log4j2.xml修改，下面是log4j2配置和rewrite配置：

image

这个文件也非常详细地把log4j2.xml配置解释了一遍，不是很清楚log4j配置的可留图保存啦。

为了方便复制，把log4j2.xml配置的源码粘贴一份出来：

<?xml version="1.0" encoding="UTF-8"?>
<configuration monitorInterval="5">
<!--变量配置-->
<Properties>
    <!-- 格式化输出：%date表示日期，HH:mm:ss.SSS表示日期格式，%thread表示线程名，%-5level表示级别从左显示5个字符宽度，
    %C{1.}表示类全限定名输出精度，%-4L输出日志所在行行号，%msg代表日志消息，%n是换行符-->
    <property name="LOG_PATTERN" value="%date{HH:mm:ss.SSS} [%thread] %-5level %C{1.} %-4L : %msg%n"/>
    <!-- 定义日志存储的路径.${web:rootDir}表示当前工程目录， -->
    <property name="FILE_PATH" value="../log/tin-example"/>
    <property name="FILE_NAME" value="tin-example"/>
</Properties>

<appenders>
    <!--控制台输出-->
    <console name="Console" target="SYSTEM_OUT">
        <!--输出日志的格式-->
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <!--表示输出level=debug级别及以上日志（onMatch），debug级别以下不输出（onMismatch）-->
        <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/>
    </console>

    <Rewrite name="rewrite">
        <DataMaskingRewritePolicy/>
        <AppenderRef ref="Console"/>
    </Rewrite>

    <!-- 打印出所有级别的日志信息，并自动滚动存档-->
    <RollingFile name="AllLevelRollingFile" fileName="${FILE_PATH}/${FILE_NAME}.log"
                 filePattern="${FILE_PATH}/${FILE_NAME}-ALL-%d{yyyy-MM-dd}_%i.log.gz">
        <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="ACCEPT"/>
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <Policies>
            <!--interval属性用来指定多久滚动一次，interval=1表示1小时滚动一次-->
            <TimeBasedTriggeringPolicy interval="1"/>
            <!--size=20表示文件大于20M滚动一次-->
            <SizeBasedTriggeringPolicy size="20MB"/>
        </Policies>
        <!-- max=15表示同文件夹下最多10个文件，再多则会覆盖，DefaultRolloverStrategy如不设置，则默认为7个-->
        <DefaultRolloverStrategy max="10"/>
    </RollingFile>

    <!-- 打印出所有error及以上级别的信息，并自动滚动存档-->
    <RollingFile name="ErrorRollingFile" fileName="${FILE_PATH}/error.log"
                 filePattern="${FILE_PATH}/${FILE_NAME}-ERROR-%d{yyyy-MM-dd}_%i.log.gz">
        <!--输出level及以上级别的信息（onMatch），level以下直接拒绝（onMismatch）-->
        <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
        <PatternLayout pattern="${LOG_PATTERN}"/>
        <Policies>
            <!--interval属性用来指定多久滚动一次，interval=1表示1小时滚动一次-->
            <TimeBasedTriggeringPolicy interval="1"/>
            <!--size=20表示文件大于20M滚动一次-->
            <SizeBasedTriggeringPolicy size="20MB"/>
        </Policies>
        <!-- max=15表示同文件夹下最多10个文件，再多则会覆盖，DefaultRolloverStrategy如不设置，则默认为7个-->
        <DefaultRolloverStrategy max="10"/>
    </RollingFile>

</appenders>

<!--Logger节点用来单独指定日志的形式，可以给不同包配置不同的日志打印策略。-->
<loggers>
    <logger name="com.tin.example.spring.log4j2" level="info" additivity="false">
        <AppenderRef ref="rewrite"/>
    </logger>

    <root level="debug">
        <appender-ref ref="Console"/>
        <appender-ref ref="AllLevelRollingFile"/>
        <appender-ref ref="ErrorRollingFile"/>
    </root>
</loggers>
</configuration>

三、源码探索log4j2日志脱敏原理

为何上文这么做就能实现日志打码脱敏？是有什么变法么？实现的原理是什么？背着一大连串疑问，现在我们从slf4j和log4j2原理说起，来了，搬好凳子了。

1、什么是slf4j？

slf4j全称simple logging facade for Java。是一个日志接口框架，配合日志输出系统实现日志输出。slf4j并不是真正输出日志的系统，只是定义了一套日志规范。类似这样的日志门面还有commons-logging。

private static final Logger LOGGER = LoggerFactory.getLogger(AccountTest.class);

以上的Logger就是slf4j的类。

2、log4j2又是什么？

log4j2才是一个真正的日志系统，它才是我们项目中打印日志的代码库实现。除了log4j2，我们常见的日志库还有log4j、logback、jdk-logging。

slf4j作为连接log和代码层的中间层，我们只要使用slf4j提供的接口，不用关心日志的具体实现（想想这样的好处是我们可以把业务系统内日志库比如log4j2换为logback也没问题）。说起来有点像jdbc，我们切换不同的数据库，jdbc帮我们做好了兼容。

log4j2的依赖包有3个，slf4j和log4j2的几个jar包关系作用如下：

image

3、slf4j和log4j2是如何完成绑定的？

从上面图都看到了，slf4j-api和log4j相关的包根本不在一起，那么它们之间是通过什么关联的？

答案是：

slf4j指定路径进行类加载，log4j必然有桥接实现类。 还是从这行定义和初始化Logger的代码开始看起：

private static final Logger LOGGER = LoggerFactory.getLogger(AccountTest.class);

从LoggerFactory.getLogger一直进入到LoggerFactory类的bind方法，找到staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet()，这里即是slf4j完成绑定log4j2的地方：

image

findPossibleStaticLoggerBinderPathSet()通过指定路径加载一个StaticLoggerBinder类：

image

指定查找org/slf4j/impl/StaticLoggerBinder.class进行加载。

那么StaticLoggerBinder应该在哪里？

当然是在log4j2包内了！

image

通过StaticLoggerBinder这个类即完成了slf4j和log4j的绑定，看下图。

image

绑定完之后即通过getLoggerFactory方法获取到Log4jLoggerFactory：

image

log4j2和slf4j完成了绑定，那么，和本文所说的脱敏原理有什么关系？

脱敏的实现原理真正在于log4j2，以上只是展开说明日志系统的基本关联原理，为接下来讲述log4j的插件机制打个铺垫。

log4j2 通过使用插件机制加载各种组件，比如appender, logger等，我们的脱敏方案编码定义了一个类：

image

实现了log4j的rewrite策略类，这其实就是一种插件！

要讲清楚Plugin原理得分两部分讲。

一是log4j.xml配置文件是如何加载的；

二是我们定义的Plugin插件又是如何加载注册的。

4、log4j.xml配置文件是如何加载的？

我们依然是通过断点看源码，毕竟，源码底下无谎言！ 还是从下面这行代码开始看起：

image

上文已经提到过Log4jLoggerFactory，它继承了AbstractLoggerAdapter这个抽象类，我们直接进入到getContext方法获取Logger的地方：

image

anchor中文译为"锚"，这里是通过Java反射得到日志类，anchor不为null，因此进入到后面的语句。

image

进入getContext，我们的Log4jContextFactory又出现了，它在LogManager中的静态代码块中已初始化好。

image

我们继续到Log4jContextFactory内看getContext：

image

已初始化好的selector，内部具体如何获取context有兴趣可自行debug，我们进入到ctx.start方法内：

image

看到reconfigure()方法，就知道log4j准备开始加载配置了！！！再从reconfigure一直往下看：

image

687行获取得到一个XmlConfiguration，这是因为我们使用的是xml配置文件！！！正常来说配置文件除了xml，还有properties，yaml，json等。

此处既然已获得配置文件的内容， 那么我们退回去看ConfigurationFactory.getInstance().getConfiguration(this,contextName,configURI,cl)。

image

看看XmlConfigurationFactory类

image

指定了xml后缀，getConfiguration实际返回XmlConfiguration

image

根据configSource的log4jx.xml文件，进行配置内容加载。

image

到这里xml配置就算是加载完成啦。xml里面定义的<DataMaskingRewritePolicy/>标签也会被加载。

[图片上传失败...(image-28c8f9-1611469924727)]

接下来，自然而然的我们就会问，这个标签和代码@Plugin注解定义的插件是如何关联起来的？或者又说Plugin插件是如何加载的？

5、我们定义的Plugin插件又是如何加载注册的？

log4j中的Plugin注解提供了一种便捷的方法将一个类声明成 log4j2 的插件，比如我单测用到的案例：

image

在log4j2加载上下文的时候会加载Plugin，log4j统一用PluginRegistry注册中心加载和注册插件，并由PluginManager来管理。

进入到PluginManager：

image

注释都写得很清楚，从指定的指定文件Log4j2Plugin.dat加载插件，继续进入loadFromMainClassLoader方法

image image

不同模块不同jar包都有可能存在Log4j2Plugins.dat文件，比如log4j-core包存在

image

我们自己编写代码定义的插件则被编译到target目录下(因为我的是mac，在控制台的看得，win系统也一样找到编译产生的target文件夹即可)

image

我们编译生成的Log4j2Plugins.dat里面的内容又是什么呢？

image

文件记录了插件分类、全限定类名等信息。

说到这里，产生新的一个疑问，我们自己的Log4j2Plugins.dat 文件究竟是如何被生成到target目录下的？

6、AbstractProcessor注解处理器

这不得不说我们的注解编译处理器咯！注解分为两种类型，一种是运行时注解，另一种是编译时注解。编译时注解的核心要依赖APT(Annotation Processing Tools)实现，基本原理就是在类、方法、字段等上添加注解，在编译时，编译器通过扫描AbstractProcessor的子类，把对应合适的注解传入process函数，然后我们开发人员可以在编译期进行相应的逻辑处理了。看看log4j实现的注解编译处理器：

image

我们平常编码很少会用到注解编译处理器，有兴趣可自行写单元测试试一试，这种没玩过的代码写起来还挺有趣的。不过自行写的话需要声明好javax.annotation.processing.Processor文件，再补一张log4j声明的文件：

image

四、朋友请留步

我是tin，一个在努力让自己变得更优秀的普通攻城狮。阅历有限、学识浅薄，如你有发现文章不妥之处，非常欢迎加我提出，我一定细心推敲加以修改。

看到这里请安排个鼓励再走吧，坚持原创不容易，你的正反馈是我坚持输出的最强大动力，谢谢啦。

[图片上传失败...(image-782447-1611469924727)]

总结、提升
做一个快乐的攻城狮
构筑属于自己的一方天地