一起进阶一起拿高工资!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)]

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

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 195,783评论 5 462
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 82,360评论 2 373
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 142,942评论 0 325
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 52,507评论 1 267
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 61,324评论 5 358
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 46,299评论 1 273
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 36,685评论 3 386
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 35,358评论 0 254
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 39,652评论 1 293
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 34,704评论 2 312
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 36,465评论 1 326
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 32,318评论 3 313
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 37,711评论 3 299
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 28,991评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,265评论 1 251
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 41,661评论 2 342
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 40,864评论 2 335

推荐阅读更多精彩内容