SLF4j 居然不是编译时绑定?日志又该如何正确的分文件输出?——原理与总结篇
各位新年快乐,过了个新年,休(hua)息(shui)了三周,不过我又回来更新了,经过前面四篇想必小伙伴已经了解日志的使用以及最佳实践了,这个系列的文章也差不多要结束了,今天我们来总结一下。
概览
这篇文章我们讨论一下 SLF4j 的设计,以及 SLF4j 好在哪,之后进行一些答疑与前系列文章勘误,最最后我们来了解一下如何正确的分文件输出日志。
分析设计
SLF4j 并没有使用网上所谓的编译时绑定,实际上是采用了约定俗成的方式,如何做的?很简单,就是直接加载org/slf4j/impl/StaticLoggerBinder.class
,找到一个直接使用,没找到或者找到多个报警告,,分析一下源码:
我们一起来看一个个 Logger 实例是如何创建的:
org.slf4j.LoggerFactory#getLogger(java.lang.String)
,获取 logger 实例的真正入口ch.qos.logback.classic.LoggerContext#getLogger(java.lang.String)
,调用了 logback 的LoggerContext
(实现 LoggerFactory),具体如何调用到这里下面解析)- 可以看到
childLogger = logger.createChildByName(childName);
创建了 loggger实例,继续跟进 - 在
ch.qos.logback.classic.Logger#createChildByName
方法中可以看到childLogger = new Logger(childName, this, this.loggerContext);
,至此我们目的也达到了,logger 是 new 出来的并不是所谓的编译时绑定。
我们继续来跟踪如何调用到 logback 的 LoggerContext
(LogggerFactory),并且来验证一下是否真的是所谓的编译时绑定:
-
还是
org.slf4j.LoggerFactory#getLogger(java.lang.String)
方法,这次我们跟进到org.slf4j.LoggerFactory#getILoggerFactory
方法中发现调用了performInitialization
,跟进去发现调用了bind
,继续跟进发现调用了findPossibleStaticLoggerBinderPathSet
方法在当前ClassPath下查询了所有名为org/slf4j/impl/StaticLoggerBinder.class
类路径返回 -
真正代码如下,注释写的很明确:
Set<URL> staticLoggerBinderPathSet = null; // skip check under android, see also // http://jira.qos.ch/browse/SLF4J-328 if (!isAndroid()) { staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet(); reportMultipleBindingAmbiguity(staticLoggerBinderPathSet); } // the next line does the binding StaticLoggerBinder.getSingleton();
StaticLoggerBinder
这个类就是绑定的关键,点进去发现根本不是 SLF4j 的类,而是来自于 Logback,也就是说,SLF4j 使用了第三方(Logback、Log4j 等)提供的中介类,(Spring Boot 自动配置也部分使用了这种思想,以后的全栈系列文章将会有详细解析,欢迎关注),如果出出现NoClassDefFoundError
则提示一下使用者,然后不再处理日志。SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
结论:
给出结论之前我们先来明确一下 Java 的绑定(Binding)的概念,Java 本身只支持静态(static)绑定与运行时(runtime)绑定,直到与 JDK 1.6 版本一起发布的 JSR269 才能进行编译时绑定,员外理解的编译时绑定类似于 lomok 在编译过程中修改字节码。SFL4j 的 logger 实例是 new 出来的,绑定 LogContext
的 StaticLoggerBinder
(中介类) 是写死的,编译时并没有处理任何逻辑,也谈不上什么编译时绑定,员外翻遍了 SLF4j 文档也没有找到任何有关编译时绑定的材料,官方只提到了 “static binding”, 所以回到文章标题,网上流传的编译时绑定根本就是错的,SLF4j使用的是 Convention over Configuration(CoC)– 惯例优于配置原则,我不管你是什么日志框架,我只加载org.slf4j.impl.StaticLoggerBinder
。这完美契合了软件设计的 KISS(Keep It Simple, Stupid)原则,而 Commons-logging 魔法(magic)一样的动态加载虽然设计很高大上,在应用领域却直接被打脸,低效率、与 OSGi 共同使用所导致的 ClassLoader 问题更是火上浇油,所以员外与大家共勉,写代码切勿炫技。
以上是本文核心,略过的读者劳烦再读一次。
为什么SLF4j 更好
先了解一下为什么说 SLF4j 更好,下面两段话来自于Spring 4.x 官方文档:
Not Using Commons Logging
Unfortunately, the runtime discovery algorithm in
commons-logging
, while convenient for the end-user, is problematic. If we could turn back the clock and start Spring now as a new project it would use a different logging dependency. The first choice would probably be the Simple Logging Facade for Java ( SLF4J), which is also used by a lot of other tools that people use with Spring inside their applications.不幸的是,
commons-logging
的运行时发现算法虽然对用户很方便,但却有问题。 如果我们有后悔药能够将 Spring 作为一个新项目重新启动,首选可能是 Simple Logging Facade for Java(SLF4J),Spring 所依赖的其他工具也能使用它。
That might seem like a lot of dependencies just to get some logging. Well it is, but it is optional, and it should behave better than the vanilla
commons-logging
with respect to classloader issues, notably if you are in a strict container like an OSGi platform. Allegedly there is also a performance benefit because the bindings are at compile-time not runtime.这看起来好像仅仅为了日志就需要很多依赖。但这些依赖都是可选的,在类加载器问题方面,它应该比普通的 Commons-logging 表现得更好,特别是如果您在 OSGi 平台这样的严格容器中。据说性能还有优势,因为绑定是在编译时而不是运行时。
这两段文字可谓是肺腑之言,公平公正,员外也没有到处去验证,所谓性能优势我认为作为static final
级别变量,性能优势也不会太大。员外认为 SLF4j 本质上更好的原因在于其提供市面上所有日志框架的兼容解决方案。
勘误
第一篇文章「Java日志体系居然这么复杂?——架构篇」其中 Spring Boot的使用依赖,我写到“Spring已经写好了一个log4j2-starter但缺少桥接包”是不对的,员外出于好奇验证一下,之所以 Spring 没有依赖 jcl-over-slf4j 是因为 Spring Boot 2.x 版本以后依赖了其自己实现的 Spring-jcl 桥接,而 1.x 版本则带有 jcl-over-slf4j 依赖,所以抱歉,我的文章这里写错了,望各位周知。
第二篇文章「五年Java经验,面试还是说不出日志该怎么写更好?——日志规范与最佳实践篇」其中 Log4j2配置文件那一段有误,缺了一个名为 STDOUT 的控制台Appender,代码如下:
<Console name="STDOUT"> <PatternLayout pattern="[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n"/> </Console>
第四篇文章「这么香的日志动态级别与输出,你确定不进来看看?——生产环境动态输入日志级别、文件」
这篇文章也是有一个配置文件粘贴错位置了,不过源码是正确的,请各位下载github源码,以源码为准。
答疑
第一个答疑是读者的一个小要求,问我能不能写一个YAML格式的 Log4j2 配置文件,当然可以了,下面是手写的,请测试一下再进入生产使用:
Configuration:
status: debug
name: YAMLConfig
properties:
property:
name: baseDir
value: logs
appenders:
RollingFile:
- name: RollingFile
fileName: ${baseDir}/log.log
filePattern: "${baseDir}/$${date:yyyy-MM}/log-%d{yyyy-MM-dd-HH}-%i.log.gz"
PatternLayout:
pattern: "%d{yyyy-MM-dd HH:mm:ss.SSS} %5p %pid --- [%t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}"
Policies:
- TimeBasedTriggeringPolicy: true
SizeBasedTriggeringPolicy:
size: 250 MB
DefaultRollOverStrategy:
max: 100
Delete:
basePath: ${baseDir}
maxDepth: 2
IfFileName:
glob: "*/app-*.log.gz"
IfLastModified:
age: 30d
IfAny:
IfAccumulatedFileSize:
exceeds: 100 GB
IfAccumulatedFileCount:
exceeds: 10
Console:
name: STDOUT
PatternLayout:
Pattern: "[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n"
Filters:
ThresholdFilter:
level: debug
Loggers:
logger:
- name: org.apache.logging.log4j.test2
level: debug
additivity: false
AppenderRef:
ref: RollingFile
Root:
level: trace
AppenderRef:
ref: STDOUT
另外一个小伙伴在我的文章下提出了几个问题:
每个日志文件大小,如何分割?日期分割?一天一个? 是一天一个目录还是一天一个文件? 还是一周一个目录? 区不区分error和info日志在不同文件?打不打印其他级别日志? 能不能动态修改日志级别不停机?是否需要异步日志,你们的访问量到了默认同步日志扛不住的地步了么?怎么异步日志?
虽然这个小伙伴态度不是很好,但是问题还是很好的:
-
每个日志文件大小,如何分割?日期分割?一天一个? 是一天一个目录还是一天一个文件? 还是一周一个目录?
每个文件大小我喜欢250M这个数字,也这么配的,日期分割这个就不应该我来讲了,我说一个月一分割,一般应用都好几百个G了,我说一分钟一分割,好多应用还不到1M,所以按照自己线上的需求慢慢调整才行。
-
区不区分error和info日志在不同文件?
员外坚决反对按照日志级别分文件,设想一下回溯现场的时候,info、warn、error 级别都是有用日志,如果分开了,是不是逐个去看?如果让我逐个去定位错误位置,我想我会骂娘的,至于如何正确的分文件输出日志,后面我会有补充,见下文。
-
打不打印其他级别日志?
打不打印其他级别日志根本就是个伪问题,不需要打印其他级别也就不需要那么多日志级别了,这个问题是不是可以理解为日志应该开到什么级别,我一般开 info 级别,我也见过线上只开 error 的,然后业务里的日志输出都是error的(反面教材)。
-
能不能动态修改日志级别不停机?
能的,参考我上一篇文章,而且这方面应该没有人做的比我文章里写的更好了。
-
是否需要异步日志,怎么异步日志?
我个人不倾向于异步日志,磁盘IO满了,开了异步也是缓冲区满,缓冲区满了要么阻塞,要么抛弃,至于开了异步所带来的性能优势并不大。怎么异步日志我文章里也有写,请参阅公众号。
-
你们的访问量到了默认同步日志扛不住的地步了么?
日志扛不住了要先考虑是不是过多,如果实在没法减少日志,就考虑将日志输出路径单独挂载磁盘、更换更好的磁盘等等。
正确的分文件输出日志
读过员外的文章就知道,员外是赞成分文件输出日志的,不过员外反对按照级别来输出文件。如何正确的按文件输出日志呢?以前文章没有写过,这里来补充一下。
很简单,配置多个appender,然后可以按照 loggger 来分文件,代码如下:
<Logger name="com.jiyuanwai.log.xxx" level="info" additivity="false"> <appender-ref ref="XXXFile"/> </Logger> <Logger name="com.jiyuanwai.log.yyy" level="info" additivity="false"> <appender-ref ref="YYYFile"/> </Logger>
这个倒是很简单,但是还有一个问题,单个类如果有多种日志想要输出到多个位置,该怎么办,解决方案有两种,一个类持有多个 logger 实例:
class A { static final Logger log = LoggerFactory.getLogger("com.jiyuanwai.log.xxx"); static final Logger log = LoggerFactory.getLogger("com.jiyuanwai.log.yyy"); ... }
这种办法实现简单,但是不优雅,我们来尝试拿出另外一套方案,就是 Maker 配合 Filter 来实现,当然根据以前的文章了解到我们还可以使用 Sift 配合 MDC 来实现,但员外不推荐,至于为什么,作为公众号粉丝福利可以关注公众号回复 “Sift” 来获取答案,我们来继续看 demo:
// Marker 也可以考虑 static final Marker file1 = MarkerFactory.getMarker("file1"); Marker file2 = MarkerFactory.getMarker("file2"); log.info(file1, "A file 1 log."); log.info(file2, "A file 2 log.");
配置文件如下:
<appender name="FILE1" class="ch.qos.logback.core.FileAppender"> <file>${LOG_PATH}/testFile1.log</file> <append>true</append> <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator"> <marker>file1</marker> </evaluator> <!-- 不匹配 NEUTRAL不处理,ACCEPT接收,DENY抛弃 --> <OnMismatch>DENY</OnMismatch> <!-- 匹配处理方式 NEUTRAL不处理,ACCEPT接收,DENY抛弃 --> <OnMatch>ACCEPT</OnMatch> </filter> <encoder> <pattern>${FILE_LOG_PATTERN}</pattern> </encoder> </appender> <appender name="FILE2" class="ch.qos.logback.core.FileAppender"> <file>${LOG_PATH}/testFile2.log</file> <append>true</append> <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator class="ch.qos.logback.classic.boolex.OnMarkerEvaluator"> <!-- 此处可以配置多个 marker--> <marker>file2</marker> </evaluator> <!-- 不匹配 NEUTRAL不处理,ACCEPT接收,DENY抛弃 --> <OnMismatch>DENY</OnMismatch> <!-- 匹配处理方式 NEUTRAL不处理,ACCEPT接收,DENY抛弃 --> <OnMatch>ACCEPT</OnMatch> </filter> <encoder> <pattern>${FILE_LOG_PATTERN}</pattern> </encoder> </appender> <logger name="com.jiyuanwai.logging.LoggingApplication" additivity="false"> <appender-ref ref="FILE1"/> <appender-ref ref="FILE2"/> </logger>
结束语
以上只是抛砖引玉,日志分文件输出还可以写更多逻辑,小伙伴需要自己动手发掘。
至此日志系列就算是告一段落了,如果还有疑问小伙伴可以留言讨论,接下来一系列我们进入Spring Boot + Vue 的全栈之路,敬请关注。
以上是个人观点,如果有问题或错误,欢迎留言讨论指正,码字不易,如果觉得写的不错,求关注、求点赞、求转发。
扫码关注公众号,第一时间获得更新